基於oracle 10.2.0.1 rac使用oradebug dump hanganalyze 分析oracle hang系列五

wisdomone1發表於2015-11-10
Oracle

背景

    延續上一文：基於oracle 10.2.0.1 rac使用oradebug dump hanganalyze 分析oracle hang系列四 
    http://blog.itpub.net/9240380/viewspace-1827352/，繼續學習TRACE FILE的內容構成。


結論

1,trace file的第四部分state of nodes記錄所有資料庫會話的資訊，包括了前後臺程式
2，級別5較級別3，會轉儲TRACE FILE第2部分中在等待事件的程式的詳細資訊，並且包括記憶體資訊的DUMP
3,級別10較之級別5，會轉儲所有資料庫會話的資訊
4，引申一下，一般級別5就足夠了，如果還感覺不夠，可以採用級別10
5,State of nodes
([nodenum]/cnode/sid/sess_srno/session/ospid/state/start/finish/[adjlist]/predecessor):
中的nodenum為sid-1
  


測試



--oracle程式個數
SQL> select count(*) from v$process;


  COUNT(*)
----------
        29


--oracle session個數
SQL> select count(*) from v$session;


  COUNT(*)
----------
        27        


--經用UE匹配，可見state of nodes就是所有資料庫會話的資訊，包括了前後臺程式
State of nodes
([nodenum]/cnode/sid/sess_srno/session/ospid/state/start/finish/[adjlist]/predecessor):
[135]/1/136/47/0x83b53b38/22712/IGN/1/2//none
[136]/1/137/1/0x83b54f70/7504/SINGLE_NODE/3/4//none
[137]/1/138/2/0x83b563a8/7377/SINGLE_NODE/5/6//none
[139]/1/140/5/0x83b58c18/7137/SINGLE_NODE/7/8//none
[142]/1/143/1/0x83b5c8c0/6971/IGN/9/10//none
[143]/1/144/1/0x83b5dcf8/6944/IGN/11/12//none
[144]/1/145/1/0x83b5f130/6950/IGN/13/14//none
[146]/1/147/392/0x83b619a0/23993/SINGLE_NODE_NW/15/16//none
[149]/1/150/1/0x83b65648/6710/IGN/17/18//none
[150]/1/151/1/0x83b66a80/6706/IGN/19/20//none
[152]/1/153/20/0x83b692f0/15971/IGN/21/22//none
[153]/1/154/1/0x83b6a728/6701/IGN/23/24//none
[154]/1/155/1/0x83b6bb60/6649/IGN/25/26//none
[155]/1/156/1/0x83b6cf98/6647/IGN/27/28//none
[156]/1/157/1/0x83b6e3d0/6645/IGN/29/30//none
[157]/1/158/1/0x83b6f808/6643/IGN/31/32//none
[158]/1/159/1/0x83b70c40/6641/IGN/33/34//none
[159]/1/160/1/0x83b72078/6639/IGN/35/36//none
[160]/1/161/1/0x83b734b0/6637/IGN/37/38//none
[161]/1/162/1/0x83b748e8/6635/IGN/39/40//none
[162]/1/163/1/0x83b75d20/6633/IGN/41/42//none
[164]/1/165/1/0x83b78590/6629/IGN/43/44//none
[165]/1/166/1/0x83b799c8/6627/IGN/45/46//none
[166]/1/167/1/0x83b7ae00/6625/IGN/47/48//none
[167]/1/168/1/0x83b7c238/6623/IGN/49/50//none
[168]/1/169/1/0x83b7d670/6621/SINGLE_NODE/51/52//none
[169]/1/170/1/0x83b7eaa8/6619/IGN/53/54//none




---再對比看下不同級別的TRACE FILE的區別


---級別5
SQL> oradebug setmypid
Statement processed.
SQL> oradebug dump hanganalyze 5
Statement processed.
SQL> oradebug tracefile_name
/u01/app/oracle/admin/jingfa/udump/jingfa1_ora_2145.trc


可見級別5比我之前測試所用的級別3，資訊更多，還會對某個程式產生SYSTEMSTATE DUMP資訊以及某個程式的呼叫堆疊，以及某個程式的詳細資訊
還有其它幾個程式的資訊


