Data … as usual

In this post, I will explain how to trace CBO computation (aka 10053 event) for a specific sql_id and in another session.

To do this, we need to know two things:

1) How to trace another session? To do this, I will use undocumented oracle tool “oradebug”. More precisely, I will use the new event declaration syntax which is not based on event id.

2) How to trace CBO computation for a specific sql_id? To do this, I will use the new event declaration syntax (more details in the demonstration above)

To demonstrate this trick, I will consider two sessions:

– The first session (S1) is logged as an application user named LAURENT. This user owns two table T1 and T4, and we only want to trace a specific SQL Query (select count(*) from t4 where id between 500 and 550;).

– The second session (S2) is logged as SYS user who will launch oradebug commands.

* S1 (logged as LAURENT)

SQL> select count(*) from t4 where id between 500 and 550;
COUNT(*)
----------
 51

* S2 (logged as SYS) : querying the dictionary to obtain sql_id associated to the SQL query:

SQL> select sql_id,sql_text from v$sql
 2 where sql_text like 'select count(*) from t4 where id between 500 and 550%';
SQL_ID        SQL_TEXT
------------- --------------------------------------------------------------------------------
2zg40utr7a08n select count(*) from t4 where id between 500 and 550

* S1 (logged as LAURENT): obtain Oracle PID and system PID (spid) of the session we will trace. This information will be used for oradebug in the next step.

SQL> select pid,spid from v$process
 2 where addr=(select paddr from v$session
 3 where sid=(select sid from v$mystat where rownum=1));
PID        SPID
---------- ---------
25         4850

* S2 (Logged as SYS) : we will use oradebug new features to trace a specific sql_id by using the new syntax for tracing CBO Computations (trace[RDBMS.SQL_Optimizer.*])

SQL> ALTER SYSTEM FLUSH SHARED_POOL;
SQL> -- Setting Oracle PID to trace and verify by crossing the result of the system pid
SQL> oradebug setorapid 25
Oracle pid: 25, Unix process pid: 4850, image: oracle@oel (TNS V1-V3)
SQL> -- nolimit to tracefile
SQL> oradebug unlimit
Statement processed.
SQL> -- tracing SQL_Optimizer computation for a specific sql (here's our sql_id)
SQL> oradebug event trace[RDBMS.SQL_Optimizer.*][sql:2zg40utr7a08n]
Statement processed.
SQL> -- obtain the trace file name
SQL> oradebug tracefile_name
/u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4850.trc

NB : Flushing shared pool is mandatory if you have already shared cursor for the statement to trace in the shared pool.

* S1 (Logged as LAURENT) : execute many sql statements in the session including our specific sql statement:

S1 (execute sql_id 2zg40utr7a08n one time, and others sql):
SQL> select count(*) from t4 where id between 500 and 550;
COUNT(*)
----------
 51

SQL> select count(*) from t4 ;
COUNT(*)
----------
 300000

SQL> select count(*) from t1;
COUNT(*)
----------
 294958

Finally, open the tracefile generated, you will only have the CBO computations and statistics for our specific sql_id:

[oracle@oel ~]$ vi /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4850.trc
Registered qb: SEL$1 0xe47325b8 (PARSER)
---------------------
QUERY BLOCK SIGNATURE
---------------------
 signature (): qb_name=SEL$1 nbfros=1 flg=0
 fro(0): flg=4 objn=78460 hint_alias="T4"@"SEL$1"
SPM: statement not found in SMB
**************************
Automatic degree of parallelism (ADOP)
**************************
Automatic degree of parallelism is disabled: Parameter.
PM: Considering predicate move-around in query block SEL$1 (#0)
**************************
Predicate Move-Around (PM)
**************************
OPTIMIZER INFORMATION
******************************************
----- Current SQL Statement for this session (sql_id=2zg40utr7a08n) -----
select count(*) from t4 where id between 500 and 550
*******************************************

.../...

Query Block Registry:
SEL$1 0xe47325b8 (PARSER) [FINAL]
:
 call(in-use=13920, alloc=49184), compile(in-use=88336, alloc=152104), execution(in-use=6016, alloc=8088)
End of Optimizer State Dump
Dumping Hints
=============
====================== END SQL Statement Dump ======================

Update : Bertrand Drouvot has blogged a tricky way to flush a specific sql_id before generating its CBO computation trace file. See link : http://bdrouvot.wordpress.com/2013/09/16/flush-a-single-sql-statement-and-capture-a-10053-trace-for-it/