トラブルを解決するためトレースファイルがよく必要とされる。
取得方法は
該当セッション自身、一般のエラー
ALTER SESSION SET SQL_TRACE=ON; -- 問題のSQL文を実行する ... ALTER SESSION SET SQL_TRACE=OFF;
該当セッション自身、高度のエラー（ラッチ、待機など情報が必要）
ALTER SESSION SET EVENTS '10046 trace name context forever, level 12'; -- 問題のSQL文を実行する ... ALTER SESSION SET EVENTS '10046 trace name context off';
レベルの詳細は下記のとおり。
| レベル | 内容 |
| LEVEL 1 | SQL_TRACE機能と同等 |
| LEVEL 4 | LEVEL 1の情報に追加して、バインド変数情報が出力される |
| LEVEL 8 | LEVEL 1の情報に追加して、待機イベント情報が出力される |
| LEVEL 12 | LEVEL 1の情報に追加して、バインド変数情報、待機イベント情報が出力される |
アプリケーションに組み込む場合
場合によって、直接問題文の発行する前に手で発行できないことがあるため、
アプリケーション、プロシージャに組み込むことができる。
execute 'ALTER SESSION SET EVENTS ''10046 trace name context forever, level 12'' '; -- 問題のSQL文を実行する ... execute 'ALTER SESSION SET EVENTS ''10046 trace name context off'' ';
他のセッションのトレースファイルの取得
--セッションのSIDとSERIAL#の取得 SQL> SELECT sid,serial#,username,program,machine,status,last_call_et FROM v$session 2 WHERE username='SCOTT'; SID SERIAL# USERNAME PROGRAM MACHINE STATUS LAST_CALL_ET ----- ---------- ------------ --------------------------------- ------------ -------- ------------ 10 2 SCOTT sqlplus@linuxtest (TNS V1-V3) linux006 INACTIVE 2 --セッションのトレース EXECUTE DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(10,12,TRUE); -- 問題のSQL文を実行する ... EXECUTE DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(10,12,FALSE); --セッションに対してレベルを指定してトレース EXECUTE DBMS_SYSTEM.SET_EV(10,2,10046,12,''); -- 問題のSQL文を実行する ... EXECUTE DBMS_SYSTEM.SET_EV(10,2,10046,0,'');
トレースファイルの特定
トレースファイルの特定
http://www.builder.com.cn/2007/0910/497699.shtml
http://www.eygle.com/archives/2007/09/11g_tracefile_name.html
-- under 11g -- sql 1 SELECT a.VALUE || b.symbol || c.instance_name || '_ora_' || d.spid || '.trc' trace_file FROM (SELECT VALUE FROM v$parameter WHERE NAME = 'user_dump_dest') a, (SELECT SUBSTR (VALUE, -6, 1) symbol FROM v$parameter WHERE NAME = 'user_dump_dest') b, (SELECT instance_name FROM v$instance) c, (SELECT spid FROM v$session s, v$process p, v$mystat m WHERE s.paddr = p.addr AND s.SID = m.SID AND m.statistic# = 0) d ; -- sql 2 select u_dump.value || '/' || db_name.value || '_ora_' || v$process.spid || nvl2(v$process.traceid, '_' || v$process.traceid, null ) || '.trc' "Trace File" from v$parameter u_dump cross join v$parameter db_name cross join v$process join v$session on v$process.addr = v$session.paddr where u_dump.name = 'user_dump_dest' and db_name.name = 'db_name' and v$session.audsid=sys_context('userenv','sessionid'); -- after 11g -- trace file name of current session SELECT VALUE FROM V$DIAG_INFO WHERE NAME = 'Default Trace File'; -- trace file name for all processes select program,TRACEFILE from v$process;
あるいは初期化パラメータのuser_dump_destの指定したフォルダを時間順でみれば、最新のほうに並んでいるはず。
SQL> show parameter user_dump_dest NAME TYPE ------------------------------------ --------------------------------- VALUE ------------------------------ user_dump_dest string /u01/oracle/app/oracle/admin/sid/udump host [oracle@linuxtest ~]$ cd /u01/oracle/app/oracle/admin/sid/udump [oracle@ linuxtest udump]$ ls -ltr ... -rw-r----- 1 oracle oinstall 2541 8月 21 16:34 dbsid_ora_10101.trc -rw-r----- 1 oracle oinstall 943 8月 21 16:43 dbsid_ora_14837.trc -rw-r----- 1 oracle oinstall 1361 8月 21 16:43 dbsid_ora_10773.trc
生トレースファイルの確認
References:
http://www.itpub.net/forum.php?mod=viewthread&tid=1137992
1.Activating/deactivating trace http://www.gplivna.eu/papers/otrace.htm
2.Interpreting Raw SQL_TRACE and DBMS_SUPPORT.START_TRACE output, Metalink Note 39817.1
3.Trace Analyzer TRCANLZR - Interpreting Raw SQL Traces with Binds and/or Waits generated by EVENT 10046 Metalink Note 224270.1
See Also:
Abbreviation In Oracle Trace File
Here is a sample snippet from a trace file.
PARSING IN CURSOR #5 len=222 dep=1 uid=0 oct=3 lid=0 tim=1230889092568518 hv=3598296092 ad='402c848c' sqlid='1a8n1zgb7m90w' select user#,password,datats#,tempts#,type#,defrole,resource$, ptime,exptime, ltime, astatus, lcount, decode(defschclass,NULL,'DEFAULT_CONSUMER_GROUP',defschclass),spare1,spare4,ext_username,spare2 from user$ where name=:1 END OF STMT PARSE #5:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,plh=1457651150,tim=1230889092568518 EXEC #5:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,plh=1457651150,tim=1230889092568518 FETCH #5:c=0,e=0,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=4,plh=1457651150,tim=1230889092568518 STAT #5 id=1 cnt=1 pid=0 pos=1 obj=22 op='TABLE ACCESS BY INDEX ROWID USER$ (cr=2 pr=0 pw=0 time=0 us)' STAT #5 id=2 cnt=1 pid=1 pos=1 obj=46 op='INDEX UNIQUE SCAN I_USER1 (cr=1 pr=0 pw=0 time=0 us)' CLOSE #5:c=0,e=0,dep=1,type=3,tim=1230889092568518
Parsing in cursor:
len =the length of the cursor.
dep =recursive depth of cursor(0-parent,>0-child)
uid =user id
oct =oracle command type no OCI
lid =user id owning the statement e.g. package(libary user id)
tim =the time the parse began
hv =hash valus
ad =sql address of cursor
sqlid=sql id of cursor
END OF STMT=indicate the end of sql STateMenT
c =cpu time
e =elapsed time
p =number of database blocks read (physical)
cr =number of consistent mode blocks read(logical)
cu =number of current mode blocks read(logical)
mis=number of library cache misses
r =number of rows returned
dep=recursive depth of cursor
og =optimizer goal (1=all_rows, 2=first_rows, 3=rule and 4=choose)
plh=plan hash value
tim=
cr =BG(Backgroud) Consistent Read mode
pr =OS Buffer Gets
pw =OS Write Calls
WAIT #5: nam='rdbms ipc reply' ela= 873 from_process=9 timeout=2147483647 p3=0 obj#=64143 tim=1230889212565389 WAIT #5: nam='rdbms ipc reply' ela= 820 from_process=5 timeout=2147483647 p3=0 obj#=64143 tim=1230889212566547 XCTEND rlbk=0, rd_only=1, tim=1230889212602618
nam =event name
ela =elapsed time
next three values after ela are indicate the P1, P2 and P3 variables for each specific event.
XCTEND =Transaction Commit END
rlbk True(1) if and only if the transaction was rolled back.
rd_only True(1) if and only if the transaction changed no data in the database