State of nodes
([nodenum]/cnode/sid/sess_srno/session/ospid/state/start/finish/[adjlist]/predecessor):
[136]/0/137/6/0x83b54f70/31964/IGN/1/2//none
[139]/0/140/1/0x83b58c18/16060/SINGLE_NODE/3/4//none
[143]/0/144/1/0x83b5dcf8/15794/SINGLE_NODE/5/6//none
[145]/0/146/103/0x83b60568/2145/SINGLE_NODE_NW/7/8//none
[149]/0/150/1/0x83b65648/15354/IGN/9/10//none
[150]/0/151/1/0x83b66a80/15350/IGN/11/12//none
[151]/0/152/9/0x83b67eb8/16058/SINGLE_NODE/13/14//none
[152]/0/153/9/0x83b692f0/27178/IGN/15/16//none
[153]/0/154/1/0x83b6a728/15320/IGN/17/18//none
[154]/0/155/1/0x83b6bb60/15318/IGN/19/20//none
[155]/0/156/1/0x83b6cf98/15316/IGN/21/22//none
[156]/0/157/1/0x83b6e3d0/15314/IGN/23/24//none
[157]/0/158/1/0x83b6f808/15312/IGN/25/26//none
[158]/0/159/1/0x83b70c40/15310/IGN/27/28//none
[159]/0/160/1/0x83b72078/15308/IGN/29/30//none
[160]/0/161/1/0x83b734b0/15289/IGN/31/32//none
[161]/0/162/1/0x83b748e8/15287/IGN/33/34//none
[162]/0/163/1/0x83b75d20/15283/IGN/35/36//none
[164]/0/165/1/0x83b78590/15273/IGN/37/38//none
[165]/0/166/1/0x83b799c8/15271/IGN/39/40//none
[166]/0/167/1/0x83b7ae00/15269/IGN/41/42//none
[167]/0/168/1/0x83b7c238/15267/IGN/43/44//none
[168]/0/169/1/0x83b7d670/15265/SINGLE_NODE/45/46//none
[169]/0/170/1/0x83b7eaa8/15263/IGN/47/48//none
Dumping System_State and Fixed_SGA in process with ospid 15265
Dumping call stack for process with ospid 15265
Dumping call stack for process with ospid 15265
Dumping detailed process information for ospid 15265
Dumping process information for ospid 16060
Dumping process information for ospid 15794
Dumping process information for ospid 16058
Dumping process information for ospid 15265


我們分析下上述這些特定程式是什麼程式？




select addr,pid,spid,program from v$process where spid in 
(15265,
16060,
15794,
16058,
15265)


ADDR                    PID SPID         PROGRAM
---------------- ---------- ------------ ------------------------------------------------
0000000083A56E10          3 15265        oracle@jingfa1 (DIAG)
0000000083A61418         24 15794        oracle@jingfa1 (QMNC)
0000000083A61C00         25 16058        oracle@jingfa1 (q000)
0000000083A623E8         26 16060        oracle@jingfa1 (q001)


可見這些特定程式為oracle後些後臺程式，那麼為何要轉儲這些後臺程式，而不轉儲其它的後臺程式呢


經過對比TRACE FILE的第2部分,可見它轉儲的是第2部分中有等待事件的這些對應的程式資訊
Other chains found:
Chain 1 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
    <0/140/1/0x83a623e8/16060/Streams AQ: qmn slave idle wait>
Chain 2 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
    <0/144/1/0x83a61418/15794/Streams AQ: qmn coordinator idle>
Chain 3 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
    <0/146/103/0x83a5fc60/2145/No Wait>  ---不會轉儲它的程式，因為它沒有等待事件
Chain 4 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
    <0/152/9/0x83a61c00/16058/Streams AQ: waiting for time man>
Chain 5 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
    <0/169/1/0x83a56e10/15265/DIAG idle wait>






