Posts Tagged ‘end to end tracing’
Tracing user specific SQL statements
Assuming following request:
I would like to trace SQL statements of specific Oracle user, not any other users.
My first choice would be the powerful end to end tracing facility of Oracle 10g.
Next one is dbms_xplan package which is not only powerful but also the most important package in Oracle.
1. End to end tracing to trace specific user.
UKJA@ukja102> -- 1. Create logon trigger in which I give identifier to user's session
UKJA@ukja102> connect /as sysdba
Connected.
SYS@ukja10> create or replace trigger logon_trigger
2 after logon on database
3 begin
4 if ora_login_user = 'UKJA' then
5 dbms_session.set_identifier('ukja');
6 end if;
7 end;
8 /
Trigger created.
SYS@ukja10> -- 2. Enable sql*trace for given client identifier
SYS@ukja10> exec dbms_monitor.client_id_trace_enable(client_id=>'ukja', -
> waits=>true, binds=>true);
PL/SQL procedure successfully completed.
SYS@ukja10> -- 3. Logon as UKJA user and execute some queries
SYS@ukja10> connect ukja/ukja@ukja102
Connected.
UKJA@ukja102> select count(*) from t1;
COUNT(*)
----------
0
UKJA@ukja102> connect ukja/ukja@ukja102
Connected.
UKJA@ukja102> select count(*) from t1;
COUNT(*)
----------
0
UKJA@ukja102> connect ukja/ukja@ukja102
Connected.
UKJA@ukja102> select count(*) from t1;
COUNT(*)
----------
0
UKJA@ukja102> -- 4. Disable sql*trace for given client identifier
UKJA@ukja102> connect sys /as sysdba
Connected.
SYS@ukja10> exec dbms_monitor.client_id_trace_disable(client_id=>'ukja');
PL/SQL procedure successfully completed.
SYS@ukja10> -- 5. Now the most difficult part.
Our 3 trace files are scattered in the user dump directory. We should merge it.
The fantastic trcsess tool does this for me.
SYS@ukja10> col value new_value dump_dir
SYS@ukja10>
SYS@ukja10> select value from v$parameter where name = 'user_dump_dest';
VALUE
--------------------
C:\ORACLE\ADMIN\UKJA
10\UDUMP
SYS@ukja10> -- Merge!
SYS@ukja10> ho trcsess output=trc1.out clientid=ukja &dump_dir\*.trc
SYS@ukja10> -- And tkprof
SYS@ukja10> ho tkprof trc1.out tk1.out
-- Tkprof report. The result(3 executions from different sessions) was merged successfully!
select count(*)
from
t1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 6 0.00 0.00 0 9 0 3
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 12 0.00 0.00 0 9 0 3
This end to end tracing is quite flexible and powerful. Love it!
2. DBMS_XPLAN.DISPLAY_CURSOR to trace specific user.
UKJA@ukja102> -- Following simple query would capture the queries
which start with 'select /*+ gather_plan_statistics */ count(*)%' and
executed by UKJA user
UKJA@ukja102> select
2 cursor(select * from table(
3 dbms_xplan.display_cursor(s.sql_id, s.child_number, 'allstats last')))
4 from v$sql s
5 where s.parsing_schema_name = 'UKJA'
6 and s.sql_text like 'select /*+ gather_plan_statistics */ count(*) %'
7 ;
CURSOR(SELECT*FROMTA
--------------------
CURSOR STATEMENT : 1
CURSOR STATEMENT : 1
PLAN_TABLE_OUTPUT
-------------------------------------------------------------------------------------
SQL_ID fuynj2z4vdjks, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ count(*) from t3
Plan hash value: 463314188
-------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers |
-------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:00.01 | 7 |
| 2 | TABLE ACCESS FULL| T3 | 1 | 1000 | 1000 |00:00:00.01 | 7 |
-------------------------------------------------------------------------------------
CURSOR STATEMENT : 1
CURSOR STATEMENT : 1
PLAN_TABLE_OUTPUT
-------------------------------------------------------------------------------------
SQL_ID 5cunshnzqa8vb, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ count(*) from t2
Plan hash value: 3321871023
-------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers |
-------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:00.01 | 3 |
| 2 | TABLE ACCESS FULL| T2 | 1 | 1 | 0 |00:00:00.01 | 3 |
-------------------------------------------------------------------------------------
CURSOR STATEMENT : 1
CURSOR STATEMENT : 1
PLAN_TABLE_OUTPUT
-------------------------------------------------------------------------------------
SQL_ID cz662tawx6sbt, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ count(*) from t1
Plan hash value: 3724264953
-------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers |
-------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:00.01 | 3 |
| 2 | TABLE ACCESS FULL| T1 | 1 | 1 | 0 |00:00:00.01 | 3 |
-------------------------------------------------------------------------------------
Again, very easy and powerful.
Dion Cho - Oracle Performance Storyteller 