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

Question

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.

Unseasoned

Answer 1

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

Bloomers

Pretty nice Nicholas. I had read about these options but I was curious to know if there was a missing/hidden config that would allow me to get the binding info out of the box using the standard ODP.NET tracing. They could add a new trace level to show that info, shouldn't they? At least we have options to grab that info and this is great. I'll try these options ASAP. Thank you very much! – Unseasoned

Answer 2

I agree with everything posted by Nicholas but would add that beginning with Oracle 10.1 the DBMS_MONITOR PL/SQL Package is the preferred method of enabling/disabling tracing. Though setting the event still works as Nicholas has nicely demonstrated.

As you have observed ODP does not emit bind variable values into its trace file as a security consideration.

Jhvh

Great! I know this answer was provided by Mark A. Williams (the author of that article mentioned in my question). I got in contact with him through e-mail and asked him to provide his insights regarding this matter. He replied the e-mail and told me he just answered it. How privileged I'm! :D – Unseasoned