級別5還包含記憶體資訊的跟蹤轉儲，當然這塊內容有何用，暫時未知
*** 2015-11-10 11:09:50.349
KSTDUMP: In-memory trace dump
TIME:SEQ#        ORAPID   SID EVENT  OP DATA
========================================================================
0DA4AA36:00BBF60D    21     0 10280   2 kst: trace buffer wrapped on 11-10 11:04:22.309
0DA4AA36:00BBF60E    21     0 10280   3 kst: process info: ospid=23010 pso_num=21 pso_serial#=24
0DA4AA39:00BBF60F    21     0 10005   2 KSL WAIT END [PX Deq: reap credit] 0/0x0 0/0x0 0/0x0 time=8
0DA4AA3C:00BBF610    21     0 10005   1 KSL WAIT BEG [PX Idle Wait] 200/0xc8 74/0x4a 0/0x0
0DC9ECCA:00BBF7FA    21     0 10005   2 KSL WAIT END [PX Idle Wait] 200/0xc8 74/0x4a 0/0x0 time=2441784
0DC9ECD7:00BBF7FB    21     0 10005   1 KSL WAIT BEG [PX Deq: reap credit] 0/0x0 0/0x0 0/0x0
0DC9ECE1:00BBF7FC    21     0 10005   2 KSL WAIT END [PX Deq: reap credit] 0/0x0 0/0x0 0/0x0 time=10
0DC9ECE4:00BBF7FD    21     0 10005   1 KSL WAIT BEG [PX Idle Wait] 200/0xc8 75/0x4b 0/0x0






---級別10
State of nodes
([nodenum]/cnode/sid/sess_srno/session/ospid/state/start/finish/[adjlist]/predecessor):
[136]/0/137/6/0x83b54f70/31964/IGN/1/2//none
[139]/0/140/1/0x83b58c18/16060/SINGLE_NODE/3/4//none
[143]/0/144/1/0x83b5dcf8/15794/SINGLE_NODE/5/6//none
[145]/0/146/113/0x83b60568/9590/SINGLE_NODE_NW/7/8//none
[149]/0/150/1/0x83b65648/15354/IGN/9/10//none
[150]/0/151/1/0x83b66a80/15350/IGN/11/12//none
[151]/0/152/9/0x83b67eb8/16058/SINGLE_NODE/13/14//none
[152]/0/153/9/0x83b692f0/27178/IGN/15/16//none
[153]/0/154/1/0x83b6a728/15320/IGN/17/18//none
[154]/0/155/1/0x83b6bb60/15318/IGN/19/20//none
[155]/0/156/1/0x83b6cf98/15316/IGN/21/22//none
[156]/0/157/1/0x83b6e3d0/15314/IGN/23/24//none
[157]/0/158/1/0x83b6f808/15312/IGN/25/26//none
[158]/0/159/1/0x83b70c40/15310/IGN/27/28//none
[159]/0/160/1/0x83b72078/15308/IGN/29/30//none
[160]/0/161/1/0x83b734b0/15289/IGN/31/32//none
[161]/0/162/1/0x83b748e8/15287/IGN/33/34//none
[162]/0/163/1/0x83b75d20/15283/IGN/35/36//none
[164]/0/165/1/0x83b78590/15273/IGN/37/38//none
[165]/0/166/1/0x83b799c8/15271/IGN/39/40//none
[166]/0/167/1/0x83b7ae00/15269/IGN/41/42//none
[167]/0/168/1/0x83b7c238/15267/IGN/43/44//none
[168]/0/169/1/0x83b7d670/15265/SINGLE_NODE/45/46//none
[169]/0/170/1/0x83b7eaa8/15263/IGN/47/48//none


級別10比級別5，區別在於轉儲更多程式的具體資訊
Dumping System_State and Fixed_SGA in process with ospid 15265
Dumping call stack for process with ospid 15265
Dumping call stack for process with ospid 15265
Dumping detailed process information for ospid 15265
Dumping process information for ospid 31964
Dumping process information for ospid 16060
Dumping process information for ospid 15794
Dumping process information for ospid 15354
Dumping process information for ospid 15350
Dumping process information for ospid 16058
Dumping process information for ospid 27178
Dumping process information for ospid 15320
Dumping process information for ospid 15318
Dumping process information for ospid 15316
Dumping process information for ospid 15314
Dumping process information for ospid 15312
Dumping process information for ospid 15310
Dumping process information for ospid 15308
Dumping process information for ospid 15289
Dumping process information for ospid 15287
Dumping process information for ospid 15283
Dumping process information for ospid 15273
Dumping process information for ospid 15271
Dumping process information for ospid 15269
Dumping process information for ospid 15267
Dumping process information for ospid 15265
Dumping process information for ospid 15263




---分析下轉儲這些程式到底是哪些程式，和級別5有何區別


