Search This Blog

Total Pageviews

Saturday 27 January 2018

Tracing SQL statement execution


Oracle Tracing SQL statement execution... 


Tracing SQL statement execution
sql trace 



alter session set nls_date_format='dd-mm-yyyy hh24:mi';
set linesize 500 pagesize 300
clear columns

col osuser 		for a16
col program 	for a10 trunc
col Locked 		for a6
col status 		for a1 trunc print
col "hh:mm:ss" 	for a8
col SQL_ID 		for a15
col seq# 		for 99999 --Sequence number that uniquely identifies the wait. Incremented for each wait
col module 		for a25
col ACTION 		for a20
col kill 		for a17
col event heading 'Current/LastEvent' for a25 trunc
col state head 'State (sec)' for a14
col username    for a25
select ''''||sid ||','|| serial#||',@'||inst_id ||''''  kill
,con_id --12c
, username
, ltrim(substr(osuser, greatest(instr(osuser, '\', -1, 1)+1,length(osuser)-14))) osuser
, substr(program,instr(program,'/',-1)+1,decode(instr(program,'@'),0,decode(instr(program,'.'),0,length(program),instr(program,'.')-1),instr(program,'@')-1)) program,
 decode(lockwait,NULL,' ','L') locked, status,
to_char(to_date(mod(last_call_et,86400), 'sssss'), 'hh24:mi:ss') "hh:mm:ss" , sql_id,SQL_CHILD_NUMBER,prev_sql_id, prev_child_number, seq# , event,
decode(state,'WAITING','WAITING '||lpad(to_char(mod(SECONDS_IN_WAIT,86400),'99990'),6),'WAITED SHORT TIME','ON CPU','WAITED KNOWN TIME','ON CPU',state) state
, substr(module,1,25) module,final_blocking_session_status,sql_exec_start
-- substr(action,1,20) action
from GV$SESSION
where 1=1
--and  type = 'USER'
and STATUS!='INACTIVE'
--and audsid != 0 -- to exclude internal processess
--and USERNAME='ODS'
and SQL_ID='36psp2j8kf741'
--and event not like 'SQL*Net message from%'
-- and sid ||','|| serial#||',@'||inst_id =&Kill  -- from above 
and sid=2775
order by inst_id, status, last_call_et desc, sid
/


KILL                  CON_ID USERNAME                  OSUSER           PROGRAM    LOCKED S hh:mm:ss SQL_ID          SQL_CHILD_NUMBER PREV_SQL_ID   PREV_CHILD_NUMBER            SEQ# Current/LastEvent         State (sec)    MODULE                    FINAL_BLOCK SQL_EXEC_START
----------------- ---------- ------------------------- ---------------- ---------- ------ - -------- --------------- ---------------- ------------- ----------------- ---------- ------------------------- -------------- ------------------------- ----------- ----------------
'2775,8536,@1'             5 SYS                       oracle           sqlplus           A 00:02:16 36psp2j8kf741                  0 b9nbhsbx8tqz5             14       2461 db file sequential read   ON CPU         sqlplus@xxxxxxxxxxxxxxxxxxxx NOT IN WAIT 01-03-2023 08:26

Elapsed: 00:00:00.01




 begin
    dbms_sqldiag.dump_trace(p_sql_id=>'36psp2j8kf741',
                            p_component=>'Optimizer',
                           p_file_id=>'OPT_TRACE_36psp2j8kf741');
    end;
    /

col VALUE for a100
select value from v$diag_info where name = 'Default Trace File';


or 


Want to trace following Sql ..
select /*+ TEST */ id,name from ANUJ_BIG_TABLE order by 1,2 desc

To find out the sql id
 set linesize 300
col SQL_TEXT for a60 wrap
select sql_id, child_number, sql_text from gv$sql where sql_text like '%select /*+ TEST */ id,name%';

SQL_ID CHILD_NUMBER SQL_TEXT
------------- ------------ ------------------------------------------------------------
8yhtz51ah96v7 0 select /*+ TEST */ id,name from ANUJ_BIG_TABLE order by 1,2
 desc



execute DBMS_SQLDIAG.DUMP_TRACE(-
 p_sql_id=>'8yhtz51ah96v7', -
 p_child_number=>0, -
 p_component=>'Optimizer', -
 p_file_id=>'ANUJ_TEST');
SYS@rac1> 
PL/SQL procedure successfully completed.


To find sql trace ..
set pagesize 200 linesize 200
col value for a100
col NAME for a25
select * from v$diag_info ;

 INST_ID NAME                      VALUE                                                                                                    CON_ID
---------- ------------------------- ---------------------------------------------------------------------------------------------------- ----------
         1 Diag Enabled              TRUE                                                                                                          0
         1 ADR Base                  /u01/app/oracle                                                                                               0
         1 ADR Home                  /u01/app/oracle/diag/rdbms/asrac/asrac1                                                                       0
         1 Diag Trace                /u01/app/oracle/diag/rdbms/asrac/asrac1/trace                                                                 0
         1 Diag Alert                /u01/app/oracle/diag/rdbms/asrac/asrac1/alert                                                                 0
         1 Diag Incident             /u01/app/oracle/diag/rdbms/asrac/asrac1/incident                                                              0
         1 Diag Cdump                /u01/app/oracle/diag/rdbms/asrac/asrac1/cdump                                                                 0
         1 Health Monitor            /u01/app/oracle/diag/rdbms/asrac/asrac1/hm                                                                    0
         1 Default Trace File        /u01/app/oracle/diag/rdbms/asrac/asrac1/trace/asrac1_ora_11675_ANUJ_TEST.trc                                  0  <<<<<<---- trace file info 
         1 Active Problem Count      2                                                                                                             0
         1 Active Incident Count     2                                                                                                             0

11 rows selected.

ls -ltr /u01/app/oracle/diag/rdbms/asrac/asrac1/trace/asrac1_ora_11675_ANUJ_TEST.trc
-rw-r----- 1 oracle oinstall 140805 Jan 27 11:06 /u01/app/oracle/diag/rdbms/asrac/asrac1/trace/asrac1_ora_11675_ANUJ_TEST.trc


to create a text file .... 
tkprof /u01/app/oracle/diag/rdbms/asrac/asrac1/trace/asrac1_ora_11675_ANUJ_TEST.trc sort='(prsela,exeela,fchela)' print=10
tkprof /u01/app/oracle/diag/rdbms/asrac/asrac1/trace/asrac1_ora_11675_ANUJ_TEST.trc sort='(prsela,exeela,fchela)' print=10
output =ANUJ_TEST.txt

Text file ... 
-rw-r--r-- 1 oracle oinstall 15548 Jan 27 11:16 asrac1_ora_11675_ANUJ_TEST.txt

ls -ltr *.txt
-rw-r--r-- 1 oracle oinstall 15548 Jan 27 11:16 asrac1_ora_11675_ANUJ_TEST.txt


alter system set events 'trace[RDBMS.SQL_Optimizer.*][sql:8yhtz51ah96v7]';
alter system set events 'trace[RDBMS.SQL_Optimizer.*][sql:8yhtz51ah96v7] off';

SYS@asrac1> ALTER SYSTEM SET EVENTS 'trace[SQL_Optimizer.*] off';
System altered.

=========

alter system set events 'sql_trace [sql:auyf5px9yxx9j]';
alter system set events 'trace[rdbms.SQL_Optimizer.*][sql:auyf7px9yxx9j]';


alter system set events 'sql_trace [sql:36psp2j8kf741] wait=true,bind=true';
alter system set events 'trace[sql_optimizer.*] [sql:36psp2j8kf741]';

To search sql dump file ..

find /u01/app/oracle/diag/rdbms/orc/orc/trace -type f -exec grep -il "36psp2j8kf741" {} \;

alter system set events 'sql_trace off';
alter system set events 'trace[sql_optimizer.*] off';
========


EXEC DBMS_MONITOR.session_trace_enable(session_id => TO_NUMBER(SUBSTR('&&sid_serial.', 1, INSTR('&&sid_serial.', ',') - 1)), serial_num => TO_NUMBER(SUBSTR('&&sid_serial.', INSTR('&&sid_serial.', ',') + 1)), waits => TRUE, binds => TRUE, plan_stat => 'ALL_EXECUTIONS');
--
COL trace_filename NEW_V trace_filename FOR A200;
SELECT d.value||'/'||i.instance_name||'_ora_'||spid||CASE WHEN pr.traceid IS NOT NULL THEN '_'||pr.traceid END||'.trc' trace_filename
  FROM v$session se, 
       v$process pr,
       v$instance i,
       v$diag_info d
 WHERE se.type = 'USER'
   AND se.sid||','||se.serial# LIKE '%'||REPLACE('&&sid_serial.', ' ')||'%'
   AND pr.con_id = se.con_id
   AND pr.addr = se.paddr
   AND d.name = 'Diag Trace'
/
--
PRO
PRO tracing session &&sid_serial. for &&seconds. seconds...
PRO
EXEC DBMS_LOCK.sleep(seconds => &&seconds.);
EXEC DBMS_MONITOR.session_trace_disable(session_id => TO_NUMBER(SUBSTR('&&sid_serial.', 1, INSTR('&&sid_serial.', ',') - 1)), serial_num => TO_NUMBER(SUBSTR('&&sid_serial.', INSTR('&&sid_serial.', ',') + 1)));

===

col trace for a150
select 'EXECUTE DBMS_MONITOR.session_trace_enable(session_id =>'||s.sid||','|| 'serial_num=>'||s.serial#||','||' waits=>TRUE, binds=>TRUE);' trace
FROM V$SESSION S, V$PROCESS P
WHERE  S.PADDR = P.ADDR
AND S.SID = (select SYS_CONTEXT('USERENV','SID') from dual);

TRACE
------------------------------------------------------------------------------------------------------------------------------------------------------
EXECUTE DBMS_MONITOR.session_trace_enable(session_id =>1589,serial_num=>27417, waits=>TRUE, binds=>TRUE);



 SELECT S.SID,S.SERIAL#, P.TRACEFILE
FROM V$SESSION S, V$PROCESS P
WHERE  S.PADDR = P.ADDR
AND S.SID = 1589;


trace file info 
set linesize 300
col TRACEFILE for a100 
select value ||'/'||(select instance_name from v$instance) ||'_ora_'||
          (select spid||case when traceid is not null then '_'||traceid else null end
                from v$process where addr = (select paddr from v$session
                                            where sid = (select sid from v$mystat
                                                       where rownum = 1
                                                  )
                                       )
          ) || '.trc' tracefile
   from v$parameter where name = 'user_dump_dest'
   /


to search trace file

begin
  dbms_monitor.session_trace_enable (
    session_id => 3143, 
    serial_num => 44891, 
    waits      => true, 
    binds      => true,
    plan_stat  => 'all_executions');
end;


begin
  dbms_monitor.session_trace_disable (
  session_id => 3143, 
    serial_num => 44891
	);
	end;
	

 find /u01/app/oracle/diag/rdbms/**/***/trace -name "*.trc" -mtime -0.08 -exec grep -l "*** SESSION ID:(3143." {} \;
 
 find /u01/app/oracle/diag/rdbms/**/***/trace -name "*.trc" -mmin -120 -exec grep -l "*** SESSION ID:(3143." {} \;
 
Bug 19683821 : 10053 TRACE IS NOT GETTING GENERATED WHEN THE SQL IS GOING FOR A SOFT PARSE.

====
How to enable tracing? 
10046 tracing:
==============

Enabling trace for session:
---------------------------
alter session set timed_statistics = true;
alter session set statistics_level=all;
alter session set max_dump_file_size = unlimited;
ALTER SESSION SET TRACEFILE_IDENTIFIER = "MY_10046";
alter session set events '10046 trace name context forever,level 12' ;

<run your sql query>


Disabling trace for a session:
------------------------------
alter session set events '10046 trace name context off';
exit;

====




 cat index.sql

--===
alter session set container=rac ;
set linesize 300 pagesize 300 timing on time on

alter session set timed_statistics = true;
alter session set statistics_level=all;
alter session set max_dump_file_size = unlimited;
ALTER SESSION SET TRACEFILE_IDENTIFIER = "MY_10046_1";
alter session set events '10046 trace name context forever,level 12' ;


col OBJEC OWNER for a20
col OBJECT_NAME for a20

SELECT 'INDEX' object_type,owner, index_name object_name, last_analyzed, stattype_locked, stale_stats
FROM all_ind_statistics
WHERE (last_analyzed IS NULL OR stale_stats = 'YES') and stattype_locked IS NULL
ORDER BY owner, object_type, object_name;

alter session set events '10046 trace name context off';

--===    





run script 
nohup sqlplus '/ as sysdba' @/home/oracle/index.sql > /home/oracle/index_1.txt 2>&1 &





tkprof for pdb database 

tkprof rac_ora_27603_MY_10046_1.trc rac_ora_46040_MY_10046_11.txt pdbtrace=tkprof/passwd@rac



========


select sid, serial# from v$session
where sid = 3152;



begin
  dbms_monitor.session_trace_enable (
    session_id => 3152, 
    serial_num => 4134, 
    waits      => true, 
    binds      => true,
    plan_stat  => 'all_executions');
end;



define 1=3152
select
   r.value                                ||'/diag/rdbms/'||
  lower(sys_context('USERENV','DB_NAME') )      ||'/'||
   sys_context('USERENV','INSTANCE_NAME') ||'/trace/'||
   sys_context('USERENV','DB_NAME')       ||'_ora_'||p.spid||'.trc'
   as tracefile_name
from v$session s, v$parameter r, v$process p
where r.name = 'diagnostic_dest'
and s.sid = &1
and p.addr = s.paddr
union all
select
   r.value                                ||'/diag/rdbms/'||
  sys_context('USERENV','DB_NAME')      ||'/'||
   sys_context('USERENV','INSTANCE_NAME') ||'/trace/'||
   sys_context('USERENV','DB_NAME')       ||'_ora_'||p.spid||'.trc'
   as tracefile_name
from v$session s, v$parameter r, v$process p
where r.name = 'diagnostic_dest'
and s.sid = &&1
and p.addr = s.paddr
;


===



How to Create a SQL-testcase Using the DBMS_SQLDIAG Package [Video] (Doc ID 727863.1)

Oracle DBA

anuj blog Archive