Oracle Scratchpad

January 15, 2007

10132 (again)

Filed under: Execution plans,trace files,Troubleshooting — Jonathan Lewis @ 9:30 pm GMT Jan 15,2007

If you ever enable event 10132, don’t be surprised to find some of the resulting execution plans looking a little messy, for example (from a 9i trace file):

 
Current SQL statement for this session: 
select col#,intcol#,ntab# from ntab$ where obj#=:1 order by intcol# asc 
Plan Table 
-------- 
---------------------------------------------------------------------------------------------- 
| Operation              | Name   | Rows | Bytes | Cost | TQ  |IN-OUT|PQ Distrib|Pstart|Pstop| 
---------------------------------------------------------------------------------------------- 
| SELECT STATEMENT       |        |    0 |     0 |    0 |     |      |          |      |     | 
|  SORT ORDER BY         |        |    0 |     0 |    0 |     |      |          |      |     | 
BINDS #50: 
 bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24 offset=0 
   bfp=0350b1cc bln=22 avl=03 flg=05 
   value=352 
EXEC #50:c=0,e=155,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=4,tim=212109737730 
FETCH #50:c=0,e=56,p=0,cr=3,cu=0,mis=0,r=1,dep=2,og=4,tim=212109737835 
|   TABLE ACCESS CLUSTER | NTAB$  |    0 |     0 |    0 |     |      |          |      |     | 
|    INDEX UNIQUE SCAN   | I_OBJ# |    0 |     0 |    0 |     |      |          |      |     | 
----------------------------------------------------------------------------------------------   

There’s an important reason for that messy bit in the middle, and it can appear in all sorts of other odd places in trace files, especially the better known 10046 trace file.

Oracle doesn’t necessarily know everything about the things it has in the dictionary cache (a.k.a. the row cachev$rowcache), so sometimes it has to do lookups based on a cached id.

Checking further up the trace file (which, as you can see, also had event 10046 enables at level 4 – for bind values), we find the following parse call for cursor #50:

 
PARSING IN CURSOR #50 len=116 dep=2 uid=0 oct=3 lid=0 tim=212109584604 hv=431456802 ad='6ef67c8c' 
select o.owner#,o.name,o.namespace,o.remoteowner,o.linkname,o.subname,o.dataobj#,o.flags from obj$ o where o.obj#=:1 
END OF STMT     

If we feed the bind value of 352 into this query, we can see that Oracle needed the name of the ntab$ cluster before it could print it in our original execution plan.

1 Comment »

  1. Hi Jonathan,

    I have found in your blogs, mentions of various events like event 10132. What are these events? How to enable them? Could you please point me to the books in Oracle Documentation, where these events are documented.

    As per my understanding, by enabling events, we can collect some extra information in the trace files.

    Many Thanks
    Dinesh

    Comment by Dinesh Velhal — January 26, 2007 @ 6:48 am GMT Jan 26,2007 | Reply


RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

The Rubric Theme. Blog at WordPress.com.

Follow

Get every new post delivered to your Inbox.

Join 4,524 other followers