转载

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

背景

延续上一文：基于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 : :
<0>
Chain 2 : :
<0>
Chain 3 : :
<0> ---不会转储它的进程，因为它没有等待事件
Chain 4 : :
<0>
Chain 5 : :
<0>

级别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

正文到此结束