Skip to Main Content
  • Questions

  • Is there any reason alter session set events '10046 trace name context forever, level 12' would not show bind variables.

Breadcrumb

Question and Answer

Tom Kyte

Thanks for the question, kurt.

Asked: July 15, 2009 - 1:54 pm UTC

Last updated: July 27, 2009 - 5:47 am UTC

Version: 11.1

Viewed 1000+ times

You Asked

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


and Tom said...

if the query has already been parsed before you started tracing, you won't see it.

for example:

variable x refcursor
set serveroutput off
declare
    l_rec all_users%rowtype;
begin
    open :x for 'select * from all_users BEFORE where user_id > :x' using 1;
    fetch :x into l_rec;
end;
/

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

print x
exec open :x for 'select * from all_users AFTER where user_id > :x' using 100000;
print x

column trace new_val TRACE

select c.value || '/' || d.instance_name || '_ora_' || a.spid || '.trc' trace
  from v$process a, v$session b, v$parameter c, v$instance d
 where a.addr = b.paddr
   and b.audsid = userenv('sessionid')
   and c.name = 'user_dump_dest'
/

connect /
!vi &TRACE



will produce a trace file like this:

*** 2009-07-16 13:50:39.724
*** SESSION ID:(136.6231) 2009-07-16 13:50:39.724
*** CLIENT ID:() 2009-07-16 13:50:39.724
*** SERVICE NAME:(SYS$USERS) 2009-07-16 13:50:39.724
*** MODULE NAME:(SQL*Plus) 2009-07-16 13:50:39.724
*** ACTION NAME:() 2009-07-16 13:50:39.724

WAIT #4: nam='SQL*Net message to client' ela= 4 driver id=1650815232 # bytes=1 p3=0 obj#=-1 tim=1247766639714556
WAIT #4: nam='SQL*Net message from client' ela= 1347 driver id=1650815232 # bytes=1 p3=0 obj#=-1 tim=1247766639726155
CLOSE #4:c=0,e=0,dep=0,type=1,tim=1247766639724572
WAIT #3: nam='SQL*Net message to client' ela= 3 driver id=1650815232 # bytes=1 p3=0 obj#=-1 tim=1247766639726299
=====================
PARSING IN CURSOR #3 len=49 dep=0 uid=171 oct=3 lid=171 tim=1247766639724572 hv=733528349 ad='52636f30' sqlid='3ss3vnnpvjh8x'
select * from all_users BEFORE where user_id > :x
END OF STMT
FETCH #3:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=15,dep=0,og=1,plh=3413134360,tim=1247766639724572
WAIT #3: nam='SQL*Net message from client' ela= 3601 driver id=1650815232 # bytes=1 p3=0 obj#=-1 tim=1247766639730055
WAIT #3: nam='SQL*Net message to client' ela= 1 driver id=1650815232 # bytes=1 p3=0 obj#=-1 tim=1247766639730107
FETCH #3:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=15,dep=0,og=1,plh=3413134360,tim=1247766639724572
WAIT #3: nam='SQL*Net message from client' ela= 2492 driver id=1650815232 # bytes=1 p3=0 obj#=-1 tim=1247766639732667
WAIT #3: nam='SQL*Net message to client' ela= 4 driver id=1650815232 # bytes=1 p3=0 obj#=-1 tim=1247766639732807
FETCH #3:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=15,dep=0,og=1,plh=3413134360,tim=1247766639724572
WAIT #3: nam='SQL*Net message from client' ela= 3412 driver id=1650815232 # bytes=1 p3=0 obj#=-1 tim=1247766639736320
WAIT #3: nam='SQL*Net message to client' ela= 3 driver id=1650815232 # bytes=1 p3=0 obj#=-1 tim=1247766639736455
FETCH #3:c=1000,e=0,p=0,cr=19,cu=0,mis=0,r=2,dep=0,og=1,plh=3413134360,tim=1247766639735695
WAIT #3: nam='SQL*Net message from client' ela= 1623 driver id=1650815232 # bytes=1 p3=0 obj#=-1 tim=1247766639738689
CLOSE #3:c=0,e=0,dep=0,type=0,tim=1247766639735695
=====================
PARSING IN CURSOR #4 len=89 dep=0 uid=171 oct=47 lid=171 tim=1247766639735695 hv=3039451362 ad='525f9bbc' sqlid='6834dfauknq72'
BEGIN open :x for 'select * from all_users AFTER where user_id > :x' using 100000; END;
END OF STMT
PARSE #4:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=1247766639735695
BINDS #4:
 Bind#0
  oacdty=102 mxl=04(04) mxlc=00 mal=00 scl=00 pre=00
  oacflg=01 fl2=1000000 frm=00 csi=00 siz=4 off=0
  kxsbbbfp=b79eebd4  bln=04  avl=04  flg=05
  value=
