今天,客户端某数据库遭遇大量library cache lock 和cursor pin S wait on X的问题,经诊断发现是由于他们底层的ASM存储是多个库共享的,故障时间段别的库占用大量的IO,导致paitsm库的IO响应变慢,db file sequential read从平时的20多毫秒,到了故障时的400多毫秒。
且这个库大量的sql使用了SPM,库中有近5000条baseline,连select 1 from dual这样的简单SQL也使用了SPM。
在这2个因素的共同作用下,导致了大量library cache lock 和cursor pin S wait on X。
分析过程如下:
(一)
9:23 数据库中出现大量library cache lock,大约有1400个session处于该等待。去War Room之前,做了 hangeanalyze,从hanganalyze的文件分析,存在多种堵塞链条:
1 2 3 4 5 6 7 |
117 'db file sequential read'<='read by other session'<='library cache lock' 13 'db file sequential read'<='read by other session'<='library cache lock'<='cursor: pin S' 13 'control file sequential read'<='log file switch completion' 12 'library cache lock'<='library cache lock'<='library cache lock'...<='library cache lock'<=... 5 'db file sequential read'<='read by other session' 1 <not in a wait><='cursor: pin S wait on X' 1 'library cache lock'<='cursor: pin S wait on X' |
可以看到,大部分的阻塞链还是’db file sequential read’<='read by other session'<='library cache lock'。也就是说,db file sequential导致了library cache lock。看上去还是非常像IO慢的问题导致library cache lock的。
如:
sample_id 140056627时, sid 3654(select 1 from dual,library cache lock) is blocked by
=> sid 1171(select 1 from dual,read by other session, obj为SQLOBJ$_PKEY) is blocked by
=> sid 1018(SELECT NVL(MAX(MYDATE), TO_DATE(‘2007-09-01’, ‘YYYY-MM-DD’)) FROM TAB_ABC_99 WHERE AKSBBCCD_ID = :B1,db file sequential read, obj为SQLOBJ$_PKEY)
等待library cache lock的sql,和阻塞library cache lock的sql是一样的,都是select 1 from dual,但是最终的holder的sql,是另外的SQL。
注:在MOS中,虽然没有关于SQLOBJ$PKEY的详细说明,但是能查询的大部分资料都和spm有关
(二)
dba kill library cache lock
(三)
10:08 ,发现再次出现大量cursor: pin S wait on X,final blocking session是sid为2475的session,处于db file scattered read。
在做process dump之后,kill os process。
我们通过process dump,我们可以看到的阻塞链是:db file scattered read<= library cache lock,即dump的时候,该session处于db file scattered read。
在process dump中,我们看到,2745的session大约堵塞了35个session,其中一个session是3032,处于library cache lock,请求44ab09e98的handle,而往下查时,我们可以看到,2745的该session是以X模式hold住了44ab09e98的handle,所以3032的session就无法获得,只能等2745的session释放。
process dump:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 |
Current Wait Stack: 0: waiting for 'db file scattered read' <<<<< file#=0x2, block#=0x8388, blocks=0x8 wait_id=13067 seq_num=13352 snap_id=1 wait times: snap=0.222181 sec, exc=0.222181 sec, total=0.222181 sec wait times: max=infinite, heur=0.222181 sec wait counts: calls=0 os=0 in_wait=1 iflags=0x5a0 There are 35 sessions blocked by this session. <<<<< Dumping one waiter: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< inst: 1, sid: 3032, ser: 46627 wait event: 'library cache lock' <<<<<<<<<<<<<<<<<< p1: 'handle address'=0x44ab09e98 <<<<<<<<< p2: 'lock address'=0x45a527f50 p3: '100*mode+namespace'=0x310002 row_wait_obj#: 4294967295, block#: 0, row#: 0, file# 0 min_blocked_time: 1581 secs, waiter_cache_ver: 20549 Wait State: fixed_waits=0 flags=0x2a boundary=0x4b9549e48/0 Session Wait History: ... SO: 0x4006de370, type: 78, owner: 0x4b26741e8, flag: INIT/-/-/0x00 if: 0x3 c: 0x3 proc=0x4bcd810b8, name=LIBRARY OBJECT PIN, file=kgl.h LINE:8480, pg=0 LibraryObjectPin: Address=0x4006de370 Handle=0x44ab09e98 <<<<<< Mode=X <<<<< User=0x4b9548098 Session=0x4b9548098 Count=1 Mask=0001 Flags=[00] SavepointNum=0x67 LibraryHandle: Address=0x44ab09e98 Hash=9bbdaf1 LockMode=X PinMode=X LoadLockMode=0 Status=VALD ObjectName: Name=15917672392759061765 FullHashValue=cd43f8fa81a324899ad4ca5209bbdaf1 Namespace=SQL TUNING BASE OBJECT(49) Type=SQL TUNING BASE OBJECT(75) Identifier=0 OwnerIdn=2147483644 Statistics: InvalidationCount=0 ExecutionCount=0 LoadCount=12 ActiveLocks=1 TotalLockCount=17 TotalPinCount=17 Counters: BrokenCount=13 RevocablePointer=1 KeepDependency=0 BucketInUse=14395 HandleInUse=14395 HandleReferenceCount=0 Concurrency: DependencyMutex=0x44ab09f48(0, 151, 0, 0) Mutex=0x44ab09fc8(0, 170634, 141, 0) Flags=PIN/TIM/PTM/[00003881] WaitersLists: Lock=0x44ab09f28[0x45a527fc0,0x45a527fc0] Pin=0x44ab09f08[0x44ab09f08,0x44ab09f08] Timestamp: Current=06-25-2015 09:38:31 Previous=NULL LibraryObject: Address=0x3d1b9e420 HeapMask=0000-0001-0001-0000 Flags=EXS/LOC/ALT[0024] Flags2=[0000] PublicFlags=[0000] |
虽然我们从process dump中看到是被db file scattered read堵塞,但是这可能是在dump的时候,session的等待已经改变,从ash中,我们看到阻塞链其实是db file sequential read<=library cache lock<=cursor: pin S wait on X
如:
sample_id 140059277时, sid 2515 (sql_id 535a6y4mx7gn1,cursor: pin S wait on X) is blocked by
=> sid 3032 (sql_id 535a6y4mx7gn1,library cache lock) is blocked by
=> sid 2745 (sql_id 535a6y4mx7gn1,db file sequential read, obj也还是SQLOBJ$_PKEY)
注:最后所读的对象,还是SQLOBJ$_PKEY。
我们在process dump中,也可以看到,在db file scattered read之前,确实处于db file sequential read:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 |
Sampled Session History of session 2745 serial 11423 …… The history is displayed in reverse chronological order. sample interval: 1 sec, max history 120 sec --------------------------------------------------- [1 sample, 10:08:46] waited for 'db file sequential read', seq_num: 13344 p1: 'file#'=0x2 p2: 'block#'=0x35fbd p3: 'blocks'=0x1 time_waited: >= 0 sec (still in wait) [1 sample, 10:08:45] waited for 'db file sequential read', seq_num: 13342 p1: 'file#'=0x2 p2: 'block#'=0x4be90 p3: 'blocks'=0x1 time_waited: 0.958431 sec (sample interval: 0 sec) [1 sample, 10:08:44] waited for 'db file sequential read', seq_num: 13335 p1: 'file#'=0x2 p2: 'block#'=0x108c39 p3: 'blocks'=0x1 time_waited: 0.860525 sec (sample interval: 0 sec) [1 sample, 10:08:43] waited for 'db file sequential read', seq_num: 13327 p1: 'file#'=0x2 p2: 'block#'=0xda9ae p3: 'blocks'=0x1 time_waited: 0.828370 sec (sample interval: 0 sec) [1 sample, 10:08:42] waited for 'db file sequential read', seq_num: 13321 p1: 'file#'=0x2 p2: 'block#'=0x93975 p3: 'blocks'=0x1 time_waited: 0.858617 sec (sample interval: 0 sec) …… |
(四)
11:29 再次去War Room,此时再次做 hanganalyze,看到的阻塞链为:
1 2 3 |
382 'resmgr:cpu quantum'<='library cache lock' 47 'resmgr:cpu quantum'<='library cache lock'<='cursor: pin S wait on X' 2 'log file parallel write'<='log file sync' |
如:
sample_id 140063747时, sid 32 (sql_id 535a6y4mx7gn1,cursor: pin S wait on X) is blocked by
=> sid 1968 (sql_id 535a6y4mx7gn1,library cache lock) is blocked by
=> sid 1172 (sql_id 535a6y4mx7gn1,resmgr:cpu quantum)
综上4个时间点,我们可以看出,阻塞链为:
‘db file sequential read ‘<='library cache lock'<='cursor: pin S wait on X'或者
'resmgr:cpu quantum'<='library cache lock'<='cursor: pin S wait on X'
Db file sequential read 的对象都是SQLOBJ$_PKEY。
由于resource manager的作用,导致处理排队,从而引发library cache lock比较好理解,但是IO慢为何导致了library cache lock?
我们看到library cache handle的holder持有了比较长的时间,一直在处于读SQLOBJ$_PKEY,这是因为SQL在做解析时,需要持有handle,而且需要等解析完,才会释放handle。而由于我们的sql是有SPM固定的,在解析的时候,需要去访问SQLOBJ$_PKEY,而SQLOBJ$_PKEY的对象,由于IO差,访问的慢,或者read by other session正在被别的session访问,而别的session也遭受着IO差的问题。因此,耗费了较多的时间在访问SQLOBJ$_PKEY上。再对于SQLOBJ$_PKEY的访问没有结束前,解析不算完成,因此也就不能释放handle。
因此别的session就处于library cache lock了。
另外,cursor pin S wait on X被library cache lock堵塞,我们用3个session来说明原因:
Session A,由于IO慢,hold住了handle,释放的慢。
Session B,需要获得handle,但是被session A hold着,所以处于library cache lock等待。而这个session,在执行select 1 from dual的时候,在解析时会生成一个child cursor,并以exclusive模式pin住这个child cursor。
Session C,由于和session B执行的是一个sql,需要以shared模式共享上面的child cursor,但是由于session B还没有完成解析,还没生成完整的child cursor,所以也无法共享这个child cursor。所以处于cursor pin Swait on X的等待。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 |
Session C: ---------------------------------------- SO: 0x4b8cf13f0, type: 2, owner: (nil), flag: IN ... Current Wait Stack: 0: waiting for 'cursor: pin S wait on X' idn=0x27d3be81, value=0x7b000000000, where=0x500000000 wait_id=106 seq_num=107 snap_id=1 wait times: snap=42 min 55 sec, exc=42 min 55 sec, total=42 min 55 sec wait times: max=infinite, heur=42 min 55 sec wait counts: calls=0 os=0 in_wait=1 iflags=0x5a2 There is at least one session blocking this session. Dumping 1 direct blocker(s): inst: 1, sid: 1968, ser: 18357 Dumping final blocker: inst: 1, sid: 3702, ser: 34891 Wait State: fixed_waits=0 flags=0x22 boundary=(nil)/-1 Session Wait History: ... ---------------------------------------- SO: 0x2c903d538, type: 77, owner: 0x4b521c698, flag: INIT/-/-/0x00 if: 0x3 c: 0x3 proc=0x4b8cf13f0, name=LIBRARY OBJECT LOCK, file=kgl.h LINE:8476, pg=0 LibraryObjectLock: Address=0x2c903d538 Handle=0x476a55410 Mode=N CanBeBrokenCount=1 Incarnation=1 ExecutionCount=0 ClusterLock=0x448fa74e0 Context=0x2b6f6bc43078 User=0x4b521c698 Session=0x4b521c698 ReferenceCount=1 Flags=CBK/[0020] SavepointNum=0 LibraryHandle: Address=0x476a55410 Hash=0 LockMode=N PinMode=X LoadLockMode=0 Status=VALD Name: Namespace=SQL AREA(00) Type=CURSOR(00) Statistics: InvalidationCount=0 ExecutionCount=0 LoadCount=1 ActiveLocks=51 TotalLockCount=51 TotalPinCount=52 Counters: BrokenCount=1 RevocablePointer=1 KeepDependency=0 BucketInUse=0 HandleInUse=0 HandleReferenceCount=0 Concurrency: DependencyMutex=0x476a554c0(0, 0, 0, 0) Mutex=0x48bdf4e68(0, 602180, 1294, 0) Flags=RON/PIN/PN0/EXP/CHD/[10012111] WaitersLists: Lock=0x476a554a0[0x476a554a0,0x476a554a0] Pin=0x476a55480[0x476a55480,0x476a55480] LibraryObject: Address=0x292c0e140 HeapMask=0000-0001-0001-0000 Flags=EXS[0000] Flags2=[0000] PublicFlags=[0000] DataBlocks: Block: #='0' name=KGLH0^27d3be81 pins=0 Change=NONE Heap=0x476a55358 Pointer=0x292c0e1e0 Extent=0x292c0e0c0 Flags=I/-/P/A/-/- FreedLocation=0 Alloc=3.148438 Size=3.976562 LoadTime=9484515620 Block: #='6' name=SQLA^27d3be81 pins=0 Change=NONE Heap=0x413820d28 Pointer=0x292c0cd28 Extent=0x292c0c0c0 Flags=I/-/P/A/-/E FreedLocation=0 Alloc=0.000000 Size=0.000000 LoadTime=0 NamespaceDump: Child Cursor: Heap0=0x292c0e1e0 Heap6=0x292c0cd28 Heap0 Load Time=06-25-2015 10:56:38 Heap6 Load Time=06-25-2015 10:56:38 ---------------------------------------- KGX Atomic Operation Log 0x448fa74e0 Mutex 0x413820c80(1968, 0) idn 27d3be81 oper GET_SHRD<<<<<<<<<<<<<<<<< Cursor Pin uid 1185 efd 0 whr 5 slp 5774 opr=2 pso=0x2c903d538 flg=0 pcs=0x413820bf0 nxt=(nil) flg=35 cld=6 hd=0x476a55410 par=0x48bdf3d68 ct=1f hsh=0 unp=(nil) unn=0 hvl=5bc57b98 nhv=1 ses=0x4b93927b8 hep=0x413820c80 flg=80 ld=1 ob=0x292c0e140 ptr=0x292c0cd28 fex=0x292c0c0c0 Session B: ---------------------------------------- SO: 0x4b8db8470, type: 2, owner: (nil), flag: INIT/-/-/0x00 if: 0x3 c: 0x3 proc=0x4b8db8470, name=process, file=ksu.h LINE:12451, pg=0 (process) Oracle pid:1010, ser:17, calls cur/top: 0x2d4aee7a0/0x3b5259db0 flags : (0x0) - flags2: (0x0), flags3: (0x0) intr error: 0, call error: 0, sess error: 0, txn error 0 intr queue: empty ksudlp FALSE at location: 0 (post info) last post received: 0 0 26 ... Current Wait Stack: 0: waiting for 'library cache lock' handle address=0x44ab09e98, <<<<<<<lock address=0x2f9db9f48 <<<<<<, 100*mode+namespace=0x310002 wait_id=281 seq_num=282 snap_id=1 wait times: snap=68 min 27 sec, exc=68 min 27 sec, total=68 min 27 sec wait times: max=infinite, heur=68 min 27 sec wait counts: calls=1379 os=1379 in_wait=1 iflags=0x15a2 There is at least one session blocking this session. Dumping 1 direct blocker(s): inst: 1, sid: 1172, ser: 47967 Dumping final blocker: inst: 1, sid: 1210, ser: 61171 There are 50 sessions blocked by this session. Dumping one waiter: ... SO: 0x2f9db9f48, type: 77, owner: 0x2d4aee7a0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3 proc=0x4b8db8470, name=LIBRARY OBJECT LOCK, file=kgl.h LINE:8476, pg=0 LibraryObjectLock: Address=0x2f9db9f48 Handle=0x44ab09e98<<<<<<<< RequestMode=S <<<<<< CanBeBrokenCount=14 Incarnation=1 ExecutionCount=0 User=0x4b93927b8 Session=0x4b93927b8 ReferenceCount=0 Flags=[0000] SavepointNum=91 LibraryHandle: Address=0x44ab09e98 Hash=9bbdaf1 LockMode=X PinMode=X LoadLockMode=0 Status=VALD ObjectName: Name=15917672392759061765 FullHashValue=cd43f8fa81a324899ad4ca5209bbdaf1 Namespace=SQL TUNING BASE OBJECT(49) Type=SQL TUNING BASE OBJECT(75) Identifier=0 OwnerIdn=2147483644 Statistics: InvalidationCount=0 ExecutionCount=0 LoadCount=13 ActiveLocks=1 TotalLockCount=22 TotalPinCount=22 Counters: BrokenCount=14 RevocablePointer=1 KeepDependency=0 BucketInUse=18078 HandleInUse=18078 HandleReferenceCount=0 Concurrency: DependencyMutex=0x44ab09f48(0, 166, 0, 0) Mutex=0x44ab09fc8(0, 214929, 142, 0) Flags=PIN/TIM/PTM/[00003881] WaitersLists: Lock=0x44ab09f28[0x2f9db9fb8,0x266f5b438] Pin=0x44ab09f08[0x44ab09f08,0x44ab09f08] Timestamp: Current=06-25-2015 10:45:43 Previous=NULL LibraryObject: Address=0x3d1b9e420 HeapMask=0000-0001-0001-0000 Flags=EXS/LOC/ALT[0024] Flags2=[0000] PublicFlags=[0000] DataBlocks: Block: #='0' name=KGLH0^9bbdaf1 pins=0 Change=UPDATE Heap=0x46289fdb0 Pointer=0x3d1b9e7c0 Extent=0x3d1b9e3a0 Flags=I/-/P/A/-/- FreedLocation=0 Alloc=1.000000 Size=4.000000 LoadTime=9481753770 ---------------------------------------- SO: 0x3bd2c7330, type: 77, owner: 0x4b93927b8, flag: INIT/-/-/0x00 if: 0x3 c: 0x3 proc=0x4b8db8470, name=LIBRARY OBJECT LOCK, file=kgl.h LINE:8476, pg=0 LibraryObjectLock: Address=0x3bd2c7330 Handle=0x476a55410 Mode=N CanBeBrokenCount=1 Incarnation=1 ExecutionCount=0 ClusterLock=0x3bd2ca5f0 Context=0x2af4ef5bdbe8 User=0x4b93927b8 Session=0x4b93927b8 ReferenceCount=1 Flags=CBK/[0020] SavepointNum=0 LibraryHandle: Address=0x476a55410 Hash=0 LockMode=N PinMode=X LoadLockMode=0 Status=VALD Name: Namespace=SQL AREA(00) Type=CURSOR(00) Statistics: InvalidationCount=0 ExecutionCount=0 LoadCount=1 ActiveLocks=51 TotalLockCount=51 TotalPinCount=52 Counters: BrokenCount=1 RevocablePointer=1 KeepDependency=0 BucketInUse=0 HandleInUse=0 HandleReferenceCount=0 Concurrency: DependencyMutex=0x476a554c0(0, 0, 0, 0) Mutex=0x48bdf4e68(0, 602229, 1294, 0) Flags=RON/PIN/PN0/EXP/CHD/[10012111] WaitersLists: Lock=0x476a554a0[0x476a554a0,0x476a554a0] Pin=0x476a55480[0x476a55480,0x476a55480] LibraryObject: Address=0x292c0e140 HeapMask=0000-0001-0001-0000 Flags=EXS[0000] Flags2=[0000] PublicFlags=[0000] DataBlocks: Block: #='0' name=KGLH0^27d3be81 pins=0 Change=NONE Heap=0x476a55358 Pointer=0x292c0e1e0 Extent=0x292c0e0c0 Flags=I/-/P/A/-/- FreedLocation=0 Alloc=3.148438 Size=3.976562 LoadTime=9484515620 Block: #='6' name=SQLA^27d3be81 pins=0 Change=NONE Heap=0x413820d28 Pointer=0x292c0cd28 Extent=0x292c0c0c0 Flags=I/-/P/A/-/E FreedLocation=0 Alloc=0.000000 Size=0.000000 LoadTime=0 NamespaceDump: Child Cursor: Heap0=0x292c0e1e0 Heap6=0x292c0cd28 Heap0 Load Time=06-25-2015 10:56:38 Heap6 Load Time=06-25-2015 10:56:38 ---------------------------------------- KGX Atomic Operation Log 0x3bd2ca5f0 Mutex 0x413820c80(1968, 0) idn 27d3be81 oper LONG_EXCL <<<<<<<<<<<<<<<<<< Cursor Pin uid 1968 efd 0 whr 1 slp 0 opr=3 pso=0x3bd2c7330 flg=0 pcs=0x413820bf0 nxt=(nil) flg=35 cld=6 hd=0x476a55410 par=0x48bdf3d68 ct=1f hsh=0 unp=(nil) unn=0 hvl=5bc57b98 nhv=1 ses=0x4b93927b8 ---------------------------------------- SO: 0x2f9db9f48, type: 77, owner: 0x2d4aee7a0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3 proc=0x4b8db8470, name=LIBRARY OBJECT LOCK, file=kgl.h LINE:8476, pg=0 LibraryObjectLock: Address=0x2f9db9f48 Handle=0x44ab09e98 RequestMode=S <<<<< CanBeBrokenCount=14 Incarnation=1 ExecutionCount=0 User=0x4b93927b8 Session=0x4b93927b8 ReferenceCount=0 Flags=[0000] SavepointNum=91 LibraryHandle: Address=0x44ab09e98 Hash=9bbdaf1 LockMode=X PinMode=X LoadLockMode=0 Status=VALD ObjectName: Name=15917672392759061765 FullHashValue=cd43f8fa81a324899ad4ca5209bbdaf1 Namespace=SQL TUNING BASE OBJECT(49) Type=SQL TUNING BASE OBJECT(75) Identifier=0 OwnerIdn=2147483644 Statistics: InvalidationCount=0 ExecutionCount=0 LoadCount=13 ActiveLocks=1 TotalLockCount=22 TotalPinCount=22 Counters: BrokenCount=14 RevocablePointer=1 KeepDependency=0 BucketInUse=18078 HandleInUse=18078 HandleReferenceCount=0 Concurrency: DependencyMutex=0x44ab09f48(0, 166, 0, 0) Mutex=0x44ab09fc8(0, 214929, 142, 0) Flags=PIN/TIM/PTM/[00003881] WaitersLists: Lock=0x44ab09f28[0x2f9db9fb8,0x266f5b438] Pin=0x44ab09f08[0x44ab09f08,0x44ab09f08] Timestamp: Current=06-25-2015 10:45:43 Previous=NULL LibraryObject: Address=0x3d1b9e420 HeapMask=0000-0001-0001-0000 Flags=EXS/LOC/ALT[0024] Flags2=[0000] PublicFlags=[0000] DataBlocks: Block: #='0' name=KGLH0^9bbdaf1 pins=0 Change=UPDATE Heap=0x46289fdb0 Pointer=0x3d1b9e7c0 Extent=0x3d1b9e3a0 Flags=I/-/P/A/-/- FreedLocation=0 Alloc=1.000000 Size=4.000000 LoadTime=9481753770 ... Session A: ---------------------------------------- Current Wait Stack: 0: waiting for 'read by other session' file#=0x2, block#=0x104218, class#=0x1 wait_id=21251 seq_num=21258 snap_id=1 wait times: snap=1.020540 sec, exc=1.020540 sec, total=1.020540 sec wait times: max=infinite, heur=1.020540 sec wait counts: calls=2 os=2 in_wait=1 iflags=0x15a2 There is at least one session blocking this session. Dumping 1 direct blocker(s): inst: 1, sid: 1210, ser: 61171 Dumping final blocker: inst: 1, sid: 1210, ser: 61171 There are 55 sessions blocked by this session. Dumping one waiter: inst: 1, sid: 778, ser: 45477 wait event: 'library cache lock' p1: 'handle address'=0x44ab09e98 p2: 'lock address'=0x266f5b3c8 p3: '100*mode+namespace'=0x310003 row_wait_obj#: 204124, block#: 150389215, row#: 0, file# 5 min_blocked_time: 4748 secs, waiter_cache_ver: 22870 Wait State: fixed_waits=0 flags=0x22 boundary=(nil)/-1 Session Wait History: elapsed time of 0.000058 sec since current wait ... SO: 0x2e94bf230, type: 78, owner: 0x4b2531d08, flag: INIT/-/-/0x00 if: 0x3 c: 0x3 proc=0x4b4ddea30, name=LIBRARY OBJECT PIN, file=kgl.h LINE:8480, pg=0 LibraryObjectPin: Address=0x2e94bf230 Handle=0x44ab09e98<<<<<<<< Mode=X <<<<<<<< User=0x4bd27bce8 Session=0x4bd27bce8 Count=1 Mask=0001 Flags=[00] SavepointNum=0x14c LibraryHandle: Address=0x44ab09e98 Hash=9bbdaf1 LockMode=X PinMode=X LoadLockMode=0 Status=VALD ObjectName: Name=15917672392759061765 FullHashValue=cd43f8fa81a324899ad4ca5209bbdaf1 Namespace=SQL TUNING BASE OBJECT(49) Type=SQL TUNING BASE OBJECT(75) Identifier=0 OwnerIdn=2147483644 Statistics: InvalidationCount=0 ExecutionCount=0 LoadCount=13 ActiveLocks=1 TotalLockCount=22 TotalPinCount=22 Counters: BrokenCount=14 RevocablePointer=1 KeepDependency=0 BucketInUse=18069 HandleInUse=18069 HandleReferenceCount=0 Concurrency: DependencyMutex=0x44ab09f48(0, 166, 0, 0) Mutex=0x44ab09fc8(0, 214819, 142, 0) Flags=PIN/TIM/PTM/[00003881] WaitersLists: Lock=0x44ab09f28[0x2f9db9fb8,0x28c66a8d0] Pin=0x44ab09f08[0x44ab09f08,0x44ab09f08] Timestamp: Current=06-25-2015 10:45:43 Previous=NULL LibraryObject: Address=0x3d1b9e420 HeapMask=0000-0001-0001-0000 Flags=EXS/LOC/ALT[0024] Flags2=[0000] PublicFlags=[0000] DataBlocks: Block: #='0' name=KGLH0^9bbdaf1 pins=0 Change=UPDATE Heap=0x46289fdb0 Pointer=0x3d1b9e7c0 Extent=0x3d1b9e3a0 Flags=I/-/P/A/-/- FreedLocation=0 Alloc=1.000000 Size=4.000000 LoadTime=9481753770 ---------------------------------------- SO: 0x2e94bf4c0, type: 77, owner: 0x4b2531d08, flag: INIT/-/-/0x00 if: 0x3 c: 0x3 proc=0x4b4ddea30, name=LIBRARY OBJECT LOCK, file=kgl.h LINE:8476, pg=0 LibraryObjectLock: Address=0x2e94bf4c0 Handle=0x44ab09e98<<<<< Mode=X CanBeBrokenCount=13 Incarnation=1 ExecutionCount=0 User=0x4bd27bce8 Session=0x4bd27bce8 ReferenceCount=1 Flags=CNB/[0001] SavepointNum=14c LibraryHandle: Address=0x44ab09e98 Hash=9bbdaf1 LockMode=X PinMode=X LoadLockMode=0 Status=VALD ObjectName: Name=15917672392759061765 FullHashValue=cd43f8fa81a324899ad4ca5209bbdaf1 Namespace=SQL TUNING BASE OBJECT(49) Type=SQL TUNING BASE OBJECT(75) Identifier=0 OwnerIdn=2147483644 Statistics: InvalidationCount=0 ExecutionCount=0 LoadCount=13 ActiveLocks=1 TotalLockCount=22 TotalPinCount=22 Counters: BrokenCount=14 RevocablePointer=1 KeepDependency=0 BucketInUse=18069 HandleInUse=18069 HandleReferenceCount=0 |
所以,解决该数据库的问题,一方面需要我们加快IO,加速SQLOBJ$_PKEY的访问,另一方面,也可以减少数据库中SPM的数量,不要让大量的sql走SPM,从而减少对SQLOBJ$_PKEY的访问。