How to get tracing info for binding variables passed through OracleParameter in ODP.NET?

Leniel Maccaferri picture Leniel Maccaferri · Sep 21, 2013 · Viewed 11.5k times · Source

After Googling a lot and not finding what I'm looking for I decided to ask this question.

I'm using binding variables as demonstrated in this awesome article from 2005 titled The Values That Bind by Mark A. Williams, like this:

OracleParameter p_APP_NAME =
    new OracleParameter("p_APP_NAME", OracleDbType.NVarchar2, ParameterDirection.Input);
                         p_APP_NAME.Size = 50;
                         p_APP_NAME.Value = log.Application.Name;
                         cmd.Parameters.Add(p_APP_NAME);

I successfully enabled ODP.NET debug tracing but one key info that's missing is that the logged SQL statement doesn't show me what was the value bound to the binding variable.

It's logging OracleCommand.CommandText but without OracleCommand.Parameters values. It's showing me this:

TIME:2013/09/20-22:59:21:890 TID:20fc  OpsSqlPrepare2(): SQL: UPDATE PS_LOG SET 
                                              APP_NAME = :p_APP_NAME, 
                                              WHERE LOG_ID = :p_LOG_ID

What I'd really like to see are the actual values that were used in the query sent to the ORACLE server like this:

TIME:2013/09/20-22:59:21:890 TID:20fc  OpsSqlPrepare2(): SQL: UPDATE PS_LOG SET 
                                              APP_NAME = 'App Name', 
                                              WHERE LOG_ID = 777

Am I missing some configuration or this info I want is not available when using ODP.NET tracing capability?

If this is not built-in I guess I'll have to implement my own substitution method and log the SQL Statement myself.

Answer

Nick Krasnov picture Nick Krasnov · Sep 21, 2013

As one of the options, you could turn on sql tracing with bind variables dumping by setting 10046 event of level 12 or 4 for a session, either manually or automatically(in a logon trigger for a user for instance):

alter session set events '10046 trace name context forever, level 12';

After that trace file will be generated in a directory specified by user_dump_dest parameter.

SQL> show parameter user_dump_dest;

NAME                                 TYPE        VALUE                          
------------------------------------ ----------- ------------------------------ 
user_dump_dest                       string      D:\...\diag\rdbms\cdb\cdb 
                                                 \trace   

Here is an example:

SQL> alter session set events '10046 trace name context forever, level 12';
  2 variable var number;
  3 exec :var := 1234567;     -- our bind variable
  4 select 1 from dual where 1234567 = :var ;

Among other information presented in a newly generated trace file we could find information about the query, bind variable(s) and its/their values:

PARSING IN CURSOR #375980232 len=40 dep=0 uid=103
oct=3 lid=103 tim=2640550035 hv=1641534478
ad='7ff5bd0baf0' sqlid='ap9rzz5hxgp0f'
select 1 from dual where 1234567 = :var <-- our query
END OF STMT
PARSE #375980232:c=0,e=375,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=2640550034
BINDS #375980232:
Bind#0
oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
oacflg=03 fl2=1000000 frm=01 csi=178 siz=24 off=0
kxsbbbfp=16646e10 bln=22 avl=05 flg=05
value=1234567 <-- value of the bind variable

You could also, starting from Oracle 10g and up, query v$sql_bind_capture dynamic performance view to get information about bind variable(s) and their values:

select t.parsing_user_id
     , t.sql_fulltext         -- text of a query
     , bc.name                -- name of a bind variable
     , bc.value_string        -- value of a bind variable
  from v$sqlarea t
  join v$sql_bind_capture bc
    on (bc.sql_id = t.sql_id)
  join v$session s
    on (s.user# = t.parsing_schema_id)
  where s.username = user
    and bc.name in (':VAR') -- name of a bind variable(s), 
                            -- value(s) of which we want to know

Result:

PARSING_USER_ID   SQL_FULLTEXT                      NAME    VALUE_STRING   
 ------------------------------------------------------------------------ 
           103   select 1 from dual where 1 =:var  :VAR     1234567