Hello Experts
upgraded to 11.2.0.4 from 11.2.0.2 and now I am unable to rebuild indexes online. Causes a lot of high library cache locks and cursor: pin S wait on X waits.
==================
This table has 50000 rows in it. They take about 3 to 4 seconds to rebuild with or without parallel when then don't get this wait event.
Also this did not happen in 11.2.0.2 as we needed to do this on a regular basis
AWR report showing the index rebuilds online is < awr_report_105593_105595_node1.html >
The three online rebuilds that are shown in report took 31s to 45s (seconds) to execute.
Parallel also enabled "alter index sqlmgr.ICP_F401_F402_F201_TT_IDX rebuild online parallel 4;" but no improvements
Hang Analyze after enabling parallel
=============
Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
With the Partitioning, Automatic Storage Management, OLAP, Data Mining
and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/11.2.0.4
System name: Linux
Node name: nvtalnx112
Release: 2.6.32-431.29.2.el6.x86_64
Version: #1 SMP Sun Jul 27 15:55:46 EDT 2014
Machine: x86_64
Instance name: ncrxdb09
Redo thread mounted by this instance: 1
Oracle process number: 58
Unix process pid: 65024, image: oracle@nvtalnx112 (TNS V1-V3)
*** 2015-03-16 09:59:10.146
*** SESSION ID:(256.2187) 2015-03-16 09:59:10.146
*** CLIENT ID:() 2015-03-16 09:59:10.146
*** SERVICE NAME:(SYS$USERS) 2015-03-16 09:59:10.146
*** MODULE NAME:(sqlplus@nvtalnx112 (TNS V1-V3)) 2015-03-16 09:59:10.146
*** ACTION NAME:() 2015-03-16 09:59:10.146
Processing Oradebug command 'setmypid'
*** 2015-03-16 09:59:10.146
Oradebug command 'setmypid' console output: <none>
*** 2015-03-16 09:59:16.921
Processing Oradebug command 'unlimit'
*** 2015-03-16 09:59:16.921
Oradebug command 'unlimit' console output: <none>
*** 2015-03-16 09:59:24.369
Processing Oradebug command 'hanganalyze 3'
*** 2015-03-16 09:59:24.494
===============================================================================
HANG ANALYSIS:
instances (db_name.oracle_sid): ncrxdb09.ncrxdb09
oradebug_node_dump_level: 3
analysis initiated by oradebug
os thread scheduling delay history: (sampling every 1.000000 secs)
0.000000 secs at [ 09:59:23 ]
NOTE: scheduling delay has not been sampled for 0.917375 secs 0.000000 secs from [ 09:59:19 - 09:59:24 ], 5 sec avg
0.000000 secs from [ 09:58:25 - 09:59:24 ], 1 min avg
0.000000 secs from [ 09:54:25 - 09:59:24 ], 5 min avg
vktm time drift history
===============================================================================
Chains most likely to have caused the hang:
[a] Chain 1 Signature: 'EMON slave idle wait'
Chain 1 Signature Hash: 0x9fbbc886
[b] Chain 2 Signature: 'EMON slave idle wait'
Chain 2 Signature Hash: 0x9fbbc886
[c] Chain 3 Signature: 'EMON slave idle wait'
Chain 3 Signature Hash: 0x9fbbc886
===============================================================================
Sessions in an involuntary wait or not in a wait:
-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 22291
process id: 40, oracle@nvtalnx112 (E001)
session id: 11
session serial #: 17
}
is waiting for 'EMON slave idle wait' with wait info:
{
time in wait: 2.822773 sec
heur. time in wait: 562 min 14 sec
timeout after: 2.177227 sec
wait id: 6761
blocking: 0 sessions
current sql: <none>
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-kslwait()+141<-kponemn()+767<-ksvrdp()+1766<-opirip()+674<-opidrv()+603<-sou2o()+103<-opimai_real()+250<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
wait history:
* time between current wait and wait #1: 0.000024 sec
1. event: 'EMON slave idle wait'
time waited: 5.000978 sec
wait id: 6760
* time between wait #1 and #2: 0.000020 sec
2. event: 'EMON slave idle wait'
time waited: 5.000754 sec
wait id: 6759
* time between wait #2 and #3: 0.000039 sec
3. event: 'EMON slave idle wait'
time waited: 5.001192 sec
wait id: 6758
}
Chain 1 Signature: 'EMON slave idle wait'
Chain 1 Signature Hash: 0x9fbbc886
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 2:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 22293
process id: 41, oracle@nvtalnx112 (E002)
session id: 131
session serial #: 11
}
is waiting for 'EMON slave idle wait' with wait info:
{
time in wait: 2.830728 sec
heur. time in wait: 562 min 14 sec
timeout after: 2.169272 sec
wait id: 6757
blocking: 0 sessions
current sql: <none>
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-kslwait()+141<-kponemn()+767<-ksvrdp()+1766<-opirip()+674<-opidrv()+603<-sou2o()+103<-opimai_real()+250<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
wait history:
* time between current wait and wait #1: 0.000029 sec
1. event: 'EMON slave idle wait'
time waited: 5.001007 sec
wait id: 6756
* time between wait #1 and #2: 0.000023 sec
2. event: 'EMON slave idle wait'
time waited: 5.000966 sec
wait id: 6755
* time between wait #2 and #3: 0.000032 sec
3. event: 'EMON slave idle wait'
time waited: 5.000967 sec
wait id: 6754
}
Chain 2 Signature: 'EMON slave idle wait'
Chain 2 Signature Hash: 0x9fbbc886
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 3:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 22295
process id: 42, oracle@nvtalnx112 (E003)
session id: 252
session serial #: 1
}
is waiting for 'EMON slave idle wait' with wait info:
{
time in wait: 2.802753 sec
heur. time in wait: 562 min 14 sec
timeout after: 2.197247 sec
wait id: 6759
blocking: 0 sessions
current sql: <none>
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-kslwait()+141<-kponemn()+767<-ksvrdp()+1766<-opirip()+674<-opidrv()+603<-sou2o()+103<-opimai_real()+250<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
wait history:
* time between current wait and wait #1: 0.000025 sec
1. event: 'EMON slave idle wait'
time waited: 5.000994 sec
wait id: 6758
* time between wait #1 and #2: 0.000023 sec
2. event: 'EMON slave idle wait'
time waited: 5.000977 sec
wait id: 6757
* time between wait #2 and #3: 0.000028 sec
3. event: 'EMON slave idle wait'
time waited: 5.000972 sec
wait id: 6756
}
Chain 3 Signature: 'EMON slave idle wait'
Chain 3 Signature Hash: 0x9fbbc886
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 4:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 22289
process id: 39, oracle@nvtalnx112 (E000)
session id: 367
session serial #: 1
}
is waiting for 'EMON slave idle wait' with wait info:
{
time in wait: 2.825976 sec
heur. time in wait: 562 min 14 sec
timeout after: 2.174024 sec
wait id: 6752
blocking: 0 sessions
current sql: <none>
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-kslwait()+141<-kponemn()+767<-ksvrdp()+1766<-opirip()+674<-opidrv()+603<-sou2o()+103<-opimai_real()+250<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
wait history:
* time between current wait and wait #1: 0.000027 sec
1. event: 'EMON slave idle wait'
time waited: 5.001771 sec
wait id: 6751
* time between wait #1 and #2: 0.000021 sec
2. event: 'EMON slave idle wait'
time waited: 5.000976 sec
wait id: 6750
* time between wait #2 and #3: 0.000025 sec
3. event: 'EMON slave idle wait'
time waited: 5.000964 sec
wait id: 6749
}
Chain 4 Signature: 'EMON slave idle wait'
Chain 4 Signature Hash: 0x9fbbc886
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 5:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 22297
process id: 43, oracle@nvtalnx112 (E004)
session id: 369
session serial #: 1
}
is waiting for 'EMON slave idle wait' with wait info:
{
time in wait: 2.658279 sec
heur. time in wait: 42 min 3 sec
timeout after: 2.341721 sec
wait id: 6762
blocking: 0 sessions
current sql: <none>
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-kslwait()+141<-kponemn()+767<-ksvrdp()+1766<-opirip()+674<-opidrv()+603<-sou2o()+103<-opimai_real()+250<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
wait history:
* time between current wait and wait #1: 0.000445 sec
1. event: 'EMON slave idle wait'
time waited: 5.001616 sec
wait id: 6761
* time between wait #1 and #2: 0.000370 sec
2. event: 'EMON slave idle wait'
time waited: 5.000633 sec
wait id: 6760
* time between wait #2 and #3: 0.000453 sec
3. event: 'EMON slave idle wait'
time waited: 5.000564 sec
wait id: 6759
}
Chain 5 Signature: 'EMON slave idle wait'
Chain 5 Signature Hash: 0x9fbbc886
-------------------------------------------------------------------------------
===============================================================================
Extra information that will be dumped at higher levels:
[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]):
[10]/1/11/17/0x35eb5a748/22291/SINGLE_NODE/
[130]/1/131/11/0x35ecbccc8/22293/SINGLE_NODE/
[251]/1/252/1/0x35ee1c168/22295/SINGLE_NODE/
[366]/1/367/1/0x35ef8db48/22289/SINGLE_NODE/
[368]/1/369/1/0x35ef87988/22297/SINGLE_NODE/
*** 2015-03-16 09:59:24.496
===============================================================================
END OF HANG ANALYSIS
===============================================================================
*** 2015-03-16 09:59:24.497
===============================================================================
HANG ANALYSIS DUMPS:
oradebug_node_dump_level: 3
===============================================================================
State of LOCAL nodes
([nodenum]/cnode/sid/sess_srno/session/ospid/state/[adjlist]):
[10]/1/11/17/0x35eb5a748/22291/SINGLE_NODE/
[130]/1/131/11/0x35ecbccc8/22293/SINGLE_NODE/
[251]/1/252/1/0x35ee1c168/22295/SINGLE_NODE/
[366]/1/367/1/0x35ef8db48/22289/SINGLE_NODE/
[368]/1/369/1/0x35ef87988/22297/SINGLE_NODE/
No processes qualify for dumping.
===============================================================================
HANG ANALYSIS DUMPS: END
===============================================================================
*** 2015-03-16 09:59:24.497
Oradebug command 'hanganalyze 3' console output:
Hang Analysis in /u01/app/oracle/diag/rdbms/ncrxdb09/ncrxdb09/trace/ncrxdb09_ora_65024.trc
*** 2015-03-16 10:03:29.888
Processing Oradebug command 'hanganalyze 3'
*** 2015-03-16 10:03:30.308
===============================================================================
HANG ANALYSIS:
instances (db_name.oracle_sid): ncrxdb09.ncrxdb09
oradebug_node_dump_level: 3
analysis initiated by oradebug
os thread scheduling delay history: (sampling every 1.000000 secs)
0.000000 secs at [ 10:03:29 ]
NOTE: scheduling delay has not been sampled for 0.482862 secs 0.000000 secs from [ 10:03:25 - 10:03:30 ], 5 sec avg
0.000000 secs from [ 10:02:30 - 10:03:30 ], 1 min avg
0.000000 secs from [ 09:58:30 - 10:03:30 ], 5 min avg
vktm time drift history
===============================================================================
Chains most likely to have caused the hang:
[a] Chain 1 Signature: <not in a wait><='library cache lock'<='library cache lock'<='cursor: pin S wait on X'
Chain 1 Signature Hash: 0x12f5c63d
[b] Chain 2 Signature: <not in a wait><='library cache lock'<='library cache lock'<='cursor: pin S wait on X'
Chain 2 Signature Hash: 0x12f5c63d
[c] Chain 3 Signature: <not in a wait><='library cache lock'<='library cache lock'<='cursor: pin S wait on X'
Chain 3 Signature Hash: 0x12f5c63d
===============================================================================
Non-intersecting chains:
-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 5376
process id: 48, oracle@nvtalnx112
session id: 8
session serial #: 73
}
is waiting for 'cursor: pin S wait on X' with wait info:
{
p1: 'idn'=0x45218db5
p2: 'value'=0x8b00000000
p3: 'where'=0x500000000
time in wait: 7.914413 sec
timeout after: never
wait id: 7132
blocking: 0 sessions
current sql: SELECT F505, F506, F507, F508, F509, F503, F504, F512, F513, F514, F517, F518, F519, F520, F521, F522, F523, F525, F526, AGEHANDLER, AGEHWHY, COPAYHANDLER, COPAYHWHY, COSTHANDLER, COSTHWHY, DISPFEEHANDLER, DISPFEEHWHY, DISPLIMHANDLER, DISPLIMHWHY, REFILLHANDLER, REFILLHWHY, TransactionType, ENTEREDDATE, F407, F302, F
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-__select()+19<-skgpwwait()+332<-kgxWait()+1404<-kgxSharedExamine()+576<-kxsGetRuntimeLock()+240<-kkscsCheckCursor()+556<-kkscsSearchChildList()+1285<-kksfbc()+12419<-kkspsc0()+1171<-kksParseCursor()+116<-opiosq0()+2027<-kpooprx()+274<-kpoal8()+842<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
wait history:
* time between current wait and wait #1: 0.000067 sec
1. event: 'SQL*Net message from client'
time waited: 0.002241 sec
wait id: 7131 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #1 and #2: 0.000002 sec
2. event: 'SQL*Net message to client'
time waited: 0.000001 sec
wait id: 7130 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #2 and #3: 0.000036 sec
3. event: 'SQL*Net message from client'
time waited: 0.000450 sec
wait id: 7129 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
}
and is blocked by
=> Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 5370
process id: 21, oracle@nvtalnx112
session id: 139
session serial #: 173
}
which is waiting for 'library cache lock' with wait info:
{
p1: 'handle address'=0x33b97b298
p2: 'lock address'=0x1df743f78
p3: '100*mode+namespace'=0xd10a00010002
time in wait: 24.284294 sec
timeout after: 14 min 35 sec
wait id: 6867
blocking: 5 sessions
current sql: SELECT F505, F506, F507, F508, F509, F503, F504, F512, F513, F514, F517, F518, F519, F520, F521, F522, F523, F525, F526, AGEHANDLER, AGEHWHY, COPAYHANDLER, COPAYHWHY, COSTHANDLER, COSTHWHY, DISPFEEHANDLER, DISPFEEHWHY, DISPLIMHANDLER, DISPLIMHWHY, REFILLHANDLER, REFILLHWHY, TransactionType, ENTEREDDATE, F407, F302, F
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-ksfwaitctx()+14<-kglLockWait()+856<-kgllkal()+2964<-kglLock()+1384<-kglget()+343<-kglgob()+187<-qcdlgbo()+525<-qcdlgob()+901<-qcsfgob()+241<-qcsprfro()+620<-qcsprfro_tree()+325<-qcsprfro_tree()+795<-qcsprfro_tree()+394<-qcspafq()+255<-qcspqbDescendents()+261<-qcspqb()+438<-qcspqbDescendents()+2991<-qcspqb()+438<-qcsevw()+447<-qcsfpsq()+117<-kkmfcbsq()+241<-kkmpfcbk()+1092<
wait history:
* time between current wait and wait #1: 0.000611 sec
1. event: 'SQL*Net message from client'
time waited: 0.008299 sec
wait id: 6866 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #1 and #2: 0.000041 sec
2. event: 'SQL*Net message to client'
time waited: 0.000001 sec
wait id: 6865 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #2 and #3: 0.000054 sec
3. event: 'SQL*Net message from client'
time waited: 0.000205 sec
wait id: 6864 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
}
and is blocked by
=> Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 52300
process id: 64, oracle@nvtalnx112
session id: 21
session serial #: 11637
}
which is waiting for 'library cache lock' with wait info:
{
p1: 'handle address'=0x33b97b298
p2: 'lock address'=0x34c4f6278
p3: '100*mode+namespace'=0xd10a00010003
time in wait: 31.973918 sec
timeout after: 14 min 28 sec
wait id: 7113
blocking: 6 sessions
current sql: alter index sqlmgr.ICP_MH_IDX rebuild online parallel 4
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-ksfwaitctx()+14<-kglLockWait()+856<-kgllkal()+2964<-kglLock()+1384<-kglget()+343<-kdiclap_lkpn()+628<-kdiclap_lock_and_pin()+54<-kdicliat_lock_index_and_table()+103<-kdicrws()+10176<-kdicdrv()+500<-opiexe()+22066<-opiosq0()+3932<-kpooprx()+274<-kpoal8()+842<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou2o()+103<-opimai_real()+133
wait history:
* time between current wait and wait #1: 0.000099 sec
1. event: 'enq: PS - contention'
time waited: 0.000063 sec
wait id: 7112 p1: 'name|mode'=0x50530006
p2: 'instance'=0x1
p3: 'slave ID'=0x1
* time between wait #1 and #2: 0.000019 sec
2. event: 'PX Deq: Slave Session Stats'
time waited: 0.000001 sec
wait id: 7111 p1: 'sleeptime/senderid'=0x0
p2: 'passes'=0x0
* time between wait #2 and #3: 0.000000 sec
3. event: 'PX Deq: Slave Session Stats'
time waited: 0.000001 sec
wait id: 7110 p1: 'sleeptime/senderid'=0x0
p2: 'passes'=0x0
}
and is blocked by
=> Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 5378
process id: 45, oracle@nvtalnx112
session id: 135
session serial #: 31
}
which is not in a wait:
{
last wait: 31.975839 sec ago
blocking: 7 sessions
current sql: SELECT RxDate, RxEnd, NDC, nvl(md.GPI, hstGPI) as currGPI, RxNum, NABP, DaysSupply, Qty, Copay, DispFee, SpecialCopay, SDoseRemainderPM, AuthNum, scriptCnt, mony, tier, multiflags, couponid, processdate, :"SYS_B_000" as packagesize, fillRuleCriteriaMatch, stepTherCriteriaMatch, decode(md.rxotcind, :"SYS_B_001", :"SYS_
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-kghalf()+247<-keshs_createHintFromText()+86<-qolTextXmlToHintList()+198<-qolTextXmlStringToHintList()+167<-qsmoGetSqlProfHints()+402<-kkocsInitCardFdbkCompCtx()+127<-kkocsMonitorTable()+510<-kkoFroAddXplAnnotations()+226<-kkoipt()+17684<-kkoqbc()+30240<-apakkoqb()+172<-apaqbdDescendents()+483<-apaqbdList()+76<-apaqbdDescendents()+768<-apaqbdList()+76<-apaqbdDescendents()+267<-apaqbdList()+76<-apaqbd()+14<-apadrv()+922<-opitca()+2089<-kksFu
wait history:
1. event: 'library cache lock'
time waited: 0.003485 sec
wait id: 7397 p1: 'handle address'=0x33b97b298
p2: 'lock address'=0x1dc7299f0
p3: '100*mode+namespace'=0xd10a00010002
* time between wait #1 and #2: 0.002574 sec
2. event: 'SQL*Net message from client'
time waited: 0.000289 sec
wait id: 7396 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #2 and #3: 0.000009 sec
3. event: 'SQL*Net message to client'
time waited: 0.000002 sec
wait id: 7395 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
}
Chain 1 Signature: <not in a wait><='library cache lock'<='library cache lock'<='cursor: pin S wait on X'
Chain 1 Signature Hash: 0x12f5c63d
-------------------------------------------------------------------------------
===============================================================================
Intersecting chains:
-------------------------------------------------------------------------------
Chain 2:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 5364
process id: 52, oracle@nvtalnx112
session id: 15
session serial #: 77
}
is waiting for 'cursor: pin S wait on X' with wait info:
{
p1: 'idn'=0x45218db5
p2: 'value'=0x8b00000000
p3: 'where'=0x500000000
time in wait: 20.194953 sec
timeout after: never
wait id: 6660
blocking: 0 sessions
current sql: SELECT F505, F506, F507, F508, F509, F503, F504, F512, F513, F514, F517, F518, F519, F520, F521, F522, F523, F525, F526, AGEHANDLER, AGEHWHY, COPAYHANDLER, COPAYHWHY, COSTHANDLER, COSTHWHY, DISPFEEHANDLER, DISPFEEHWHY, DISPLIMHANDLER, DISPLIMHWHY, REFILLHANDLER, REFILLHWHY, TransactionType, ENTEREDDATE, F407, F302, F
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-ksfwaitctx()+14<-kgxWait()+1330<-kgxSharedExamine()+576<-kxsGetRuntimeLock()+240<-kkscsCheckCursor()+556<-kkscsSearchChildList()+1285<-kksfbc()+12419<-kkspsc0()+1171<-kksParseCursor()+116<-opiosq0()+2027<-kpooprx()+274<-kpoal8()+842<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+265<-main(
wait history:
* time between current wait and wait #1: 0.000073 sec
1. event: 'SQL*Net message from client'
time waited: 0.005684 sec
wait id: 6659 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #1 and #2: 0.000002 sec
2. event: 'SQL*Net message to client'
time waited: 0.000000 sec
wait id: 6658 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #2 and #3: 0.000029 sec
3. event: 'SQL*Net message from client'
time waited: 0.000165 sec
wait id: 6657 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
}
and is blocked by 'instance: 1, os id: 5370, session id: 139',
which is a member of 'Chain 1'.
Chain 2 Signature: <not in a wait><='library cache lock'<='library cache lock'<='cursor: pin S wait on X'
Chain 2 Signature Hash: 0x12f5c63d
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 3:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 5403
process id: 36, oracle@nvtalnx112
session id: 16
session serial #: 27
}
is waiting for 'cursor: pin S wait on X' with wait info:
{
p1: 'idn'=0x45218db5
p2: 'value'=0x8b00000000
p3: 'where'=0x500000000
time in wait: 16.045369 sec
timeout after: never
wait id: 7591
blocking: 0 sessions
current sql: SELECT F505, F506, F507, F508, F509, F503, F504, F512, F513, F514, F517, F518, F519, F520, F521, F522, F523, F525, F526, AGEHANDLER, AGEHWHY, COPAYHANDLER, COPAYHWHY, COSTHANDLER, COSTHWHY, DISPFEEHANDLER, DISPFEEHWHY, DISPLIMHANDLER, DISPLIMHWHY, REFILLHANDLER, REFILLHWHY, TransactionType, ENTEREDDATE, F407, F302, F
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-ksfwaitctx()+14<-kgxWait()+1330<-kgxSharedExamine()+576<-kxsGetRuntimeLock()+240<-kkscsCheckCursor()+556<-kkscsSearchChildList()+1285<-kksfbc()+12419<-kkspsc0()+1171<-kksParseCursor()+116<-opiosq0()+2027<-kpooprx()+274<-kpoal8()+842<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+265<-main(
wait history:
* time between current wait and wait #1: 0.000176 sec
1. event: 'SQL*Net message from client'
time waited: 0.006068 sec
wait id: 7590 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #1 and #2: 0.000003 sec
2. event: 'SQL*Net message to client'
time waited: 0.000001 sec
wait id: 7589 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #2 and #3: 0.000076 sec
3. event: 'SQL*Net message from client'
time waited: 0.000438 sec
wait id: 7588 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
}
and is blocked by 'instance: 1, os id: 5370, session id: 139',
which is a member of 'Chain 1'.
Chain 3 Signature: <not in a wait><='library cache lock'<='library cache lock'<='cursor: pin S wait on X'
Chain 3 Signature Hash: 0x12f5c63d
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 4:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 5407
process id: 53, oracle@nvtalnx112
session id: 136
session serial #: 29
}
is waiting for 'cursor: pin S wait on X' with wait info:
{
p1: 'idn'=0x45218db5
p2: 'value'=0x8b00000000
p3: 'where'=0x500000000
time in wait: 3.816170 sec
timeout after: never
wait id: 10010
blocking: 0 sessions
current sql: SELECT F505, F506, F507, F508, F509, F503, F504, F512, F513, F514, F517, F518, F519, F520, F521, F522, F523, F525, F526, AGEHANDLER, AGEHWHY, COPAYHANDLER, COPAYHWHY, COSTHANDLER, COSTHWHY, DISPFEEHANDLER, DISPFEEHWHY, DISPLIMHANDLER, DISPLIMHWHY, REFILLHANDLER, REFILLHWHY, TransactionType, ENTEREDDATE, F407, F302, F
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-ksfwaitctx()+14<-kgxWait()+1330<-kgxSharedExamine()+576<-kxsGetRuntimeLock()+240<-kkscsCheckCursor()+556<-kkscsSearchChildList()+1285<-kksfbc()+12419<-kkspsc0()+1171<-kksParseCursor()+116<-opiosq0()+2027<-kpooprx()+274<-kpoal8()+842<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+265<-main(
wait history:
* time between current wait and wait #1: 0.000161 sec
1. event: 'SQL*Net message from client'
time waited: 0.001787 sec
wait id: 10009 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #1 and #2: 0.000044 sec
2. event: 'SQL*Net message to client'
time waited: 0.000001 sec
wait id: 10008 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #2 and #3: 0.000069 sec
3. event: 'SQL*Net message from client'
time waited: 0.000221 sec
wait id: 10007 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
}
and is blocked by 'instance: 1, os id: 5370, session id: 139',
which is a member of 'Chain 1'.
Chain 4 Signature: <not in a wait><='library cache lock'<='library cache lock'<='cursor: pin S wait on X'
Chain 4 Signature Hash: 0x12f5c63d
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 5:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 5401
process id: 51, oracle@nvtalnx112
session id: 371
session serial #: 1075
}
is waiting for 'cursor: pin S wait on X' with wait info:
{
p1: 'idn'=0x45218db5
p2: 'value'=0x8b00000000
p3: 'where'=0x500000000
time in wait: 11.954853 sec
timeout after: never
wait id: 5076
blocking: 0 sessions
current sql: SELECT F505, F506, F507, F508, F509, F503, F504, F512, F513, F514, F517, F518, F519, F520, F521, F522, F523, F525, F526, AGEHANDLER, AGEHWHY, COPAYHANDLER, COPAYHWHY, COSTHANDLER, COSTHWHY, DISPFEEHANDLER, DISPFEEHWHY, DISPLIMHANDLER, DISPLIMHWHY, REFILLHANDLER, REFILLHWHY, TransactionType, ENTEREDDATE, F407, F302, F
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-__select()+19<-skgpwwait()+332<-kgxWait()+1404<-kgxSharedExamine()+576<-kxsGetRuntimeLock()+240<-kkscsCheckCursor()+556<-kkscsSearchChildList()+1285<-kksfbc()+12419<-kkspsc0()+1171<-kksParseCursor()+116<-opiosq0()+2027<-kpooprx()+274<-kpoal8()+842<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
wait history:
* time between current wait and wait #1: 0.000077 sec
1. event: 'SQL*Net message from client'
time waited: 0.002245 sec
wait id: 5075 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #1 and #2: 0.000002 sec
2. event: 'SQL*Net message to client'
time waited: 0.000000 sec
wait id: 5074 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #2 and #3: 0.000041 sec
3. event: 'SQL*Net message from client'
time waited: 0.000511 sec
wait id: 5073 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
}
and is blocked by 'instance: 1, os id: 5370, session id: 139',
which is a member of 'Chain 1'.
Chain 5 Signature: <not in a wait><='library cache lock'<='library cache lock'<='cursor: pin S wait on X'
Chain 5 Signature Hash: 0x12f5c63d
-------------------------------------------------------------------------------
===============================================================================
Sessions in an involuntary wait or not in a wait:
-------------------------------------------------------------------------------
Chain 6:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 22291
process id: 40, oracle@nvtalnx112 (E001)
session id: 11
session serial #: 17
}
is waiting for 'EMON slave idle wait' with wait info:
{
time in wait: 0.435678 sec
heur. time in wait: 566 min 20 sec
timeout after: 4.564322 sec
wait id: 6811
blocking: 0 sessions
current sql: <none>
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-kslwait()+141<-kponemn()+767<-ksvrdp()+1766<-opirip()+674<-opidrv()+603<-sou2o()+103<-opimai_real()+250<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
wait history:
* time between current wait and wait #1: 0.000035 sec
1. event: 'EMON slave idle wait'
time waited: 5.001973 sec
wait id: 6810
* time between wait #1 and #2: 0.000027 sec
2. event: 'EMON slave idle wait'
time waited: 5.001962 sec
wait id: 6809
* time between wait #2 and #3: 0.000032 sec
3. event: 'EMON slave idle wait'
time waited: 5.000959 sec
wait id: 6808
}
Chain 6 Signature: 'EMON slave idle wait'
Chain 6 Signature Hash: 0x9fbbc886
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 7:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 22293
process id: 41, oracle@nvtalnx112 (E002)
session id: 131
session serial #: 11
}
is waiting for 'EMON slave idle wait' with wait info:
{
time in wait: 0.413689 sec
heur. time in wait: 566 min 20 sec
timeout after: 4.586311 sec
wait id: 6807
blocking: 0 sessions
current sql: <none>
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-kslwait()+141<-kponemn()+767<-ksvrdp()+1766<-opirip()+674<-opidrv()+603<-sou2o()+103<-opimai_real()+250<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
wait history:
* time between current wait and wait #1: 0.000023 sec
1. event: 'EMON slave idle wait'
time waited: 5.001941 sec
wait id: 6806
* time between wait #1 and #2: 0.000031 sec
2. event: 'EMON slave idle wait'
time waited: 5.000929 sec
wait id: 6805
* time between wait #2 and #3: 0.000026 sec
3. event: 'EMON slave idle wait'
time waited: 5.001041 sec
wait id: 6804
}
Chain 7 Signature: 'EMON slave idle wait'
Chain 7 Signature Hash: 0x9fbbc886
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 8:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 22295
process id: 42, oracle@nvtalnx112 (E003)
session id: 252
session serial #: 1
}
is waiting for 'EMON slave idle wait' with wait info:
{
time in wait: 0.389665 sec
heur. time in wait: 566 min 20 sec
timeout after: 4.610335 sec
wait id: 6809
blocking: 0 sessions
current sql: <none>
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-kslwait()+141<-kponemn()+767<-ksvrdp()+1766<-opirip()+674<-opidrv()+603<-sou2o()+103<-opimai_real()+250<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
wait history:
* time between current wait and wait #1: 0.000027 sec
1. event: 'EMON slave idle wait'
time waited: 5.001969 sec
wait id: 6808
* time between wait #1 and #2: 0.000030 sec
2. event: 'EMON slave idle wait'
time waited: 5.000873 sec
wait id: 6807
* time between wait #2 and #3: 0.000027 sec
3. event: 'EMON slave idle wait'
time waited: 5.001054 sec
wait id: 6806
}
Chain 8 Signature: 'EMON slave idle wait'
Chain 8 Signature Hash: 0x9fbbc886
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 9:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 22289
process id: 39, oracle@nvtalnx112 (E000)
session id: 367
session serial #: 1
}
is waiting for 'EMON slave idle wait' with wait info:
{
time in wait: 0.365675 sec
heur. time in wait: 566 min 20 sec
timeout after: 4.634325 sec
wait id: 6802
blocking: 0 sessions
current sql: <none>
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-kslwait()+141<-kponemn()+767<-ksvrdp()+1766<-opirip()+674<-opidrv()+603<-sou2o()+103<-opimai_real()+250<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
wait history:
* time between current wait and wait #1: 0.000025 sec
1. event: 'EMON slave idle wait'
time waited: 5.001957 sec
wait id: 6801
* time between wait #1 and #2: 0.000031 sec
2. event: 'EMON slave idle wait'
time waited: 5.000974 sec
wait id: 6800
* time between wait #2 and #3: 0.000029 sec
3. event: 'EMON slave idle wait'
time waited: 5.000976 sec
wait id: 6799
}
Chain 9 Signature: 'EMON slave idle wait'
Chain 9 Signature Hash: 0x9fbbc886
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
Chain 10:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (ncrxdb09.ncrxdb09)
os id: 22297
process id: 43, oracle@nvtalnx112 (E004)
session id: 369
session serial #: 1
}
is waiting for 'EMON slave idle wait' with wait info:
{
time in wait: 0.340016 sec
heur. time in wait: 46 min 8 sec
timeout after: 4.659984 sec
wait id: 6812
blocking: 0 sessions
current sql: <none>
short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-kslwait()+141<-kponemn()+767<-ksvrdp()+1766<-opirip()+674<-opidrv()+603<-sou2o()+103<-opimai_real()+250<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253
wait history:
* time between current wait and wait #1: 0.000472 sec
1. event: 'EMON slave idle wait'
time waited: 5.000769 sec
wait id: 6811
* time between wait #1 and #2: 0.000440 sec
2. event: 'EMON slave idle wait'
time waited: 5.000176 sec
wait id: 6810
* time between wait #2 and #3: 0.000448 sec
3. event: 'EMON slave idle wait'
time waited: 5.000946 sec
wait id: 6809
}
Chain 10 Signature: 'EMON slave idle wait'
Chain 10 Signature Hash: 0x9fbbc886
-------------------------------------------------------------------------------
===============================================================================
Extra information that will be dumped at higher levels:
[level 4] : 1 node dumps -- [LEAF] [LEAF_NW]
[level 5] : 12 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]):
[7]/1/8/73/0x35eb639e8/5376/NLEAF/[138]
[10]/1/11/17/0x35eb5a748/22291/SINGLE_NODE/
[14]/1/15/77/0x35eb4e3c8/5364/NLEAF/[138]
[15]/1/16/27/0x35eb4b2e8/5403/NLEAF/[138]
[20]/1/21/11637/0x35eb3be88/52300/NLEAF/[134]
[130]/1/131/11/0x35ecbccc8/22293/SINGLE_NODE/
[134]/1/135/31/0x35ecb0948/5378/LEAF_NW/
[135]/1/136/29/0x35ecad868/5407/NLEAF/[138]
[138]/1/139/173/0x35eca45c8/5370/NLEAF/[20]
[251]/1/252/1/0x35ee1c168/22295/SINGLE_NODE/
[366]/1/367/1/0x35ef8db48/22289/SINGLE_NODE/
[368]/1/369/1/0x35ef87988/22297/SINGLE_NODE/
[370]/1/371/1075/0x35ef817c8/5401/NLEAF/[138]
*** 2015-03-16 10:03:30.313
===============================================================================
END OF HANG ANALYSIS
===============================================================================
*** 2015-03-16 10:03:30.313
===============================================================================
HANG ANALYSIS DUMPS:
oradebug_node_dump_level: 3
===============================================================================
State of LOCAL nodes
([nodenum]/cnode/sid/sess_srno/session/ospid/state/[adjlist]):
[7]/1/8/73/0x35eb639e8/5376/NLEAF/[138]
[10]/1/11/17/0x35eb5a748/22291/SINGLE_NODE/
[14]/1/15/77/0x35eb4e3c8/5364/NLEAF/[138]
[15]/1/16/27/0x35eb4b2e8/5403/NLEAF/[138]
[20]/1/21/11637/0x35eb3be88/52300/NLEAF/[134]
[130]/1/131/11/0x35ecbccc8/22293/SINGLE_NODE/
[134]/1/135/31/0x35ecb0948/5378/LEAF_NW/
[135]/1/136/29/0x35ecad868/5407/NLEAF/[138]
[138]/1/139/173/0x35eca45c8/5370/NLEAF/[20]
[251]/1/252/1/0x35ee1c168/22295/SINGLE_NODE/
[366]/1/367/1/0x35ef8db48/22289/SINGLE_NODE/
[368]/1/369/1/0x35ef87988/22297/SINGLE_NODE/
[370]/1/371/1075/0x35ef817c8/5401/NLEAF/[138]
No processes qualify for dumping.
===============================================================================
HANG ANALYSIS DUMPS: END
===============================================================================
*** 2015-03-16 10:03:30.313
Oradebug command 'hanganalyze 3' console output:
Hang Analysis in /u01/app/oracle/diag/rdbms/ncrxdb09/ncrxdb09/trace/ncrxdb09_ora_65024.trc
*** 2015-03-16 10:03:41.453
Processing Oradebug command 'hanganalyze 3'
*** 2015-03-16 10:03:41.544
===============================================================================
HANG ANALYSIS:
instances (db_name.oracle_sid): ncrxdb09.ncrxdb09
oradebug_node_dump_level: 3
analysis initiated by oradebug
os thread scheduling delay history: (sampling every 1.000000 secs)
0.000000 secs at [ 10:03:40 ]
NOTE: scheduling delay has not been sampled for 0.668778 secs 0.000000 secs from [ 10:03:36 - 10:03:41 ], 5 sec avg
0.000000 secs from [ 10:02:41 - 10:03:41 ], 1 min avg
0.000000 secs from [ 09:58:42 - 10:03:41 ], 5 min avg
vktm time drift history
===============================================================================
Chains most likely to have caused the hang:
[a] Chain 1 Signature: <not in a wait><='library cache l