記一次oracle 19c RAC叢集重啟單節點DB啟動異常（二）
前面文章 記一次oracle 19c RAC叢集重啟單節點DB啟動異常（一） 提到懷疑是私網通訊問題導致的db hang，正好客戶有停機視窗，我們擷取了hang analyze日誌：
Trace file /oracle/app/diag/rdbms/crm/crm1/trace/crm1_ora_25549.trc
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.19.0.0.0
Build label: RDBMS_19.19.0.0.0DBRU_LINUX.X64_230321.1
ORACLE_HOME: /oracle/app/product/19c/db_1
System name: Linux
Node name: dbcrmserv1
Release: 5.4.17-2011.6.2.el7uek.x86_64
Version: #2 SMP Thu Sep 3 14:09:14 PDT 2020
Machine: x86_64
Instance name: crm1
Redo thread mounted by this instance: 0 <none>
Oracle process number: 201
Unix process pid: 25549, image: oracle@dbcrmserv1 (TNS V1-V3)
*** 2023-12-18T22:40:16.142315+08:00
*** SESSION ID:(1766.27689) 2023-12-18T22:40:16.142330+08:00
*** CLIENT ID:() 2023-12-18T22:40:16.142334+08:00
*** SERVICE NAME:() 2023-12-18T22:40:16.142337+08:00
*** MODULE NAME:(sqlplus@dbcrmserv1 (TNS V1-V3)) 2023-12-18T22:40:16.142339+08:00
*** ACTION NAME:() 2023-12-18T22:40:16.142342+08:00
*** CLIENT DRIVER:(SQL*PLUS) 2023-12-18T22:40:16.142344+08:00
Processing Oradebug command 'setmypid'
*** 2023-12-18T22:40:16.142363+08:00
Oradebug command 'setmypid' console output: <none>
*** 2023-12-18T22:40:21.556652+08:00
Processing Oradebug command 'unlimit'
*** 2023-12-18T22:40:21.556692+08:00
Oradebug command 'unlimit' console output: <none>
*** 2023-12-18T22:40:27.051160+08:00
Processing Oradebug command '-g all hanganalyze 3'
*** 2023-12-18T22:40:27.051236+08:00
Error while executing Oradebug command '-g all hanganalyze 3':
ORA-32743: command cannot be executed on remote instance
*** 2023-12-18T22:40:27.051255+08:00
Oradebug command '-g all hanganalyze 3' console output: <none>
*** 2023-12-18T22:41:04.141486+08:00
Processing Oradebug command 'hanganalyze 3'
*** 2023-12-18T22:41:04.363973+08:00
===============================================================================
HANG ANALYSIS:
instances (db_name.oracle_sid): crm.crm1
oradebug_node_dump_level: 3
analysis initiated by oradebug
os thread scheduling delay history: (sampling every 1.000000 secs)
0.000000 secs at [ 22:41:04 ]
NOTE: scheduling delay has not been sampled for 0.151989 secs
0.000000 secs from [ 22:41:00 - 22:41:05 ], 5 sec avg
0.000000 secs from [ 22:40:04 - 22:41:05 ], 1 min avg
0.000000 secs from [ 22:39:01 - 22:41:05 ], 5 min avg
vktm time drift history
===============================================================================
Chains most likely to have caused the hang:
[a] Chain 1 Signature: 'rdbms ipc message'<='ges enter server mode'
Chain 1 Signature Hash: 0x721a0c1f
[b] Chain 2 Signature: 'rdbms ipc message'<='ges cgs registration'
Chain 2 Signature Hash: 0x6268bedd
[c] Chain 3 Signature: 'rdbms ipc message'<='ges cgs registration'
Chain 3 Signature Hash: 0x6268bedd
===============================================================================
Non-intersecting chains:
-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (crm.crm1)
os id: 24482
process id: 199, oracle@dbcrmserv1 (SCM0)
session id: 1374
session serial #: 3006
}
is waiting for 'ges enter server mode' with wait info:
{
p1: ''=0x4
time in wait: 1 min 58 sec
timeout after: never
wait id: 3
blocking: 0 sessions
current sql_id: 0
current sql: <none>
short stack: ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+223<-__sighandler()<-semtimedop()+10<-skgpwwait()+187<-ksliwat()+2305<-kslwaitctx()+205<-kjsmesm()+1589<-kjsca_update_instance_map()+185<-kjscm_master_main()+85<-kjsc_main()+58<-ksvrdp_int()+1954<-opirip()+579<-opidrv()+581<-sou2o()+165<-opimai_real()+173<-ssthrdmain()+417<-main()+256<-__libc_start_main()+245
wait history:
* time between current wait and wait #1: 0.000186 sec
1. event: 'PGA memory operation'
time waited: 0.000004 sec
wait id: 2 p1: ''=0x50000
p2: ''=0x1
* time between wait #1 and #2: 0.000338 sec
2. event: 'PGA memory operation'
time waited: 0.000003 sec
wait id: 1 p1: ''=0x10000
p2: ''=0x1
* time between wait #2 and #3: 0.000247 sec
3. event: 'PGA memory operation'
time waited: 0.000007 sec
wait id: 0 p1: ''=0x10000
p2: ''=0x2
}
and is blocked by
=> Oracle session identified by:
{
instance: 1 (crm.crm1)
os id: 24046
process id: 22, oracle@dbcrmserv1 (LMON)
session id: 4313
session serial #: 35369
}
which is waiting for 'rdbms ipc message' with wait info:
{
p1: 'timeout'=0xa
time in wait: 0.087654 sec
timeout after: 0.012346 sec
wait id: 2845
blocking: 3 sessions
current sql_id: 0
current sql: <none>
short stack: ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+223<-__sighandler()<-epoll_wait()+19<-ipcor_wseti_wait()+94<-ipclw_wait()+528<-ksxpwait_ipclw()+919<-ksxpwait_int()+155<-ksxpwait()+319<-ksliwat()+2399<-kslwaitctx()+205<-ksarcv()+298<-kjclwmg()+38<-kjfcrfg()+97910<-kjfcln()+9278<-ksbrdp()+1167<-opirip()+541<-opidrv()+581<-sou2o()+165<-opimai_real()+173<-ssthrdmain()+417<-main()+256<-__libc_start_main()+245
wait history:
* time between current wait and wait #1: 0.000008 sec
1. event: 'CGS wait for IPC msg'
time waited: 0.000006 sec
wait id: 2844
* time between wait #1 and #2: 0.000069 sec
2. event: 'rdbms ipc message'
time waited: 0.100117 sec
wait id: 2843 p1: 'timeout'=0xa
* time between wait #2 and #3: 0.000008 sec
3. event: 'CGS wait for IPC msg'
time waited: 0.000007 sec
wait id: 2842
}
Chain 1 Signature: 'rdbms ipc message'<='ges enter server mode'
Chain 1 Signature Hash: 0x721a0c1f
-------------------------------------------------------------------------------
===============================================================================
Intersecting chains:
-------------------------------------------------------------------------------
Chain 2:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (crm.crm1)
os id: 23685
process id: 24999, oracle@dbcrmserv1 (TNS V1-V3)
session id: 7645
session serial #: 48279
}
is waiting for 'ges cgs registration' with wait info:
{
p1: 'where'=0x1
time in wait: 1 min 59 sec
timeout after: never
wait id: 118
blocking: 0 sessions
current sql_id: 0
current sql: <none>
short stack: ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+223<-__sighandler()<-semtimedop()+10<-skgpwwait()+187<-ksliwat()+2305<-kslwaitctx()+205<-kjudbm()+864<-ksqsgn()+187<-ksqnfy()+156<-kscnfy()+1221<-opistr_real()+1976<-opistr()+341<-opiodr()+1238<-ttcpip()+1240<-opitsk()+1900<-opiino()+936<-opiodr()+1238<-opidrv()+1094<-sou2o()+165<-opimai_real()+422<-ssthrdmain()+417<-main()+256<-__libc_start_main()+245
wait history:
* time between current wait and wait #1: 0.000049 sec
1. event: 'rdbms ipc reply'
time waited: 0.000042 sec
wait id: 117 p1: 'from_process'=0x7
* time between wait #1 and #2: 0.000090 sec
2. event: 'oracle thread bootstrap'
time waited: 0.049810 sec
wait id: 116 p1: 'pname'=0x0
* time between wait #2 and #3: 0.000023 sec
3. event: 'latch: shared pool'
time waited: 0.001302 sec
wait id: 115 p1: 'address'=0x609f05f0
p2: 'number'=0x26b
p3: 'why'=0x0
}
and is blocked by 'instance: 1, os id: 24046, session id: 4313',
which is a member of 'Chain 1'.
Chain 2 Signature: 'rdbms ipc message'<='ges cgs registration'
Chain 2 Signature Hash: 0x6268bedd
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 3:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (crm.crm1)
os id: 24377
process id: 135, oracle@dbcrmserv1 (FENC)
session id: 26461
session serial #: 53882
}
is waiting for 'ges cgs registration' with wait info:
{
p1: 'where'=0x0
time in wait: 1 min 56 sec
timeout after: 6 min 12 sec
wait id: 35
blocking: 0 sessions
current sql_id: 0
current sql: <none>
short stack: ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+223<-__sighandler()<-semtimedop()+10<-skgpwwait()+187<-ksliwat()+2305<-kslwaitctx()+205<-kfmdPriRegRclient()+1147<-kfmdProcessRclient()+276<-kfnbListenNodeReconf()+741<-ksbrdp()+1167<-opirip()+541<-opidrv()+581<-sou2o()+165<-opimai_real()+173<-ssthrdmain()+417<-main()+256<-__libc_start_main()+245
wait history:
* time between current wait and wait #1: 0.000013 sec
1. event: 'CSS operation: query'
time waited: 0.000126 sec
wait id: 34 p1: 'function_id'=0x25
* time between wait #1 and #2: 0.000000 sec
2. event: 'CSS operation: query'
time waited: 0.000002 sec
wait id: 33 p1: 'function_id'=0x2b
* time between wait #2 and #3: 0.000002 sec
3. event: 'CSS group registration'
time waited: 0.000587 sec
wait id: 32 p1: 'group_name1'=0x41534d5f
p2: 'group_name2'=0x434c4945
p3: 'mem_id'=0xffffffff
}
and is blocked by 'instance: 1, os id: 24046, session id: 4313',
which is a member of 'Chain 1'.
Chain 3 Signature: 'rdbms ipc message'<='ges cgs registration'
Chain 3 Signature Hash: 0x6268bedd
-------------------------------------------------------------------------------
===============================================================================
Sessions in an involuntary wait or not in a wait:
-------------------------------------------------------------------------------
Chain 4:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (crm.crm1)
os id: 24011
process id: 9, oracle@dbcrmserv1 (SA00)
session id: 1765
session serial #: 27930
}
is on CPU or Wait CPU:
{
last wait: 2 min 2 sec ago
blocking: 0 sessions
current sql_id: 0
current sql: <none>
short stack: ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+223<-__sighandler()<-ksmprepage_memory()+233<-ksm_prepage_sga_seg()+207<-skgmapply()+297<-ksmprepage()+218<-ksm_sslv_exec_cbk()+183<-ksvrdp_int()+1954<-opirip()+579<-opidrv()+581<-sou2o()+165<-opimai_real()+173<-ssthrdmain()+417<-main()+256<-__libc_start_main()+245
wait history:
1. event: 'PGA memory operation'
time waited: 0.000003 sec
wait id: 1 p1: ''=0x10000
p2: ''=0x1
* time between wait #1 and #2: 0.000229 sec
2. event: 'PGA memory operation'
time waited: 0.000007 sec
wait id: 0 p1: ''=0x10000
p2: ''=0x2
}
Chain 4 Signature: 'CPU or Wait CPU'
Chain 4 Signature Hash: 0xabe82914
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 5:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (crm.crm1)
os id: 24372
process id: 133, oracle@dbcrmserv1 (ASMB)
session id: 26069
session serial #: 27341
}
is waiting for 'ASMB cookie valid check' with wait info:
{
p1: ''=0x1
time in wait: 1 min 59 sec
timeout after: 10 min 13 sec
wait id: 39
blocking: 0 sessions
current sql_id: 0
current sql: <none>
short stack: ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+223<-__sighandler()<-semtimedop()+10<-skgpwwait()+187<-ksliwat()+2305<-kslwaitctx()+205<-kfmdGetRclientCookie()+2127<-kfnbInstanceReg()+1395<-kfnbRegister()+784<-kfnOpExecuteWithWait()+9908<-kfnbRun()+18338<-ksbrdp()+1167<-opirip()+541<-opidrv()+581<-sou2o()+165<-opimai_real()+173<-ssthrdmain()+417<-main()+256<-__libc_start_main()+245
wait history:
* time between current wait and wait #1: 0.005172 sec
1. event: 'ASM background starting'
time waited: 0.000000 sec
wait id: 38 p1: 'locn'=0x0
p2: 'asmbidx'=0x0
p3: 'group'=0x0
* time between wait #1 and #2: 0.000426 sec
2. event: 'ASM file metadata operation'
time waited: 0.000042 sec (last interval)
time waited: 0.037239 sec (total)
wait id: 29 p1: 'msgop'=0x0
p2: 'locn'=0x9
* time between wait #2 and #3: 0.000000 sec
3. event: 'latch: shared pool'
time waited: 0.003409 sec
wait id: 37 p1: 'address'=0x609f0690
p2: 'number'=0x26b
p3: 'why'=0x0
}
Chain 5 Signature: 'ASMB cookie valid check'
Chain 5 Signature Hash: 0xc8e124c2
-------------------------------------------------------------------------------
===============================================================================
Extra information that will be dumped at higher levels:
[level 4] : 1 node dumps -- [LEAF] [LEAF_NW]
[level 5] : 5 node dumps -- [NO_WAIT] [INVOL_WT] [SINGLE_NODE] [NLEAF] [SINGLE_NODE_NW]
State of ALL nodes
([nodenum]/cnode/sid/sess_srno/session/ospid/state/[adjlist]):
[1373]/1/1374/3006/0x1263179ae8/24482/NLEAF/[4312]
[1764]/1/1765/27930/0x12c32bfb30/24011/SINGLE_NODE_NW/
[4312]/1/4313/35369/0x13036c2160/24046/LEAF/
[7644]/1/7645/48279/0x1323947da0/23685/NLEAF/[4312]
[26068]/1/26069/27341/0x12653dd8c0/24372/SINGLE_NODE/
[26460]/1/26461/53882/0x12c55260f0/24377/NLEAF/[4312]
*** 2023-12-18T22:41:04.365581+08:00
===============================================================================
END OF HANG ANALYSIS
===============================================================================
*** 2023-12-18T22:41:04.365740+08:00
===============================================================================
HANG ANALYSIS DUMPS:
oradebug_node_dump_level: 3
===============================================================================
State of LOCAL nodes
([nodenum]/cnode/sid/sess_srno/session/ospid/state/[adjlist]):
[1373]/1/1374/3006/0x1263179ae8/24482/NLEAF/[4312]
[1764]/1/1765/27930/0x12c32bfb30/24011/SINGLE_NODE_NW/
[4312]/1/4313/35369/0x13036c2160/24046/LEAF/
[7644]/1/7645/48279/0x1323947da0/23685/NLEAF/[4312]
[26068]/1/26069/27341/0x12653dd8c0/24372/SINGLE_NODE/
[26460]/1/26461/53882/0x12c55260f0/24377/NLEAF/[4312]
No processes qualify for dumping.
===============================================================================
HANG ANALYSIS DUMPS: END
===============================================================================
*** 2023-12-18T22:41:04.366110+08:00
Oradebug command 'hanganalyze 3' console output:
Hang Analysis in /oracle/app/diag/rdbms/crm/crm1/trace/crm1_ora_25549.trc
*** 2023-12-18T22:41:36.959054+08:00
Processing Oradebug command 'hanganalyze 3'
*** 2023-12-18T22:41:37.053369+08:00
===============================================================================
HANG ANALYSIS:
instances (db_name.oracle_sid): crm.crm1
oradebug_node_dump_level: 3
analysis initiated by oradebug
os thread scheduling delay history: (sampling every 1.000000 secs)
0.000000 secs at [ 22:41:36 ]
NOTE: scheduling delay has not been sampled for 0.073344 secs
0.000000 secs from [ 22:41:32 - 22:41:37 ], 5 sec avg
0.000000 secs from [ 22:40:37 - 22:41:37 ], 1 min avg
0.000000 secs from [ 22:39:01 - 22:41:37 ], 5 min avg
vktm time drift history
===============================================================================
Chains most likely to have caused the hang:
[a] Chain 1 Signature: 'rdbms ipc message'<='ges enter server mode'
Chain 1 Signature Hash: 0x721a0c1f
[b] Chain 2 Signature: 'rdbms ipc message'<='ges cgs registration'
Chain 2 Signature Hash: 0x6268bedd
[c] Chain 3 Signature: 'rdbms ipc message'<='ges cgs registration'
Chain 3 Signature Hash: 0x6268bedd
===============================================================================
Non-intersecting chains:
-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (crm.crm1)
os id: 24482
process id: 199, oracle@dbcrmserv1 (SCM0)
session id: 1374
session serial #: 3006
}
is waiting for 'ges enter server mode' with wait info:
{
p1: ''=0x4
time in wait: 2 min 31 sec
timeout after: never
wait id: 3
blocking: 0 sessions
current sql_id: 0
current sql: <none>
short stack: ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+223<-__sighandler()<-semtimedop()+10<-skgpwwait()+187<-ksliwat()+2305<-kslwaitctx()+205<-kjsmesm()+1589<-kjsca_update_instance_map()+185<-kjscm_master_main()+85<-kjsc_main()+58<-ksvrdp_int()+1954<-opirip()+579<-opidrv()+581<-sou2o()+165<-opimai_real()+173<-ssthrdmain()+417<-main()+256<-__libc_start_main()+245
wait history:
* time between current wait and wait #1: 0.000186 sec
1. event: 'PGA memory operation'
time waited: 0.000004 sec
wait id: 2 p1: ''=0x50000
p2: ''=0x1
* time between wait #1 and #2: 0.000338 sec
2. event: 'PGA memory operation'
time waited: 0.000003 sec
wait id: 1 p1: ''=0x10000
p2: ''=0x1
* time between wait #2 and #3: 0.000247 sec
3. event: 'PGA memory operation'
time waited: 0.000007 sec
wait id: 0 p1: ''=0x10000
p2: ''=0x2
}
and is blocked by
=> Oracle session identified by:
{
instance: 1 (crm.crm1)
os id: 24046
process id: 22, oracle@dbcrmserv1 (LMON)
session id: 4313
session serial #: 35369
}
which is waiting for 'rdbms ipc message' with wait info:
{
p1: 'timeout'=0xa
time in wait: 0.095470 sec
timeout after: 0.004530 sec
wait id: 3515
blocking: 3 sessions
current sql_id: 0
current sql: <none>
short stack: ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+223<-__sighandler()<-epoll_wait()+19<-ipcor_wseti_wait()+94<-ipclw_wait()+528<-ksxpwait_ipclw()+919<-ksxpwait_int()+155<-ksxpwait()+319<-ksliwat()+2399<-kslwaitctx()+205<-ksarcv()+298<-kjclwmg()+38<-kjfcrfg()+97910<-kjfcln()+9278<-ksbrdp()+1167<-opirip()+541<-opidrv()+581<-sou2o()+165<-opimai_real()+173<-ssthrdmain()+417<-main()+256<-__libc_start_main()+245
wait history:
* time between current wait and wait #1: 0.000009 sec
1. event: 'CGS wait for IPC msg'
time waited: 0.000006 sec
wait id: 3514
* time between wait #1 and #2: 0.000006 sec
2. event: 'rdbms ipc message'
time waited: 0.100173 sec
wait id: 3513 p1: 'timeout'=0xa
* time between wait #2 and #3: 0.000004 sec
3. event: 'CGS wait for IPC msg'
time waited: 0.000003 sec
wait id: 3512
}
Chain 1 Signature: 'rdbms ipc message'<='ges enter server mode'
Chain 1 Signature Hash: 0x721a0c1f
-------------------------------------------------------------------------------
===============================================================================
Intersecting chains:
-------------------------------------------------------------------------------
Chain 2:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (crm.crm1)
os id: 23685
process id: 24999, oracle@dbcrmserv1 (TNS V1-V3)
session id: 7645
session serial #: 48279
}
is waiting for 'ges cgs registration' with wait info:
{
p1: 'where'=0x1
time in wait: 2 min 32 sec
timeout after: never
wait id: 118
blocking: 0 sessions
current sql_id: 0
current sql: <none>
short stack: ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+223<-__sighandler()<-semtimedop()+10<-skgpwwait()+187<-ksliwat()+2305<-kslwaitctx()+205<-kjudbm()+864<-ksqsgn()+187<-ksqnfy()+156<-kscnfy()+1221<-opistr_real()+1976<-opistr()+341<-opiodr()+1238<-ttcpip()+1240<-opitsk()+1900<-opiino()+936<-opiodr()+1238<-opidrv()+1094<-sou2o()+165<-opimai_real()+422<-ssthrdmain()+417<-main()+256<-__libc_start_main()+245
wait history:
* time between current wait and wait #1: 0.000049 sec
1. event: 'rdbms ipc reply'
time waited: 0.000042 sec
wait id: 117 p1: 'from_process'=0x7
* time between wait #1 and #2: 0.000090 sec
2. event: 'oracle thread bootstrap'
time waited: 0.049810 sec
wait id: 116 p1: 'pname'=0x0
* time between wait #2 and #3: 0.000023 sec
3. event: 'latch: shared pool'
time waited: 0.001302 sec
wait id: 115 p1: 'address'=0x609f05f0
p2: 'number'=0x26b
p3: 'why'=0x0
}
and is blocked by 'instance: 1, os id: 24046, session id: 4313',
which is a member of 'Chain 1'.
Chain 2 Signature: 'rdbms ipc message'<='ges cgs registration'
Chain 2 Signature Hash: 0x6268bedd
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 3:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (crm.crm1)
os id: 24377
process id: 135, oracle@dbcrmserv1 (FENC)
session id: 26461
session serial #: 53882
}
is waiting for 'ges cgs registration' with wait info:
{
p1: 'where'=0x0
time in wait: 2 min 28 sec
timeout after: 5 min 40 sec
wait id: 35
blocking: 0 sessions
current sql_id: 0
current sql: <none>
short stack: ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+223<-__sighandler()<-semtimedop()+10<-skgpwwait()+187<-ksliwat()+2305<-kslwaitctx()+205<-kfmdPriRegRclient()+1147<-kfmdProcessRclient()+276<-kfnbListenNodeReconf()+741<-ksbrdp()+1167<-opirip()+541<-opidrv()+581<-sou2o()+165<-opimai_real()+173<-ssthrdmain()+417<-main()+256<-__libc_start_main()+245
wait history:
* time between current wait and wait #1: 0.000013 sec
1. event: 'CSS operation: query'
time waited: 0.000126 sec
wait id: 34 p1: 'function_id'=0x25
* time between wait #1 and #2: 0.000000 sec
2. event: 'CSS operation: query'
time waited: 0.000002 sec
wait id: 33 p1: 'function_id'=0x2b
* time between wait #2 and #3: 0.000002 sec
3. event: 'CSS group registration'
time waited: 0.000587 sec
wait id: 32 p1: 'group_name1'=0x41534d5f
p2: 'group_name2'=0x434c4945
p3: 'mem_id'=0xffffffff
}
and is blocked by 'instance: 1, os id: 24046, session id: 4313',
which is a member of 'Chain 1'.
Chain 3 Signature: 'rdbms ipc message'<='ges cgs registration'
Chain 3 Signature Hash: 0x6268bedd
-------------------------------------------------------------------------------
===============================================================================
Sessions in an involuntary wait or not in a wait:
-------------------------------------------------------------------------------
Chain 4:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (crm.crm1)
os id: 24372
process id: 133, oracle@dbcrmserv1 (ASMB)
session id: 26069
session serial #: 27341
}
is waiting for 'ASMB cookie valid check' with wait info:
{
p1: ''=0x1
time in wait: 2 min 32 sec
timeout after: 9 min 41 sec
wait id: 39
blocking: 0 sessions
current sql_id: 0
current sql: <none>
short stack: ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+223<-__sighandler()<-semtimedop()+10<-skgpwwait()+187<-ksliwat()+2305<-kslwaitctx()+205<-kfmdGetRclientCookie()+2127<-kfnbInstanceReg()+1395<-kfnbRegister()+784<-kfnOpExecuteWithWait()+9908<-kfnbRun()+18338<-ksbrdp()+1167<-opirip()+541<-opidrv()+581<-sou2o()+165<-opimai_real()+173<-ssthrdmain()+417<-main()+256<-__libc_start_main()+245
wait history:
* time between current wait and wait #1: 0.005172 sec
1. event: 'ASM background starting'
time waited: 0.000000 sec
wait id: 38 p1: 'locn'=0x0
p2: 'asmbidx'=0x0
p3: 'group'=0x0
* time between wait #1 and #2: 0.000426 sec
2. event: 'ASM file metadata operation'
time waited: 0.000042 sec (last interval)
time waited: 0.037239 sec (total)
wait id: 29 p1: 'msgop'=0x0
p2: 'locn'=0x9
* time between wait #2 and #3: 0.000000 sec
3. event: 'latch: shared pool'
time waited: 0.003409 sec
wait id: 37 p1: 'address'=0x609f0690
p2: 'number'=0x26b
p3: 'why'=0x0
}
Chain 4 Signature: 'ASMB cookie valid check'
Chain 4 Signature Hash: 0xc8e124c2
-------------------------------------------------------------------------------
===============================================================================
Extra information that will be dumped at higher levels:
[level 4] : 1 node dumps -- [LEAF] [LEAF_NW]
[level 5] : 4 node dumps -- [NO_WAIT] [INVOL_WT] [SINGLE_NODE] [NLEAF] [SINGLE_NODE_NW]
State of ALL nodes
([nodenum]/cnode/sid/sess_srno/session/ospid/state/[adjlist]):
[1373]/1/1374/3006/0x1263179ae8/24482/NLEAF/[4312]
[4312]/1/4313/35369/0x13036c2160/24046/LEAF/
[7644]/1/7645/48279/0x1323947da0/23685/NLEAF/[4312]
[26068]/1/26069/27341/0x12653dd8c0/24372/SINGLE_NODE/
[26460]/1/26461/53882/0x12c55260f0/24377/NLEAF/[4312]
*** 2023-12-18T22:41:37.054430+08:00
===============================================================================
END OF HANG ANALYSIS
===============================================================================
*** 2023-12-18T22:41:37.054574+08:00
===============================================================================
HANG ANALYSIS DUMPS:
oradebug_node_dump_level: 3
===============================================================================
State of LOCAL nodes
([nodenum]/cnode/sid/sess_srno/session/ospid/state/[adjlist]):
[1373]/1/1374/3006/0x1263179ae8/24482/NLEAF/[4312]
[4312]/1/4313/35369/0x13036c2160/24046/LEAF/
[7644]/1/7645/48279/0x1323947da0/23685/NLEAF/[4312]
[26068]/1/26069/27341/0x12653dd8c0/24372/SINGLE_NODE/
[26460]/1/26461/53882/0x12c55260f0/24377/NLEAF/[4312]
No processes qualify for dumping.
===============================================================================
HANG ANALYSIS DUMPS: END
===============================================================================
*** 2023-12-18T22:41:37.054926+08:00
Oradebug command 'hanganalyze 3' console output:
Hang Analysis in /oracle/app/diag/rdbms/crm/crm1/trace/crm1_ora_25549.trc
Trace file /oracle/app/diag/rdbms/crm/crm1/trace/crm1_ora_28097.trc Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production Version 19.19.0.0.0 Build label: RDBMS_19.19.0.0.0DBRU_LINUX.X64_230321.1 ORACLE_HOME: /oracle/app/product/19c/db_1 System name: Linux Node name: dbcrmserv1 Release: 5.4.17-2011.6.2.el7uek.x86_64 Version: #2 SMP Thu Sep 3 14:09:14 PDT 2020 Machine: x86_64 Instance name: crm1 Redo thread mounted by this instance: 0 <none> Oracle process number: 9 Unix process pid: 28097, image: oracle@dbcrmserv1 (TNS V1-V3) *** 2023-12-18T22:42:27.591841+08:00 *** SESSION ID:(1766.32428) 2023-12-18T22:42:27.591856+08:00 *** CLIENT ID:() 2023-12-18T22:42:27.591860+08:00 *** SERVICE NAME:() 2023-12-18T22:42:27.591862+08:00 *** MODULE NAME:(sqlplus@dbcrmserv1 (TNS V1-V3)) 2023-12-18T22:42:27.591865+08:00 *** ACTION NAME:() 2023-12-18T22:42:27.591868+08:00 *** CLIENT DRIVER:(SQL*PLUS) 2023-12-18T22:42:27.591870+08:00 Processing Oradebug command 'setmypid' *** 2023-12-18T22:42:27.591888+08:00 Oradebug command 'setmypid' console output: <none> *** 2023-12-18T22:42:32.004405+08:00 Processing Oradebug command 'unlimit' *** 2023-12-18T22:42:32.004475+08:00 Oradebug command 'unlimit' console output: <none> *** 2023-12-18T22:42:43.498864+08:00 Processing Oradebug command 'dump systemstate 258' System state caller's stack: Short stack dump: ksedsts()+426<-ksdxfstk()+58<-ksdxdocmdmultex()+6024<-ksdxdocmdmult()+55<-ksudmp_proc_short_stack()+373<-ksudss_opt()+307<-ksdxdmp()+1425<-ksdxfdmp()+152<-ksdxen_int()+3381<-opiodr()+1238<-ttcpip()+1240<-opitsk()+1900<-opiino()+936<-opiodr()+1238<-opidrv()+1094<-sou2o()+165<-opimai_real()+422<-ssthrdmain()+417<-main()+256<-__libc_start_main()+245 =================================================== SYSTEM STATE (level=2, with short stacks) ------------ Dumping the Process Summary 1: PSEUDO process 2: PMON ospid 23970 sid 393 ser 23178, waiting for 'pmon timer' 3: CLMN ospid 23975 sid 589 ser 14477, waiting for 'pmon timer' 4: PSP0 ospid 23979 sid 785 ser 20379, waiting for 'rdbms ipc message' 5: IPC0 ospid 23992 sid 981 ser 52769, waiting for 'rdbms ipc message' 6: VKTM ospid 23997 sid 1177 ser 39579, waiting for 'VKTM Logical Idle Wait' 7: GEN0 ospid 24003 sid 1373 ser 3038, waiting for 'rdbms ipc message' 8: MMAN ospid 24007 sid 1569 ser 46577, waiting for 'rdbms ipc message' 9: USER ospid 28097 sid 1766 ser 32428, 10: GEN1 ospid 24018_24019 sid 1961 ser 57758, waiting for 'rdbms ipc message' 11: SCMN ospid 24018_24018 sid 2157 ser 16215, waiting for 'watchdog main loop' 12: DIAG ospid 24021 sid 2353 ser 12192, waiting for 'process diagnostic dump' 13: OFSD ospid 24023_24024 sid 2549 ser 33299, waiting for 'OFS idle' 14: SCMN ospid 24023_24023 sid 2745 ser 13146, waiting for 'watchdog main loop' 15: DBRM ospid 24026 sid 2941 ser 49489, waiting for 'rdbms ipc message' 16: VKRM ospid 24030 sid 3137 ser 22608, waiting for 'VKRM Idle' 17: PING ospid 24032 sid 3333 ser 36422, waiting for 'PING' 18: SVCB ospid 24034 sid 3529 ser 55334, waiting for 'rdbms ipc message' 19: ACMS ospid 24036 sid 3725 ser 42418, waiting for 'rdbms ipc message' 20: PMAN ospid 24040 sid 3921 ser 8793, waiting for 'pman timer' 21: DIA0 ospid 24044 sid 4117 ser 30744, waiting for 'DIAG idle wait' 22: LMON ospid 24046 sid 4313 ser 35369, waiting for 'rdbms ipc message' 23: LMD0 ospid 24050 sid 4509 ser 38337, waiting for 'ges remote message' 24: LMS0 ospid 24052_24060 sid 4705 ser 42218, waiting for 'gcs remote message' 25: SCMN ospid 24052_24052 sid 4901 ser 43628, waiting for 'watchdog main loop' 26: LMS1 ospid 24054_24066 sid 5097 ser 48791, waiting for 'gcs remote message' 27: SCMN ospid 24054_24054 sid 5293 ser 29230, waiting for 'watchdog main loop' 28: LMS2 ospid 24056_24069 sid 5489 ser 1150, waiting for 'gcs remote message' 29: SCMN ospid 24056_24056 sid 5685 ser 21140, waiting for 'watchdog main loop' 30: LMS3 ospid 24058_24076 sid 5881 ser 25384, waiting for 'gcs remote message' 31: SCMN ospid 24058_24058 sid 6077 ser 5385, waiting for 'watchdog main loop' 32: LMS4 ospid 24062_24081 sid 6273 ser 20985, waiting for 'gcs remote message' 33: SCMN ospid 24062_24062 sid 6469 ser 41547, waiting for 'watchdog main loop' 34: LMS5 ospid 24067_24086 sid 6665 ser 35820, waiting for 'gcs remote message' 35: SCMN ospid 24067_24067 sid 6861 ser 36936, waiting for 'watchdog main loop' 36: LMS6 ospid 24072_24092 sid 7057 ser 23893, waiting for 'gcs remote message' 37: SCMN ospid 24072_24072 sid 7253 ser 54797, waiting for 'watchdog main loop' 38: LMS7 ospid 24077_24097 sid 7449 ser 37036, waiting for 'gcs remote message' 39: SCMN ospid 24077_24077 sid 7646 ser 10645, waiting for 'watchdog main loop' 40: LMS8 ospid 24082_24102 sid 7841 ser 20174, waiting for 'gcs remote message' 41: SCMN ospid 24082_24082 sid 8037 ser 65090, waiting for 'watchdog main loop' 42: LMS9 ospid 24087_24105 sid 8233 ser 46812, waiting for 'gcs remote message' 43: SCMN ospid 24087_24087 sid 8429 ser 29516, waiting for 'watchdog main loop' 44: LMSA ospid 24093_24113 sid 8625 ser 24194, waiting for 'gcs remote message' 45: SCMN ospid 24093_24093 sid 8821 ser 47030, waiting for 'watchdog main loop' 46: LMSB ospid 24095_24112 sid 9017 ser 4423, waiting for 'gcs remote message' 47: SCMN ospid 24095_24095 sid 9213 ser 45023, waiting for 'watchdog main loop' 48: LMSC ospid 24100_24123 sid 9409 ser 38699, waiting for 'gcs remote message' 49: SCMN ospid 24100_24100 sid 9605 ser 41847, waiting for 'watchdog main loop' 50: LMSD ospid 24106_24126 sid 9801 ser 36167, waiting for 'gcs remote message' 51: SCMN ospid 24106_24106 sid 9997 ser 46859, waiting for 'watchdog main loop' 52: LMSE ospid 24109_24131 sid 10193 ser 58880, waiting for 'gcs remote message' 53: SCMN ospid 24109_24109 sid 10389 ser 4156, waiting for 'watchdog main loop' 54: LMSF ospid 24116_24134 sid 10585 ser 39018, waiting for 'gcs remote message' 55: SCMN ospid 24116_24116 sid 10781 ser 4162, waiting for 'watchdog main loop' 56: LMSG ospid 24122_24146 sid 10977 ser 46975, waiting for 'gcs remote message' 57: SCMN ospid 24122_24122 sid 11173 ser 54402, waiting for 'watchdog main loop' 58: LMSH ospid 24125_24150 sid 11369 ser 57150, waiting for 'gcs remote message' 59: SCMN ospid 24125_24125 sid 11565 ser 5306, waiting for 'watchdog main loop' 60: LMSI ospid 24129_24160 sid 11761 ser 10437, waiting for 'gcs remote message' 61: SCMN ospid 24129_24129 sid 11957 ser 3413, waiting for 'watchdog main loop' 62: LMSJ ospid 24133_24163 sid 12153 ser 5476, waiting for 'gcs remote message' 63: SCMN ospid 24133_24133 sid 12349 ser 37391, waiting for 'watchdog main loop' 64: LMSK ospid 24138_24158 sid 12545 ser 1470, waiting for 'gcs remote message' 65: SCMN ospid 24138_24138 sid 12741 ser 49306, waiting for 'watchdog main loop' 66: LMSL ospid 24144_24174 sid 12937 ser 8393, waiting for 'gcs remote message' 67: SCMN ospid 24144_24144 sid 13133 ser 56587, waiting for 'watchdog main loop' 68: LMSM ospid 24147_24175 sid 13329 ser 52521, waiting for 'gcs remote message' 69: SCMN ospid 24147_24147 sid 13525 ser 44263, waiting for 'watchdog main loop' 70: LMSN ospid 24149_24179 sid 13721 ser 51777, waiting for 'gcs remote message' 71: SCMN ospid 24149_24149 sid 13917 ser 19733, waiting for 'watchdog main loop' 72: LMSO ospid 24152_24186 sid 14113 ser 62359, waiting for 'gcs remote message' 73: SCMN ospid 24152_24152 sid 14309 ser 53303, waiting for 'watchdog main loop' 74: LMSP ospid 24155_24189 sid 14505 ser 49990, waiting for 'gcs remote message' 75: SCMN ospid 24155_24155 sid 14701 ser 23216, waiting for 'watchdog main loop' 76: LMSQ ospid 24162_24197 sid 14897 ser 29595, waiting for 'gcs remote message' 77: SCMN ospid 24162_24162 sid 15093 ser 6756, waiting for 'watchdog main loop' 78: LMSR ospid 24166_24198 sid 15289 ser 26270, waiting for 'gcs remote message' 79: SCMN ospid 24166_24166 sid 15485 ser 49383, waiting for 'watchdog main loop' 80: LMSS ospid 24173_24205 sid 15681 ser 4628, waiting for 'gcs remote message' 81: SCMN ospid 24173_24173 sid 15877 ser 40138, waiting for 'watchdog main loop' 82: LMST ospid 24177_24206 sid 16073 ser 34382, waiting for 'gcs remote message' 83: SCMN ospid 24177_24177 sid 16269 ser 53366, waiting for 'watchdog main loop' 84: LMSU ospid 24180_24209 sid 16465 ser 14389, waiting for 'gcs remote message' 85: SCMN ospid 24180_24180 sid 16661 ser 43939, waiting for 'watchdog main loop' 86: LMSV ospid 24187_24217 sid 16857 ser 43104, waiting for 'gcs remote message' 87: SCMN ospid 24187_24187 sid 17053 ser 41472, waiting for 'watchdog main loop' 88: LMD1 ospid 24192 sid 17249 ser 15817, waiting for 'ges remote message' 89: LMD2 ospid 24208 sid 17445 ser 47098, waiting for 'ges remote message' 90: LMD3 ospid 24220 sid 17641 ser 40807, waiting for 'ges remote message' 91: LMD4 ospid 24226 sid 17837 ser 31379, waiting for 'ges remote message' 92: RMS0 ospid 24230 sid 18033 ser 35894, waiting for 'rdbms ipc message' 93: LMHB ospid 24234 sid 18229 ser 35439, waiting for 'GCR sleep' 94: LCK1 ospid 24236 sid 18425 ser 48765, waiting for 'rdbms ipc message' 95: DBW0 ospid 24240 sid 18621 ser 60008, waiting for 'rdbms ipc message' 96: DBW1 ospid 24244 sid 18817 ser 4641, waiting for 'rdbms ipc message' 97: DBW2 ospid 24249 sid 19013 ser 24424, waiting for 'rdbms ipc message' 98: DBW3 ospid 24253 sid 19209 ser 28054, waiting for 'rdbms ipc message' 99: DBW4 ospid 24257 sid 19405 ser 393, waiting for 'rdbms ipc message' 100: DBW5 ospid 24261 sid 19601 ser 54016, waiting for 'rdbms ipc message' 101: DBW6 ospid 24265 sid 19797 ser 31163, waiting for 'rdbms ipc message' 102: DBW7 ospid 24269 sid 19993 ser 20810, waiting for 'rdbms ipc message' 103: DBW8 ospid 24273 sid 20189 ser 35966, waiting for 'rdbms ipc message' 104: DBW9 ospid 24277 sid 20385 ser 13912, waiting for 'rdbms ipc message' 105: DBWA ospid 24281 sid 20581 ser 55174, waiting for 'rdbms ipc message' 106: DBWB ospid 24285 sid 20777 ser 36713, waiting for 'rdbms ipc message' 107: DBWC ospid 24289 sid 20973 ser 8996, waiting for 'rdbms ipc message' 108: DBWD ospid 24293 sid 21169 ser 7009, waiting for 'rdbms ipc message' 109: DBWE ospid 24297 sid 21365 ser 42288, waiting for 'rdbms ipc message' 110: DBWF ospid 24301 sid 21561 ser 26826, waiting for 'rdbms ipc message' 111: DBWG ospid 24305 sid 21757 ser 17353, waiting for 'rdbms ipc message' 112: DBWH ospid 24309 sid 21953 ser 59614, waiting for 'rdbms ipc message' 113: DBWI ospid 24313 sid 22149 ser 52669, waiting for 'rdbms ipc message' 114: DBWJ ospid 24318 sid 22345 ser 24791, waiting for 'rdbms ipc message' 115: GCR0 ospid 24322 sid 22541 ser 23177, waiting for 'GCR sleep' 116: DBWK ospid 24324 sid 22737 ser 53876, waiting for 'rdbms ipc message' 117: DBWL ospid 24328 sid 22933 ser 5135, waiting for 'rdbms ipc message' 118: DBWM ospid 24332 sid 23129 ser 39494, waiting for 'rdbms ipc message' 119: DBWN ospid 24336 sid 23325 ser 29095, waiting for 'rdbms ipc message' 120: LGWR ospid 24340 sid 23521 ser 31567, waiting for 'rdbms ipc message' 121: CKPT ospid 24344 sid 23717 ser 402, waiting for 'rdbms ipc message' 122: SMON ospid 24348 sid 23913 ser 65061, waiting for 'smon timer' 123: SMCO ospid 24352 sid 24109 ser 13828, waiting for 'rdbms ipc message' 124: CR00 ospid 24052_24353 sid 24305 ser 63921, waiting for 'LMS CR slave timer' 125: RECO ospid 24355 sid 24501 ser 6078, waiting for 'rdbms ipc message' 126: RS00 ospid 24052_24356 sid 24697 ser 54630, waiting for 'gcs yield cpu' 127: LREG ospid 24358 sid 24893 ser 47944, waiting for 'lreg timer' 128: CR00 ospid 24054_24359 sid 25089 ser 32914, waiting for 'LMS CR slave timer' 129: PXMN ospid 24363 sid 25285 ser 62326, waiting for 'rdbms ipc message' 130: W000 ospid 24365 sid 25481 ser 53788, waiting for 'Space Manager: slave idle wait' 131: RS01 ospid 24054_24366 sid 25677 ser 46629, waiting for 'gcs yield cpu' 132: RBAL ospid 24368 sid 25873 ser 15488, waiting for 'rdbms ipc message' 133: ASMB ospid 24372 sid 26069 ser 27341, waiting for 'ASMB cookie valid check' 134: CR00 ospid 24056_24373 sid 26265 ser 27856, waiting for 'LMS CR slave timer' 135: FENC ospid 24377 sid 26461 ser 53882, waiting for 'ges cgs registration' Blocked by inst: 1, sid: 4313, ser: 35369 Final Blocker inst: 1, sid: 4313, ser: 35369 136: CR00 ospid 24062_24380 sid 26657 ser 9424, waiting for 'LMS CR slave timer' 137: MMON ospid 24382 sid 26853 ser 31115, waiting for 'rdbms ipc message' 138: MMNL ospid 24386 sid 27049 ser 51370, waiting for 'rdbms ipc message' 139: CR00 ospid 24072_24398 sid 27245 ser 31110, waiting for 'LMS CR slave timer' 140: W001 ospid 24400 sid 27441 ser 24494, waiting for 'Space Manager: slave idle wait' 141: CR00 ospid 24058_24401 sid 27637 ser 57145, waiting for 'LMS CR slave timer' 142: CR00 ospid 24067_24402 sid 27833 ser 30909, waiting for 'LMS CR slave timer' 143: CR00 ospid 24093_24404 sid 28029 ser 34804, waiting for 'LMS CR slave timer' 144: RS02 ospid 24056_24405 sid 28225 ser 40193, waiting for 'gcs yield cpu' 145: CR00 ospid 24082_24406 sid 28421 ser 3118, waiting for 'LMS CR slave timer' 146: CR00 ospid 24077_24407 sid 28617 ser 62052, waiting for 'LMS CR slave timer' 147: RS04 ospid 24062_24408 sid 28813 ser 33088, waiting for 'gcs yield cpu' 148: CR00 ospid 24100_24409 sid 29009 ser 4243, waiting for 'LMS CR slave timer' 149: CR00 ospid 24087_24410 sid 29205 ser 908, waiting for 'LMS CR slave timer' 150: CR00 ospid 24095_24411 sid 29401 ser 49614, waiting for 'LMS CR slave timer' 151: RS06 ospid 24072_24412 sid 29597 ser 59745, waiting for 'gcs yield cpu' 152: CR00 ospid 24116_24413 sid 29793 ser 12249, waiting for 'LMS CR slave timer' 153: CR00 ospid 24106_24414 sid 29989 ser 64540, waiting for 'LMS CR slave timer' 154: CR00 ospid 24109_24415 sid 30185 ser 31800, waiting for 'LMS CR slave timer' 155: CR00 ospid 24122_24416 sid 30381 ser 26295, waiting for 'LMS CR slave timer' 156: RS03 ospid 24058_24417 sid 30577 ser 17772, waiting for 'gcs yield cpu' 157: CR00 ospid 24129_24418 sid 30773 ser 62697, waiting for 'LMS CR slave timer' 158: CR00 ospid 24133_24419 sid 30969 ser 16373, waiting for 'LMS CR slave timer' 159: RS05 ospid 24067_24420 sid 31165 ser 31972, waiting for 'gcs yield cpu' 160: CR00 ospid 24147_24421 sid 31361 ser 35456, waiting for 'LMS CR slave timer' 161: RS0A ospid 24093_24422 sid 31557 ser 13415, waiting for 'gcs yield cpu' 162: CR00 ospid 24138_24423 sid 31753 ser 2715, waiting for 'LMS CR slave timer' 163: CR00 ospid 24149_24424 sid 31949 ser 32873, waiting for 'LMS CR slave timer' 164: CR00 ospid 24187_24425 sid 32145 ser 60133, waiting for 'LMS CR slave timer' 165: CR00 ospid 24162_24426 sid 32341 ser 32260, waiting for 'LMS CR slave timer' 166: CR00 ospid 24166_24427 sid 32537 ser 44383, waiting for 'LMS CR slave timer' 167: CR00 ospid 24177_24428 sid 32733 ser 15493, waiting for 'LMS CR slave timer' 168: RS08 ospid 24082_24429 sid 32929 ser 59034, waiting for 'gcs yield cpu' 169: CR00 ospid 24125_24430 sid 33125 ser 17827, waiting for 'LMS CR slave timer' 170: CR00 ospid 24155_24431 sid 33321 ser 24849, waiting for 'LMS CR slave timer' 171: CR00 ospid 24144_24432 sid 33517 ser 30004, waiting for 'LMS CR slave timer' 172: CR00 ospid 24173_24433 sid 33713 ser 24433, waiting for 'LMS CR slave timer' 173: RS07 ospid 24077_24434 sid 33909 ser 53480, waiting for 'gcs yield cpu' 174: RS0C ospid 24100_24435 sid 34105 ser 8884, waiting for 'gcs yield cpu' 175: CR00 ospid 24152_24436 sid 34301 ser 43420, waiting for 'LMS CR slave timer' 176: RS09 ospid 24087_24437 sid 34497 ser 62066, waiting for 'gcs yield cpu' 177: CR00 ospid 24180_24438 sid 34693 ser 64747, waiting for 'LMS CR slave timer' 178: RS0B ospid 24095_24439 sid 34889 ser 2961, waiting for 'gcs yield cpu' 179: RS0F ospid 24116_24440 sid 35085 ser 54223, waiting for 'gcs yield cpu' 180: RS0D ospid 24106_24441 sid 35281 ser 47697, waiting for 'gcs yield cpu' 181: RS0E ospid 24109_24442 sid 35477 ser 45064, waiting for 'gcs yield cpu' 182: RS0G ospid 24122_24443 sid 35673 ser 15515, waiting for 'gcs yield cpu' 183: RS0I ospid 24129_24444 sid 35869 ser 1604, waiting for 'gcs yield cpu' 184: RS0J ospid 24133_24445 sid 36065 ser 27444, waiting for 'gcs yield cpu' 185: RS0M ospid 24147_24446 sid 36261 ser 8220, waiting for 'gcs yield cpu' 186: RS0K ospid 24138_24447 sid 36457 ser 63409, waiting for 'gcs yield cpu' 187: RS0N ospid 24149_24448 sid 36653 ser 62536, waiting for 'gcs yield cpu' 188: RS0V ospid 24187_24449 sid 36849 ser 846, waiting for 'gcs yield cpu' 189: RS0Q ospid 24162_24450 sid 37045 ser 54408, waiting for 'gcs yield cpu' 190: RS0R ospid 24166_24451 sid 37241 ser 56730, waiting for 'gcs yield cpu' 191: RS0T ospid 24177_24452 sid 37437 ser 43979, waiting for 'gcs yield cpu' 192: RS0H ospid 24125_24453 sid 1 ser 61259, waiting for 'gcs yield cpu' 193: RS0P ospid 24155_24454 sid 197 ser 39043, waiting for 'gcs yield cpu' 194: RS0L ospid 24144_24455 sid 394 ser 31852, waiting for 'gcs yield cpu' 195: RS0S ospid 24173_24456 sid 590 ser 18311, waiting for 'gcs yield cpu' 196: RS0O ospid 24152_24457 sid 786 ser 40613, waiting for 'gcs yield cpu' 197: RS0U ospid 24180_24458 sid 982 ser 65398, waiting for 'gcs yield cpu' 198: IMR0 ospid 24460 sid 1178 ser 39109, waiting for 'class slave wait' 199: SCM0 ospid 24482 sid 1374 ser 3006, waiting for 'ges enter server mode' Blocked by inst: 1, sid: 4313, ser: 35369 Final Blocker inst: 1, sid: 4313, ser: 35369 200: M000 ospid 24510 sid 1570 ser 44285, waiting for 'class slave wait' 202: USER ospid 25601 sid 1962 ser 9382, waiting for 'SQL*Net message from client' 24999: USER ospid 23685 sid 7645 ser 48279, waiting for 'ges cgs registration' Blocked by inst: 1, sid: 4313, ser: 35369 Final Blocker inst: 1, sid: 4313, ser: 35369 System global information: processes: base 0x12a1c96a98, size 25000 allocation: free sessions 0x12e31dfc60, free calls (nil) control alloc errors: 0 (process), 0 (session), 0 (call), 0 (transaction) Cleanup state: Seconds since last dead process scan: hard=37, soft=229, part=1 Current cleanup pass: 4, started 36 seconds ago Orapids on dead process list: [count = 0] system statistics: 0 OS CPU Qt wait time 11 Requests to/from client 250 logons cumulative 201 logons current 13 opened cursors cumulative 1 opened cursors current 0 user commits 0 user rollbacks 562 user calls 111 recursive calls 1 recursive cpu usage 0 pinned cursors current 49 user logons cumulative 47 user logouts cumulative 0 session logical reads 0 session logical reads in local numa group 0 session logical reads in remote numa group 0 session stored procedure space 1 CPU used when call started 7119 CPU used by this session 2 DB time 0 CPU used by LWTs for this session 0 DB time of LWTs for this session 0 cluster wait time 55601529 concurrency wait time 38 application wait time 10910 user I/O wait time 0 scheduler wait time 1059823278 non-idle wait time 31849 non-idle wait count 42078308311 in call idle wait time 0 session connect time 1702910538 process last non-idle time 85505112 session uga memory 91915488 session uga memory max 73 messages sent 74 messages received 3341 background timeouts 72 remote Oradebug requests 1080263512 session pga memory 1092470264 session pga memory max 0 recursive system API invocations 0 enqueue timeouts 70 enqueue waits 0 enqueue deadlocks 417 enqueue requests 0 enqueue conversions 416 enqueue releases 0 global enqueue gets sync 0 global enqueue gets async 0 global enqueue get time 0 global enqueue releases 0 physical read total IO requests 0 physical read total multi block requests 0 physical read requests optimized 0 physical read total bytes optimized 0 physical read partial requests 0 physical read total bytes 0 physical write requests optimized 0 physical write total bytes optimized 0 cell writes to flash cache 0 cell overwrites in flash cache 0 cell partial writes in flash cache 0 cell writes to flash cache for temp IO 0 physical write total IO requests 0 physical write total multi block requests 0 physical write total bytes 0 cell physical IO interconnect bytes 0 cell RDMA reads 0 cell xrmem cache read hits 0 cumulative time in requests 336666 cumulative DB time in requests 0 cumulative DB time protected in requests 0 successful replays by Application Continuity 0 rejected replays by Application Continuity 0 IM private journal HT granule count 0 IM private journal HT bucket count 1663805886911 calls to kcmadj 0 index coal, examined blocks 0 index coal, empty blocks removed 0 index coal, redo limit hit 0 spare statistic 14 0 spare statistic 15 0 spare statistic 16
這次透過hanganalyze看到了，負責執行reconfiguration的 lmon程式所呼叫的call stack。
其中，有 ipcor_wseti_wait 和 ipclw_wait。
這個function應當與IPC（Interprocess Communication）有關，IPC是用於連線叢集中的節點的元件。
所以，這次收集的資料也表明這個問題與私網通訊有關係。
【建議】
請諮詢網路或系統管理員，啟用Jumbo Frame。（把MTU設定為9000）
根據我們的經驗，啟用Jumbo Frame可以緩解 IpReasmFails 增長的現象。
參考文件：
Recommendation for the Real Application Cluster Interconnect and Jumbo Frames ( Doc ID 341788.1 )
Oracle Linux: How to Change MTU Size ( Doc ID 2520148.1 )
來自 “ ITPUB部落格 ” ，連結：https://blog.itpub.net/23825935/viewspace-3002208/，如需轉載，請註明出處，否則將追究法律責任。
相關文章
- RAC二節點啟動異常
- Solaris叢集節點重啟
- 私有IP丟失造成Oracle 12C RAC叢集節點不能啟動Oracle
- Oracle 19c rac安裝，只能啟動一個節點的ASMOracleASM
- Oracle RAC啟動因CTSS導致的異常Oracle
- [異常筆記] zookeeper叢集啟動異常： Cannot open channel to 2 at election address ……筆記
- RAC節點hang住, oracle bug導致了cpu過高，無法啟動叢集隔離Oracle
- Oracle Linux 6.7中 Oracle 11.2.0.4 RAC叢集CRS異常處理OracleLinux
- 【RAC】Oracle19.13之後的grid，節點重啟後不會自動驅動Oracle
- 紅色警報 ORACLE RAC 11.2.0.4 FOR SOLARIS 10 ASM 和DB因叢集心跳丟失重啟OracleASM
- 記錄一下oracle 19c的叢集節點移除、新增操作Oracle
- ORACLE RAC 11.2.0.4 FOR RHEL6叢集無法啟動的處理Oracle
- Oracle RAC某一節點異常，你該怎麼辦?Oracle
- oracle 11.2.0.4 rac節點異常當機之ORA-07445Oracle
- ORACLE 11.2.0.4 rac for linux 鏈路宕導致的單節點異常當機OracleLinux
- Oracle RAC常見啟動失敗故障分析Oracle
- Oracle RAC自啟動Oracle
- rac二節點例項redo故障無法啟動修復
- Oracle叢集技術 | 叢集的自啟動系列（一）Oracle
- Oracle 12c叢集啟動故障Oracle
- Oracle 11gR2 RAC 叢集服務啟動與關閉總結Oracle
- ORACLE RAC 11.2.0.4 ASM加盤導致叢集重啟之ASM sga設定過小OracleASM
- 模擬oracle rac節點異常時如何保持ogg正常執行Oracle
- 19c RAC因profile.xml檔案丟失節點1啟動失敗XML
- unix cm單節點啟動
- oracle兩節點RAC，由於gipc導致某節點crs無法啟動問題分析Oracle
- 【docker-ce】k8s叢集docker容器異常重啟問題分析DockerK8S
- 【ASK_ORACLE】RAC節點自動重啟但日誌裡未報錯的原因和解決方法Oracle
- oracle例項啟動異常慢案例一Oracle
- 記一次訂單號重複的異常
- consul 多節點/單節點叢集搭建
- 多路徑配置問題和ACFS啟用原因導致rac二節點不能正常啟動
- oracle 12c RAC安裝，例項不能多節點同時啟動Oracle
- RabbitMQ叢集重啟報錯MQ
- 記一次kubernetes叢集異常: kubelet連線apiserver超時APIServer
- RAC節點啟動失敗--ASM無法連線ASM
- Oracle RAC新增節點Oracle
- 記錄一次Oracle 11.2.0.4 RAC異地恢復到單例項Oracle單例