下面测试来至于群里面一位兄弟数据库出来大量的library cache lock/library cache:mutex X,原以为是BUG导致，最后确认是由于sql语法错误导致的，下面是在11.2.0.3环境中模拟现象
欢迎大家加入QQ群
讨论
1，DB与OS版本
www.htz.pw > select * from v$version;
BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
PL/SQL Release 11.2.0.3.0 - Production
CORE 11.2.0.3.0 Production
TNS for Linux: Version 11.2.0.3.0 - Production
NLSRTL Version 11.2.0.3.0 - Production
www.htz.pw > !lsb_release -a
LSB Version: :core-3.0-amd64:core-3.0-ia32:core-3.0-noarch:graphics-3.0-amd64:graphics-3.0-ia32:graphics-3.0-noarch
Distributor ID: RedHatEnterpriseAS
Description: Red Hat Enterprise Linux AS release 4 (Nahant Update 8)
Release: 4
Codename: NahantUpdate8
2，测试脚本
[oracle@www.htz.pw sql]$cat /tmp/total1.sh
#!/bin/bash
for i in {1..1000}
do
nohup /tmp/runsql.sh &
echo $i
done
[oracle@www.htz.pw sql]$cat /tmp/total.sh
#!/bin/bash
for b in {1..100}
do
nohup /tmp/total1.sh >/tmp/total$b &
echo $b
done
[oracle@www.htz.pw sql]$cat /tmp/runsql.sh
sqlplus -s / as sysdba <<EOF
SELECT rowid,distinct ename from scott.emp;
SELECT rowid,distinct ename from scott.emp;
...................................
SELECT rowid,distinct ename from scott.emp;
exit
下面脚本用于生成trace文件用于分析
[oracle@www.htz.pw ~]$cat /tmp/manual.sh
sqlplus -s / as sysdba <<EOF
exec DBMS_WORKLOAD_REPOSITORY.CREATE_SNAPSHOT();
oradebug setmypid
oradebug tracefile_name;
oradebug event 10046 trace name context forever,level 12;
SELECT rowid,distinct ename from scott.emp;
oradebug event 10046 trace name context off;
exec DBMS_WORKLOAD_REPOSITORY.CREATE_SNAPSHOT();
oradebug dump systemstate 266
exit
3 现象模拟
[oracle@www.htz.pw sql]$sh -x /tmp/total.sh
+ for b in '{1..100}'
+ nohup /tmp/total1.sh
+ echo 1
1
+ for b in '{1..100}'
+ nohup /tmp/total1.sh
+ echo 2
2
+ for b in '{1..100}'
+ nohup /tmp/total1.sh
+ echo 3
3
+ for b in '{1..100}'
+ echo 4
4
+ for b in '{1..100}'
+ nohup /tmp/total1.sh
+ echo 5
5
+ for b in '{1..100}'
+ nohup /tmp/total1.sh
+ echo 6
.....................
运行/tmp/total.sh脚本。
3.1 查看等待事件
I SQL_ID COMMAND COUNT(*)
-- ------------------ --------------- ----------
1 19z6y6frqctwj UNKNOWN 665
6256zq0nau5g2 PL/SQL EXECUTE 1
5v4ww7bb9y4hp SELECT 1
I EVENT SQL_ID COUNT(*)
-- ---------------------------------------- ------------------ ----------
1 SQL*Net message to client 81prbu1ddkd5c 1
library cache lock 19z6y6frqctwj 506
library cache: mutex X 19z6y6frqctwj 159
pipe get 6256zq0nau5g2 1
I EVENT COUNT(*)
-- ---------------------------------------- ----------
1 library cache: mutex X 401
library cache lock 264
pipe get 1
SQL*Net message to client 1
这里已经现出了library cache lock,library cache: mutex X等待事件，并且blocking_session一直在变化。这里虽然能找到sqlid，但是在v$sql中sql_fulltext为空
3.2 执行manual脚本
执行manual脚本，生成分析信息
[oracle@www.htz.pw ~]$./manual.sh
PL/SQL procedure successfully completed.
Elapsed: 00:00:02.72
Statement processed.
/oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_16859.trc
Statement processed.
SELECT rowid,distinct ename from scott.emp
*
ERROR at line 1:
ORA-00936: missing expression
SQL用时3分钟
Elapsed: 00:03:53.71
Statement processed.
PL/SQL procedure successfully completed.
Elapsed: 00:00:02.06
Statement processed.
3.3 trace文件分析
*** 2014-09-04 23:39:55.421
WAIT #182938303856: nam='library cache lock' ela= 167078 handle address=3731290056 lock address=2689821752 100*mode+namespace=5373954 obj#=-1 tim=1409845195421813
WAIT #182938303856: nam='library cache lock' ela= 176379 handle address=3731290056 lock address=2689821752 100*mode+namespace=5373954 obj#=-1 tim=1409845195598493
WAIT #182938303856: nam='library cache: mutex X' ela= 93014 idn=2293619106 value=1915555414016 where=82 obj#=-1 tim=1409845195857160
WAIT #182938303856: nam='library cache lock' ela= 165443 handle address=3731290056 lock address=2689821752 100*mode+namespace=5373954 obj#=-1 tim=1409845195857160
WAIT #182938303856: nam='library cache: mutex X' ela= 57730 idn=2293619106 value=1808181231616 where=82 obj#=-1 tim=1409845196013600
WAIT #182938303856: nam='library cache lock' ela= 98517 handle address=3731290056 lock address=2689821752 100*mode+namespace=5373954 obj#=-1 tim=1409845196013600
WAIT #182938303856: nam='library cache: mutex X' ela= 75987 idn=2293619106 value=1103806595072 where=82 obj#=-1 tim=1409845196169888
WAIT #182938303856: nam='library cache lock' ela= 80150 handle address=3731290056 lock address=2689821752 100*mode+namespace=5373954 obj#=-1 tim=1409845196169888
*** 2014-09-04 23:39:56.356
WAIT #182938303856: nam='library cache: mutex X' ela= 102519 idn=2293619106 value=2576980377600 where=82 obj#=-1 tim=1409845196356195
WAIT #182938303856: nam='library cache lock' ela= 83678 handle address=3731290056 lock address=2689821752 100*mode+namespace=5373954 obj#=-1 tim=1409845196356195
WAIT #182938303856: nam='library cache: mutex X' ela= 71324 idn=2293619106 value=2843268349952 where=82 obj#=-1 tim=1409845196492361
WAIT #182938303856: nam='library cache lock' ela= 64693 handle address=3731290056 lock address=2689821752 100*mode+namespace=5373954 obj#=-1 tim=1409845196492361
WAIT #182938303856: nam='library cache: mutex X' ela= 103586 idn=2293619106 value=2959232466944 where=82 obj#=-1 tim=1409845196678232
WAIT #182938303856: nam='library cache lock' ela= 82175 handle address=3731290056 lock address=2689821752 100*mode+namespace=5373954 obj#=-1 tim=1409845196678232
WAIT #182938303856: nam='library cache: mutex X' ela= 85254 idn=2293619106 value=2113123909632 where=82 obj#=-1 tim=1409845196820340
WAIT #182938303856: nam='library cache lock' ela= 56746 handle address=3731290056 lock address=2689821752 100*mode+namespace=5373954 obj#=-1 tim=1409845196820340
WAIT #182938303856: nam='library cache: mutex X' ela= 54560 idn=2293619106 value=601295421440 where=82 obj#=-1 tim=1409845196937515
WAIT #182938303856: nam='library cache lock' ela= 62518 handle address=3731290056 lock address=2689821752 100*mode+namespace=5373954 obj#=-1 tim=1409845196937515
WAIT #182938303856: nam='library cache: mutex X' ela= 93347 idn=2293619106 value=2388001816576 where=82 obj#=-1 tim=1409845197141569
WAIT #182938303856: nam='library cache lock' ela= 110615 handle address=3731290056 lock address=2689821752 100*mode+namespace=5373954 obj#=-1 tim=1409845197141569
WAIT #182938303856: nam='library cache: mutex X' ela= 120893 idn=2293619106 value=1314259992576 where=82 obj#=-1 tim=1409845197331918
WAIT #182938303856: nam='library cache lock' ela= 69317 handle address=3731290056 lock address=2689821752 100*mode+namespace=5373954 obj#=-1 tim=1409845197331918
3.4 awr部分数据
Snap Id Snap Time Sessions Curs/Sess
--------- ------------------- -------- ---------
Begin Snap: 254 04-Sep-14 23:39:51 694 1.0
End Snap: 255 04-Sep-14 23:43:48 696 1.0
Elapsed: 3.94 (mins)
DB Time: 2,600.59 (mins)
......
Top 5 Timed Foreground Events
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Avg
wait {ff392285dba4c735eaf57cbf839a563e19e0ca0b993d821097d934f85a596e2c} DB
Event Waits Time(s) (ms) time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
library cache lock 1,202,096 102,479 85 65.7 Concurrenc
library cache: mutex X 979,370 54,345 55 34.8 Concurrenc
cursor: mutex S 15,437 240 16 .2 Concurrenc
DB CPU 159 .1
ksdxexeotherwait 235 19 79 .0 Other
Time Model Statistics DB/Inst: ORCL1123/orcl1123 Snaps: 254-255
-> Total time in database user-calls (DB Time): 156035.1s
-> Statistics including the word "background" measure background process
time, and so do not contribute to the DB time statistic
-> Ordered by {ff392285dba4c735eaf57cbf839a563e19e0ca0b993d821097d934f85a596e2c} or DB time desc, Statistic name
Statistic Name Time (s) {ff392285dba4c735eaf57cbf839a563e19e0ca0b993d821097d934f85a596e2c} of DB Time
------------------------------------------ ------------------ ------------
failed parse elapsed time 161,298.8 103.4
parse time elapsed 155,974.7 100.0
DB CPU 158.6 .1
sql execute elapsed time 6.7 .0
hard parse elapsed time 1.4 .0
connection management call elapsed time 0.4 .0
hard parse (sharing criteria) elapsed time 0.2 .0
PL/SQL execution elapsed time 0.2 .0
hard parse (bind mismatch) elapsed time 0.2 .0
PL/SQL compilation elapsed time 0.0 .0
repeated bind elapsed time 0.0 .0
sequence load elapsed time 0.0 .0
DB time 156,035.1
background elapsed time 8.2
background cpu time 1.8
{ff392285dba4c735eaf57cbf839a563e19e0ca0b993d821097d934f85a596e2c} of Waits
-----------------------------------------------
Total
Event Waits <1ms <2ms <4ms <8ms <16ms <32ms <=1s >1s
-------------------------- ----- ----- ----- ----- ----- ----- ----- ----- -----
Disk file operations I/O 7 100.0
LGWR wait for redo copy 3 66.7 33.3
SQL*Net break/reset to cli 3605 90.6 1.1 1.1 .8 4.4 2.1
SQL*Net message to client 7210 100.0 .0
asynch descriptor resize 187 100.0
control file parallel writ 106 39.6 24.5 2.8 7.5 12.3 8.5 4.7
control file sequential re 563 99.8 .2
cursor: mutex S 15.4K 1.3 1.8 2.4 5.2 51.9 33.1 4.3
db file async I/O submit 356 79.2 3.4 1.1 5.6 6.2 4.2 .3
db file scattered read 2 50.0 50.0
db file sequential read 8 62.5 37.5
ksdxexeotherwait 231 16.5 83.5
library cache lock 1199. .0 .0 .0 .0 .0 8.8 91.2 .0
library cache: mutex X 977.3 .6 .1 .1 .2 1.5 22.1 75.4 .0
Instance Activity Stats DB/Inst: ORCL1123/orcl1123 Snaps: 254-255
-> Ordered by statistic name
Statistic Total per Second per Trans
-------------------------------- ------------------ -------------- -------------
parse count (describe) 10 0.0 0.4
parse count (failures) 1,802 7.6 69.3
parse count (hard) 2,251 9.5 86.6
parse count (total) 1,535 6.5 59.0
parse time cpu 14,768 62.5 568.0
parse time elapsed 16,139,949 68,262.4 620,767.3
可以看到，全是分析失败的信息
3.5 分析systemstate数据
格式化后的数据
LOCK: Handle=0xde66f7c8 579: waiting for 'library cache lock'
LOCK: Handle=0xde66f7c8 588: 588: is waiting for 248:
LOCK: Handle=0xde66f7c8 603: 603: is waiting for 248:
LOCK: Handle=0xde66f7c8 604: 604: is waiting for 248:
LOCK: Handle=0xde66f7c8 609: 609: is waiting for 248:
LOCK: Handle=0xde66f7c8 656: 656: is waiting for 248:
LOCK: Handle=0xde66f7c8 670: 670: is waiting for 248:
LOCK: Handle=0xde66f7c8 686: waiting for 'library cache lock'
Mutex 88b5d9a2 248: 248: is waiting for 24: 52: 58: 71: 82: 83: 98: 107: 113: 114: 137: 157: 171: 176: 185: 187: 197: 200: 203: 213: 214: 222: 223: 224: 232: 244: 257: 270: 273: 275: 279: 283: 292: 300: 302: 304: 321: 324: 326: 333: 334: 338: 340: 341: 361: 373: 398: 402: 409: 410: 418: 420: 421: 437: 438: 456: 462: 482: 496: 507: 508: 522: 528: 533: 543: 548: 570: 571: 577: 579: 588: 603: 604: 609: 656: 670: 686:
Warning: The following processes have multiple session state objects and
may not be properly represented above :
42: 45: 50: 52: 58: 66: 67: 71: 72: 80: 82: 83: 89:
90: 98: 100: 105: 107: 110: 114: 135: 137: 140: 156: 171: 182:
185: 187: 188: 192: 195: 197: 200: 203: 205: 213: 214: 215: 218:
222: 224: 229: 232: 244: 250: 251: 257: 272: 275: 279: 281: 282:
288: 292: 293: 299: 300: 302: 304: 307: 308: 321: 324: 326: 333:
334: 335: 338: 341: 351: 358: 361: 367: 373: 377: 385: 393: 398:
402: 404: 405: 410: 421: 426: 434: 437: 438: 439: 440: 446: 454:
456: 462: 479: 482: 507: 508: 513: 528: 533: 542: 543: 565: 570:
571: 588: 595: 597: 600: 603: 604: 609: 633: 639: 641: 650: 655:
656: 657: 658: 670: 683: 692:
Object Names
~~~~~~~~~~~~
LOCK: Handle=0xde66f7c8
Mutex 88b5d9a2
End of report. 324493 Lines Processed.
从systemstate中，可以得到248导致后面的进程发生了阻塞，其实上前面我们也说明blocking_session一直在发生变化
3.5.1 分析de66f7c8对象与进程
以library*handle*0xde66f7c8来搜索，可以发现如下内容
13933 LibraryHandle: Address=0xde66f7c8 Hash=88b5d9a2 LockMode=S PinMode=0 LoadLockMode=0 Status=0
...............相同的内容
119661 LibraryHandle: Address=0xde66f7c8 Hash=88b5d9a2 LockMode=X PinMode=0 LoadLockMode=0 Status=0
120111 LibraryHandle: Address=0xde66f7c8 Hash=88b5d9a2 LockMode=S PinMode=0 LoadLockMode=0 Status=0
................相同的内容
这里可以看到多行有LockMode=X
这里有点没有想通的是能发现多行的LockMode=X。
进入119661查看
进入119661查看
能发现是一个对象在$BUILD$.14fcde33af666791
----------------------------------------
SO: 0x957d8a80, type: 78, owner: 0xc72b2858, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xdcb18188, name=LIBRARY OBJECT LOCK, file=kgl.h LINE:8547, pg=0
LibraryObjectLock: Address=0x957d8a80 Handle=0xde66f7c8 RequestMode=S CanBeBrokenCount=1 Incarnation=1 ExecutionCount=0
User=0xd95151a0 Session=0xd95151a0 ReferenceCount=1 Flags=CNB/[0201] SavepointNum=b2
LibraryHandle: Address=0xde66f7c8 Hash=88b5d9a2 LockMode=X PinMode=0 LoadLockMode=0 Status=0
ObjectName: Name=$BUILD$.14fcde33af666791
FullHashValue=fa05f23d882d81d150400d1088b5d9a2 Namespace=SQL AREA BUILD(82) Type=CURSOR(00) Identifier=0 OwnerIdn=0
Statistics: InvalidationCount=0 ExecutionCount=0 LoadCount=0 ActiveLocks=1 TotalLockCount=17660 TotalPinCount=0
Counters: BrokenCount=1 RevocablePointer=1 KeepDependency=0 BucketInUse=48952 HandleInUse=48952 HandleReferenceCount=0
Concurrency: DependencyMutex=0xde66f878(0, 0, 0, 0) Mutex=0xde66f8f8(0, 50665262, 11175948, 0) 这里也可以看到依赖的mutex与当前对象的mutex
Flags=RON/PIN/[00010000]
WaitersLists:
Lock=0xde66f858[0xa08f6e70,0x95441758]
Pin=0xde66f838[0xde66f838,0xde66f838]
LoadLock=0xde66f8b0[0xde66f8b0,0xde66f8b0]
Timestamp:
HandleReference: Address=0xde66f978 Handle=(nil) Flags=[00]
查找进程的信息
以进程 dcb18188*type=2来搜索
121479 PROCESS 248:
PROCESS 248:
----------------------------------------
SO: 0xdcb1d4f8, type: 2, owner: (nil), flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xdcb1d4f8, name=process, file=ksu.h LINE:12616, pg=0
(process) Oracle pid:248, ser:1, calls cur/top: 0xc72b4548/0xc72b4548
flags : (0x0) -
flags2: (0x0), flags3: (0x10)
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 258
last post received-location: kgl.h LINE:8666 ID:kgllkdl: in loop
last process to post me: dcbe0588 1 0
last post sent: 0 0 258
last post sent-location: kgl.h LINE:8666 ID:kgllkdl: in loop
last process posted by me: dca6af68 1 0
(latch info) wait_event=0 bits=0
Process Group: DEFAULT, pseudo proc: 0xdb31bde8
O/S info: user: oracle, term: UNKNOWN, ospid: 12798
OSD pid info: Unix process pid: 12798, image: oracle@orcl9i (TNS V1-V3)
Short stack dump:
ksedsts()+461<-ksdxfstk()+32<-ksdxcb()+1876<-sspuser()+112<-__pthread_sighandler_rt()+104<-__sighandler()<-semtimedop()+12<-skgpwwait()+160<-ksliwat()+1865<-kslwaitctx()+163<-ksfwaitctx()+14<-kglLockWait()+837<-kglUpgradeLock()+1168<-kksGetBuildLock()+321<-kksfbc()+12550<-kkspsc0()+1173<-kksParseCursor()+116<-opiosq0()+1965<-kpooprx()+274<-kpoal8()+829<-opiodr()+916<-ttcpip()+2242<-opitsk()+1673<-opiino()+966<-opiodr()+916<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+252<-main()+201<-__libc_start_main()+169<-0000000000001000
----------------------------------------
SO: 0xd9506358, type: 4, owner: 0xdcb1d4f8, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xdcb1d4f8, name=session, file=ksu.h LINE:12624, pg=0
(session) sid: 253 ser: 7 trans: (nil), creator: 0xdcb1d4f8
flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x40009) -/-/INC
DID: , short-term DID:
txn branch: (nil)
oct: 0, prv: 0, sql: 0xde8299d0, psql: 0xde6cd4a8, user: 0/SYS
ksuxds FALSE at location: 0
service name: SYS$USERS
client details:
O/S info: user: oracle, term: , ospid: 12797
machine: orcl9i program: sqlplus@orcl9i (TNS V1-V3)
application name: sqlplus@orcl9i (TNS V1-V3), hash value=2975165397
Current Wait Stack:
Not in wait; last wait ended 0.000276 sec ago
Wait State:
fixed_waits=0 flags=0x21 boundary=(nil)/-1
Session Wait History:
elapsed time of 0.000293 sec since last wait
0: waited for 'library cache lock'
handle address=0xde66f7c8, lock address=0x9578ac18, 100*mode+namespace=0x520002 这里也可以计算得到是请求共享锁10100100000000000000010 后 16位为锁
wait_id=12679 seq_num=18211 snap_id=1
wait times: snap=0.176035 sec, exc=0.176035 sec, total=0.176035 sec
wait times: max=infinite
wait counts: calls=1 os=1
occurred after 0.000031 sec of elapsed time
1: waited for 'library cache lock'
handle address=0xde66f7c8, lock address=0x9578ac18, 100*mode+namespace=0x520002
wait_id=12677 seq_num=18210 snap_id=2
wait times: snap=0.000000 sec, exc=0.136501 sec, total=0.167093 sec
wait times: max=infinite
wait counts: calls=1 os=1
occurred after 0.000000 sec of elapsed time
www.htz.pw > @event_pin_or_lock_p3_to_type_and_mode_16.sql
Enter value for p3: 520002
KGLSTDSC KGLSTIDN MODE
---------------------------------------------------------------- ---------- ----------
SQL AREA BUILD 82 2
这里就能看是sql area build以2的模式获取
并且还可以看到下面的mutex，此会话持有一个mutex
KGL-UOL SO Cache(total=12, free=5)
KGX Atomic Operation Log 0x95799c50
Mutex 0xde66f8f8(253, 0) idn 88b5d9a2 oper EXCL
Library Cache uid 253 efd 5 whr 119 slp 0
oper=19 pt1=0xde66f7c8 pt2=0x9578ac18 pt3=(nil)
pt4=(nil) pt5=(nil) ub4=0
LibraryHandle: Address=0xde66f7c8 Hash=88b5d9a2 LockMode=S PinMode=0 LoadLockMode=0 Status=0
ObjectName: Name=$BUILD$.14fcde33af666791
FullHashValue=fa05f23d882d81d150400d1088b5d9a2 Namespace=SQL AREA BUILD(82) Type=CURSOR(00) Identifier=0 OwnerIdn=0
这里可以看到248这个进程以x模式获取锁，但是，仍然在等待2模式获取同一个对象。
下面再选择另一个X模式的行
PROCESS 639:
----------------------------------------
SO: 0xdccb51c8, type: 2, owner: (nil), flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xdccb51c8, name=process, file=ksu.h LINE:12616, pg=0
(process) Oracle pid:639, ser:1, calls cur/top: 0xc739a728/0xc739a728
flags : (0x0) -
flags2: (0x0), flags3: (0x10)
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 259
last post received-location: kgl.h LINE:8669 ID:kgllkdl: post after freeing latch
last process to post me: dcb90098 1 0
last post sent: 0 0 258
last post sent-location: kgl.h LINE:8666 ID:kgllkdl: in loop
last process posted by me: dcbe58f8 1 0
(latch info) wait_event=0 bits=0
Process Group: DEFAULT, pseudo proc: 0xdb31bde8
O/S info: user: oracle, term: UNKNOWN, ospid: 14303
OSD pid info: Unix process pid: 14303, image: oracle@orcl9i (TNS V1-V3)
Short stack dump:
ksedsts()+461<-ksdxfstk()+32<-ksdxcb()+1876<-sspuser()+112<-__pthread_sighandler_rt()+104<-__sighandler()<-semtimedop()+12<-skgpwwait()+160<-ksliwat()+1865<-kslwaitctx()+163<-ksfwaitctx()+14<-kglLockWait()+837<-kglUpgradeLock()+1168<-kksGetBuildLock()+321<-kksfbc()+12550<-kkspsc0()+1173<-kksParseCursor()+116<-opiosq0()+1965<-kpooprx()+274<-kpoal8()+829<-opiodr()+916<-ttcpip()+2242<-opitsk()+1673<-opiino()+966<-opiodr()+916<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+252<-main()+201<-__libc_start_main()+169<-0000000000001000
----------------------------------------
SO: 0xdaf9fa30, type: 4, owner: 0xdccb51c8, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xdccb51c8, name=session, file=ksu.h LINE:12624, pg=0
(session) sid: 648 ser: 1 trans: (nil), creator: 0xdccb51c8
flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x40009) -/-/INC
DID: , short-term DID:
txn branch: (nil)
oct: 0, prv: 0, sql: 0xde8299d0, psql: 0xde6cd4a8, user: 0/SYS
ksuxds FALSE at location: 0
service name: SYS$USERS
client details:
O/S info: user: oracle, term: , ospid: 13611
machine: orcl9i program: sqlplus@orcl9i (TNS V1-V3)
application name: sqlplus@orcl9i (TNS V1-V3), hash value=2975165397
Current Wait Stack:
1: waiting for 'library cache: mutex X'
idn=0x88b5d9a2, value=0x15200000000, where=0x52
wait_id=12870 seq_num=18596 snap_id=1
wait times: snap=0.000092 sec, exc=0.000092 sec, total=0.000092 sec
wait times: max=infinite, heur=0.000092 sec
wait counts: calls=0 os=0
in_wait=1 iflags=0x532
以121663 Mutex 0xde66f8f8(253, 0) idn 88b5d9a2 oper EXCL
可以发现持有者就是248这个进程
4 分析结果
这里只限本等待事件的模拟，关于SQL解析等一些其它的内容，不包括在内
1，248这个会话持有mutex，阻塞了其它的会话获取mutex锁。
2，248会话等待library cache lock，但是自己已经持有library cache lock。
SQL语法错误导致library cache lock/library cache:mutex X：等您坐沙发呢！