| << Back to previous view |
|
[QA-56] "cursor: mutex X" Created: 27/Jul/13 Updated: 28/Jul/13 |
|
| Status: | Open |
| Project: | Questions & Answers |
| Fix Version/s: | None |
| Type: | Oracle - Database Tuning | Priority: | Major |
| Reporter: | ubTools Support | Assignee: | ubTools Support |
| Resolution: | Unresolved | Votes: | 0 |
| Product Version: | 11.2.0.3.7 |
| Operating System: | Solaris |
| Host Name: | . |
| Database Name: | . |
| Description |
|
The customer has upgraded from Oracle 10.2.0.5 to Oracle 11.2.0.3.7. They encountered library cache lock problem.
Some excerpt from the AWR: Elapsed: 15.01 (mins) DB Time: 6,548.72 (mins) ..... Top 5 Timed Foreground Events Event Waits Time(s) Avg wait (ms) % DB time Wait Class library cache lock 425 364,186 856909 92.69 Concurrency enq: TX - row lock contention 288 11,500 39930 2.93 Application TCP Socket (KGAS) 136,317 9,552 70 2.43 Network DB CPU 4,167 1.06 db file sequential read 742,541 2,176 3 0.55 User I/O |
| Comments |
| Comment by ubTools Support [ 27/Jul/13 10:42 AM ] |
Some excerpt from the HANGANALYZE trace:
Chain 1:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (opusdata.opusdata)
os id: 25465
process id: 256, oracle@<hostname>
session id: 39
session serial #: 61345
}
is waiting for 'library cache lock' with wait info:
{
p1: 'handle address'=0x22038dff68
p2: 'lock address'=0x21ef361978
p3: '100*mode+namespace'=0x520002
time in wait: 5 min 33 sec
timeout after: never
wait id: 5128
blocking: 0 sessions
wait history:
* time between current wait and wait #1: 0.001507 sec
1. event: 'SQL*Net message from client'
time waited: 0.003166 sec
wait id: 5127 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.000002 sec
wait id: 5126 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
* time between wait #2 and #3: 0.000011 sec
3. event: 'SQL*Net message from client'
time waited: 0.003906 sec
wait id: 5125 p1: 'driver id'=0x54435000
p2: '#bytes'=0x1
}
and is blocked by
=> Oracle session identified by:
{
instance: 1 (opusdata.opusdata)
os id: 22379
process id: 500, oracle@<hostname>
session id: 8008
session serial #: 62080
}
which is waiting for 'cursor: mutex X' with wait info:
{
p1: 'idn'=0xd4d88873
p2: 'value'=0x1
p3: 'where'=0x400000000
time in wait: 0.000000 sec
heur. time in wait: 1 min 3 sec
timeout after: never
wait id: 7092018
blocking: 426 sessions
wait history:
* time between current wait and wait #1: 0.000007 sec
1. event: 'cursor: mutex X'
time waited: 0.000002 sec
wait id: 7092017 p1: 'idn'=0xd4d88873
p2: 'value'=0x1
p3: 'where'=0x400000000
* time between wait #1 and #2: 0.000009 sec
2. event: 'cursor: mutex X'
time waited: 0.000002 sec
wait id: 7092016 p1: 'idn'=0xd4d88873
p2: 'value'=0x1
p3: 'where'=0x400000000
* time between wait #2 and #3: 0.000007 sec
3. event: 'cursor: mutex X'
time waited: 0.000003 sec
wait id: 7092015 p1: 'idn'=0xd4d88873
p2: 'value'=0x1
p3: 'where'=0x400000000
}
Chain 1 Signature: 'cursor: mutex X'<='library cache lock'
Chain 1 Signature Hash: 0xfbcb6c60
.....
process id: 3136, oracle@<hostname>
.....
is waiting for 'library cache lock' with wait info:
.....
and is blocked by 'instance: 1, os id: 22379, session id: 8008',
There are many other sessions waiting on library cache lock in the trace. And, they are blocked by SID#8008 which is waiting on cursor: mutex X. SID#8008 blocks 426 sessions. |
| Comment by ubTools Support [ 27/Jul/13 01:03 PM ] |
Unfortunately, the blocker session SID#8008 exited. But, a new blocker SID#7579 appeared. Some excerpt from its ERRORSTACK LEVEL 3 trace:
KGX Atomic Operation Log 3c6bb9388
Mutex 22c1df2c18(7579, 0) idn d4d88873 oper EXCL
Cursor Parent uid 7579 efd 15 whr 1 slp 0
oper=OPERATION_DEFAULT pt1=0 pt2=0 pt3=0
pt4=0 u41=0 stt=0
KGX Atomic Operation Log 3c6bb93d8
Mutex 22c1df2d30(0, 1) idn d4d88873 oper GET_EXCL
hash table uid 7579 efd 15 whr 4 slp 36782
oper=OPERATION_DEFAULT pt1=0 pt2=0 pt3=0
pt4=0 u41=0 stt=0
Mutex IDN 0xd4d88873 is hold in EXCL mode at mutex address 0x22c1df2c18. The holder SID is 7579. The mutex type is Cursor Parent Waiting session holds the same mutex IDN in EXCL mode but in the different mutex address and the different mutex type. No other holder encountered in the SYSTEMSTATE trace. |
| Comment by ubTools Support [ 28/Jul/13 01:26 PM ] |
Some excerpt from AWR:
Foreground Wait Events ..... Event Waits %Time -outs Total Wait Time (s) Avg wait (ms) Waits /txn % DB time ..... cursor: mutex X 8,066,619 0 835 0 138.17 0.21 ..... Mutex Sleep Summary ordered by number of sleeps desc Mutex Type Location Sleeps Wait Time (ms) hash table kkshhcdel [KKSHBKLOC4] 8,061,510 0 The mutex sleep location is kkshhcdel [KKSHBKLOC4]. Nothing found about it in Metalink. |
| Comment by ubTools Support [ 28/Jul/13 05:33 PM ] |
|
Workaround:
Change the SQL text. |
| Comment by ubTools Support [ 28/Jul/13 05:36 PM ] |
| The customer will open an SR to Oracle Support. I'll update this issue later with SR result. |