select addr,pid,spid,program from v$process where spid in 
(31964,
16060,
15794,
15354,
15350,
16058,
27178,
15320,
15318,
15316,
15314,
15312,
15310,
15308,
15289,
15287,
15283,
15273,
15271,
15269,
15267,
15265,
15263)


可見把所有的程式全轉儲了
ADDR                    PID SPID         PROGRAM
---------------- ---------- ------------ ------------------------------------------------
0000000083A56628          2 15263        oracle@jingfa1 (PMON)
0000000083A56E10          3 15265        oracle@jingfa1 (DIAG)
0000000083A575F8          4 15267        oracle@jingfa1 (PSP0)
0000000083A57DE0          5 15269        oracle@jingfa1 (LMON)
0000000083A585C8          6 15271        oracle@jingfa1 (LMD0)
0000000083A58DB0          7 15273        oracle@jingfa1 (LMS0)
0000000083A59598          8 15283        oracle@jingfa1 (MMAN)
0000000083A59D80          9 15287        oracle@jingfa1 (DBW0)
0000000083A5A568         10 15289        oracle@jingfa1 (LGWR)
0000000083A5AD50         11 15308        oracle@jingfa1 (CKPT)
0000000083A5B538         12 15310        oracle@jingfa1 (SMON)


ADDR                    PID SPID         PROGRAM
---------------- ---------- ------------ ------------------------------------------------
0000000083A5BD20         13 15312        oracle@jingfa1 (RECO)
0000000083A5C508         14 15314        oracle@jingfa1 (CJQ0)
0000000083A5CCF0         15 15316        oracle@jingfa1 (MMON)
0000000083A5D4D8         16 15318        oracle@jingfa1 (MMNL)
0000000083A5DCC0         17 15320        oracle@jingfa1 (LCK0)
0000000083A5E4A8         18 27178        oracle@jingfa1 (TNS V1-V3)
0000000083A5EC90         19 15350        oracle@jingfa1 (ASMB)
0000000083A5F478         20 15354        oracle@jingfa1 (RBAL)
0000000083A61418         24 15794        oracle@jingfa1 (QMNC)
0000000083A61C00         25 16058        oracle@jingfa1 (q000)
0000000083A623E8         26 16060        oracle@jingfa1 (q001)


ADDR                    PID SPID         PROGRAM
---------------- ---------- ------------ ------------------------------------------------
0000000083A62BD0         27 31964        oracle@jingfa1 (O001)




SQL> select count(*) from v$session;


  COUNT(*)
----------
        24


*** 2015-11-10 11:15:25.465
KSTDUMP: In-memory trace dump
TIME:SEQ#        ORAPID   SID EVENT  OP DATA
========================================================================
3428BA57:00C4F6E6    22   146 10005   1 KSL WAIT BEG [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0
3428BA59:00C4F6E7    22   146 10005   2 KSL WAIT END [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0 time=2
3428BA6D:00C4F6E8    22   146 10005   1 KSL WAIT BEG [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0
3428BA6E:00C4F6E9    22   146 10005   2 KSL WAIT END [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0 time=1
3428BA7B:00C4F6EA    22   146 10005   1 KSL WAIT BEG [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0
3428BA7C:00C4F6EB    22   146 10005   2 KSL WAIT END [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0 time=1
3428BA88:00C4F6EC    22   146 10005   1 KSL WAIT BEG [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0
3428BA89:00C4F6ED    22   146 10005   2 KSL WAIT END [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0 time=1
3428BA96:00C4F6EE    22   146 10005   1 KSL WAIT BEG [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0
3428BA97:00C4F6EF    22   146 10005   2 KSL WAIT END [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0 time=1
3428BAA4:00C4F6F0    22   146 10005   1 KSL WAIT BEG [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0
3428BAA5:00C4F6F1    22   146 10005   2 KSL WAIT END [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0 time=1
3428BAB1:00C4F6F2    22   146 10005   1 KSL WAIT BEG [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0
3428BAB2:00C4F6F3    22   146 10005   2 KSL WAIT END [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0 time=1
3428BABE:00C4F6F4    22   146 10005   1 KSL WAIT BEG [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0
3428BABF:00C4F6F5    22   146 10005   2 KSL WAIT END [ksdxexeotherwait] 0/0x0 0/0x0 0/0x0 time=1




來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/9240380/viewspace-1827410/，如需轉載，請註明出處，否則將追究法律責任。

相關文章