Dump of memory from 0xB79EEBD4 to 0xB79EEBD8
B79EEBD0          00000000                        [....]
=====================
PARSING IN CURSOR #3 len=48 dep=1 uid=171 oct=3 lid=171 tim=1247766639735695 hv=4150464802 ad='52441f2c' sqlid='6t9qs8bvq6492'
select * from all_users AFTER where user_id > :x
END OF STMT
PARSE #3:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=3413134360,tim=1247766639735695
BINDS #3:
 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=b79f3f8c  bln=22  avl=02  flg=05
  value=100000
EXEC #3:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=3413134360,tim=1247766639735695
WAIT #4: nam='SQL*Net message to client' ela= 5 driver id=1650815232 # bytes=1 p3=0 obj#=-1 tim=1247766639740086
EXEC #4:c=1000,e=0,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=1247766639735695



notice the parsing in cursor #3 the first time - it is misleading. The cursor was already parsed, the tim= on that is wrong - it was not parsed at that tim=, we know it was parsed well before that because we parsed and fetched from it before the trace was enabled.

Rating

  (5 ratings)

Is this answer out of date? If it is, please let us know via a Comment

Comments

BEFORE/AFTER usage

Lawrence, July 16, 2009 - 3:05 pm UTC

Hi Tom,

My question is not relevant with the original but since BEFORE/AFTER are in your example.
I searched on the net but can't find BEFORE/AFTER usage.
Please point out the links how to use it.

Thanks.

Tom Kyte
July 16, 2009 - 5:57 pm UTC 

    open :x for 'select * from all_users BEFORE where user_id > :x' using 1;



could have been

    open :x for 'select * from all_users A where user_id > :x' using 1;



it is just a correlation name - you haven't see them before? I did that so we could distinctly see a query that was opened BEFORE the trace and another AFTER the trace was enabled.

They are not keywords or magic or anything - just correlation names after a table name, I used it to simply "tag" the query to make it more identifiable in the trace file.

Jonas, July 16, 2009 - 3:38 pm UTC

BEFORE and AFTER are table alias

Keywords vs alias

Lawrence, July 17, 2009 - 12:21 pm UTC

When I saw BEFORE/AFTER in the queries, my first thought was they are Oracle reserved keywords, it misled me...

Thanks.

A reader, July 24, 2009 - 5:35 am UTC

Hi Tom,
can you please explain what are the events and when this type of event setting is useful?
I am not able to find any good documentation on use of Database event.

Thanks

Tom Kyte
July 26, 2009 - 7:22 am UTC

that is because events are undocumented, to be used in the case of support asking you to.

The only widely known even is 10046 - a way to enable tracing with wait events and bind variable values. You need not use it in 10g and above as dbms_monitor gives you the ability to get that information without the event.

So, ignore events unless and until support asks you to set one and then they'll tell you what it is for and why you are setting it.

Tracing

goiyala3, July 27, 2009 - 1:30 am UTC

Tom

Is there any situation that some sql statements missed out in trace file.?
Tom Kyte
July 27, 2009 - 5:47 am UTC

define your situation a little better - not sure what you mean.


If you start tracing after something happened - the things that happened before tracing won't be there.

If you stop tracing before you are done - the things that happened after you stop tracing wont be there.

Things that happen in between - will be in the trace file.
more

Connor and Chris don't just spend all day on AskTOM. You can also catch regular content via Connor's blog and Chris's blog. Or if video is more your thing, check out Connor's channel and Chris's channel from their Youtube channels. And of course, keep up to date with AskTOM via the official twitter account.