(用户名,表、机器名已经被替换)
有用户反映一个大量session并发执行一个函数的精算业务执行不下去了,现场DBA发现后台大量等待library cache xxx和mutex s wait on x等。
查看blocking session,形成一条链条,顶端是session 930
简单取了几个session
21:42:17 SQL> select sid, sql_id, event, username, blocking_session from v$session where sid in (1084, 930, 624);
SID SQL_ID EVENT USERNAME BLOCKING_SESSION
---------- ------------- --------------------------------- ------------------------------ ----------------
624 6zhpa03mnt0n9 library cache pin XXXX 930
930 0stg7vnb99g3v db file sequential read XXXX
1084 a9jnnqxr4bnr5 library cache lock XXXX 624
查看要执行的SQL
SQL> select sql_text from v$sqlarea where sql_id = ' 6zhpa03mnt0n9 ';
SQL_TEXT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SELECT USER1. FUNC_NAME (:"SYS_B_0",:"SYS_B_1",to_date(:"SYS_B_2",:"SYS_B_3"), :"SYS_B_4") FROM dual
直接被930阻塞的624等待的是library cache pin,p1raw为 C00000066D3C9EC0
21:46:59 SQL> select p1raw, p2raw, p3raw from v$session where event = 'library cache pin';
P1RAW P2RAW P3RAW
---------------- ---------------- ----------------
C00000066D3C9EC0 C0000006655BB988 00018D9F00010003
根据锁的也是C00000066D3C9EC0查看,等待的是FUNC_NAME,正好是624要执行的函数
select ADDR,KGLHDADR,KGLHDPAR,KGLNAOWN,KGLNAOBJ,KGLNAHSH,KGLHDOBJ
from X$KGLOB
where KGLHDADR =' C00000066D3C9EC0 '
ADDR KGLHDADR KGLHDPAR KGLNAOWN KGLNAOBJ KGLNAHSH KGLHDOBJ
---------------- ---------------- ---------------- ------------------------------ ------------------------------ ---------- ----------------
9FFFFFFFBF3D5820 C00000066D3C9EC0 C00000066D3C9EC0 USER1 FUNC_NAME 1522840640 C000000641E61B98
21:42:17 SQL> select sid, sql_id, event, username, blocking_session from v$session where sid in (1084, 930, 624);
SID SQL_ID EVENT USERNAME BLOCKING_SESSION
---------- ------------- --------------------------------- ------------------------------ ----------------
624 6zhpa03mnt0n9 library cache pin XXXX 930
930 0stg7vnb99g3v db file sequential read XXXX
1084 a9jnnqxr4bnr5 library cache lock XXXX 624
查看要执行的SQL
SQL> select sql_text from v$sqlarea where sql_id = ' 6zhpa03mnt0n9 ';
SQL_TEXT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SELECT USER1. FUNC_NAME (:"SYS_B_0",:"SYS_B_1",to_date(:"SYS_B_2",:"SYS_B_3"), :"SYS_B_4") FROM dual
直接被930阻塞的624等待的是library cache pin,p1raw为 C00000066D3C9EC0
21:46:59 SQL> select p1raw, p2raw, p3raw from v$session where event = 'library cache pin';
P1RAW P2RAW P3RAW
---------------- ---------------- ----------------
C00000066D3C9EC0 C0000006655BB988 00018D9F00010003
根据锁的也是C00000066D3C9EC0查看,等待的是FUNC_NAME,正好是624要执行的函数
select ADDR,KGLHDADR,KGLHDPAR,KGLNAOWN,KGLNAOBJ,KGLNAHSH,KGLHDOBJ
from X$KGLOB
where KGLHDADR =' C00000066D3C9EC0 '
ADDR KGLHDADR KGLHDPAR KGLNAOWN KGLNAOBJ KGLNAHSH KGLHDOBJ
---------------- ---------------- ---------------- ------------------------------ ------------------------------ ---------- ----------------
9FFFFFFFBF3D5820 C00000066D3C9EC0 C00000066D3C9EC0 USER1 FUNC_NAME 1522840640 C000000641E61B98
(下面的system stat dump比上面v$session的查询时间晚一些,一些sid已经不一样了。)
首先查看当时systemdump trace里锁的情况,发现有一个锁是排他的。
[oracle@server2 tmp]$ grep "LibraryObjectLock:" systemstate.txt | grep c00000066d3c9ec0
LibraryObjectLock: Address=c000000669500cd8 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006693d4308 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006693cea90 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000669673810 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066cc5fde8 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066dd075a8 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006695aa460 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006691faaa8 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006714e1348 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000670f88e28 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066d4e5e18 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066c47df38 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000665a20c80 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006657a0700 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000671951b20 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000670e5fde8 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006699792d0 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000669836080 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000665784710 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000665704d38 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066c887118 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066c67d340 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006698eef10 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000669b7b5b8 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006659b8750 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006657d80e0 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000665519c28 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006657c5180 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066c887970 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066c8c3c08 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006714e08f0 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006714e06f0 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066d4e6670 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066d4e6570 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000670950368 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006709b9138 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000665783eb8 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006650dae98 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000665b44aa8 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000665a62048 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066d4e55c0 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066cdb0ac0 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000067094fb10 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000671230360 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066c8868c0 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066c451f20 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066d87da78 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066d87d020 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000669b15340 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006692d30c8 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000669c62550 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006692d2188 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000665b53668 Handle=c00000066d3c9ec0 Mode=X CanBeBrokenCount=1 Incarnation=2 ExecutionCount=0
从trace里找到这个锁
SO: 0xc000000665b53668, type: 78, owner: 0xc00000065e79e6f0 , flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc000000674757da0, name=LIBRARY OBJECT LOCK, file=kgl.h LINE:8547 ID:, pg=0
LibraryObjectLock: Address=c000000665b53668 Handle=c00000066d3c9ec0 Mode=X CanBeBrokenCount=1 Incarnation=2 ExecutionCount=0
User=c0000006609c9eb0 Session=c0000006609c9eb0 ReferenceCount=1 Flags=CNB/[0001] SavepointNum=ef
LibraryHandle: Address=c00000066d3c9ec0 Hash=5ac4b440 LockMode=X PinMode=S LoadLockMode=0 Status=INVL
ObjectName: Name=USER1.FUNC_NAME
FullHashValue=1b93084d9ed4e650c5bf9beb5ac4b440 Namespace=TABLE/PROCEDURE(01) Type=FUNCTION(08) Identifier=101791 OwnerIdn=117
Statistics: InvalidationCount=1 ExecutionCount=147 LoadCount=11 ActiveLocks=27 TotalLockCount=261 TotalPinCount=310
Counters: BrokenCount=1 RevocablePointer=2 KeepDependency=0 BucketInUse=10007 HandleInUse=10007 HandleReferenceCount=0
Concurrency: DependencyMutex=c00000066d3c9f70(0, 248, 0, 0) Mutex=c00000066d3c9ff0(0, 81582, 527, 0)
Flags=PIN/TIM/[00002801]
WaitersLists:
Lock=c00000066d3c9f50[c00000066d3c9f50,c00000066d3c9f50]
Pin=c00000066d3c9f30[c000000665b535d8,c000000665b535d8]
LoadLock=c00000066d3c9fa8[c00000066d3c9fa8,c00000066d3c9fa8]
Timestamp: Current=12-18-2014 00:01:57
HandleReference: Address=c00000066d3ca070 Handle=c000000669ef9cc8 Flags=OWN[200]
LibraryObject: Address=c000000641e61b98 HeapMask=0000-2011-2015-0000 Flags=EXS/LOC[0004] Flags2=[0000] PublicFlags=NST/DBG[0003]
DataBlocks:
Block: #='0' name=KGLH0^5ac4b440 pins=0 Change=NONE
Heap=c00000066d335a38 Pointer=c000000641e61c38 Extent=c000000641e61b18 Flags=I/-/P/A/-/-
FreedLocation=0 Alloc=7.804688 Size=7.953125 LoadTime=668321668
Block: #='4' name=PLMCD^5ac4b440 pins=26 Change=NONE
Heap=c000000641e3ccd0 Pointer=c0000002e293fca0 Extent=c0000002e293fc20 Flags=I/-/P/A/-/-
FreedLocation=0 Alloc=18.500000 Size=20.093750 LoadTime=668321850
Block: #='13' name=KGLA^5ac4b440 pins=26 Change=NONE
Heap=c000000641e3d408 Pointer=c0000002e3d4aad0 Extent=c0000002e3d4aa50 Flags=I/-/P/A/-/-
FreedLocation=0 Alloc=1.140625 Size=2.109375 LoadTime=668321885
根据上面的“owner: 0xc00000065e79e6f0 ”找到了它的调用者(是一个事务),
[oracle@server2 tmp]$ grep "LibraryObjectLock:" systemstate.txt | grep c00000066d3c9ec0
LibraryObjectLock: Address=c000000669500cd8 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006693d4308 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006693cea90 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000669673810 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066cc5fde8 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066dd075a8 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006695aa460 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006691faaa8 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006714e1348 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000670f88e28 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066d4e5e18 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066c47df38 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000665a20c80 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006657a0700 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000671951b20 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000670e5fde8 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006699792d0 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000669836080 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000665784710 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000665704d38 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066c887118 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066c67d340 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006698eef10 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000669b7b5b8 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006659b8750 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006657d80e0 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000665519c28 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006657c5180 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066c887970 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066c8c3c08 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c0000006714e08f0 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006714e06f0 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066d4e6670 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066d4e6570 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000670950368 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006709b9138 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000665783eb8 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006650dae98 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000665b44aa8 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000665a62048 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066d4e55c0 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066cdb0ac0 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000067094fb10 Handle=c00000066d3c9ec0 Mode=N CallPin=c000000671230360 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066c8868c0 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066c451f20 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c00000066d87da78 Handle=c00000066d3c9ec0 Mode=N CallPin=c00000066d87d020 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000669b15340 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006692d30c8 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000669c62550 Handle=c00000066d3c9ec0 Mode=N CallPin=c0000006692d2188 CanBeBrokenCount=1 Incarnation=1 ExecutionCount=2
LibraryObjectLock: Address=c000000665b53668 Handle=c00000066d3c9ec0 Mode=X CanBeBrokenCount=1 Incarnation=2 ExecutionCount=0
从trace里找到这个锁
SO: 0xc000000665b53668, type: 78, owner: 0xc00000065e79e6f0 , flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc000000674757da0, name=LIBRARY OBJECT LOCK, file=kgl.h LINE:8547 ID:, pg=0
LibraryObjectLock: Address=c000000665b53668 Handle=c00000066d3c9ec0 Mode=X CanBeBrokenCount=1 Incarnation=2 ExecutionCount=0
User=c0000006609c9eb0 Session=c0000006609c9eb0 ReferenceCount=1 Flags=CNB/[0001] SavepointNum=ef
LibraryHandle: Address=c00000066d3c9ec0 Hash=5ac4b440 LockMode=X PinMode=S LoadLockMode=0 Status=INVL
ObjectName: Name=USER1.FUNC_NAME
FullHashValue=1b93084d9ed4e650c5bf9beb5ac4b440 Namespace=TABLE/PROCEDURE(01) Type=FUNCTION(08) Identifier=101791 OwnerIdn=117
Statistics: InvalidationCount=1 ExecutionCount=147 LoadCount=11 ActiveLocks=27 TotalLockCount=261 TotalPinCount=310
Counters: BrokenCount=1 RevocablePointer=2 KeepDependency=0 BucketInUse=10007 HandleInUse=10007 HandleReferenceCount=0
Concurrency: DependencyMutex=c00000066d3c9f70(0, 248, 0, 0) Mutex=c00000066d3c9ff0(0, 81582, 527, 0)
Flags=PIN/TIM/[00002801]
WaitersLists:
Lock=c00000066d3c9f50[c00000066d3c9f50,c00000066d3c9f50]
Pin=c00000066d3c9f30[c000000665b535d8,c000000665b535d8]
LoadLock=c00000066d3c9fa8[c00000066d3c9fa8,c00000066d3c9fa8]
Timestamp: Current=12-18-2014 00:01:57
HandleReference: Address=c00000066d3ca070 Handle=c000000669ef9cc8 Flags=OWN[200]
LibraryObject: Address=c000000641e61b98 HeapMask=0000-2011-2015-0000 Flags=EXS/LOC[0004] Flags2=[0000] PublicFlags=NST/DBG[0003]
DataBlocks:
Block: #='0' name=KGLH0^5ac4b440 pins=0 Change=NONE
Heap=c00000066d335a38 Pointer=c000000641e61c38 Extent=c000000641e61b18 Flags=I/-/P/A/-/-
FreedLocation=0 Alloc=7.804688 Size=7.953125 LoadTime=668321668
Block: #='4' name=PLMCD^5ac4b440 pins=26 Change=NONE
Heap=c000000641e3ccd0 Pointer=c0000002e293fca0 Extent=c0000002e293fc20 Flags=I/-/P/A/-/-
FreedLocation=0 Alloc=18.500000 Size=20.093750 LoadTime=668321850
Block: #='13' name=KGLA^5ac4b440 pins=26 Change=NONE
Heap=c000000641e3d408 Pointer=c0000002e3d4aad0 Extent=c0000002e3d4aa50 Flags=I/-/P/A/-/-
FreedLocation=0 Alloc=1.140625 Size=2.109375 LoadTime=668321885
根据上面的“owner: 0xc00000065e79e6f0 ”找到了它的调用者(是一个事务),
SO: 0xc000000648d79818, type: 3, owner: 0xc000000648d7c4a0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc000000674757da0, name=call, file=ksu.h LINE:12620 ID:, pg=0
(call) sess: cur c0000006609c9eb0, rec 0, usr c0000006609c9eb0; flg:40 fl2:1; depth:1
svpt(xcb:0x0000000000000000 sptn:0xec uba: 0x00000000.0000.00)
xctsp name:?
svpt(xcb:0x0000000000000000 sptn:0x0 uba: 0x00000000.0000.00)
status:INVALID next:0x0000000000000000
ksudlc FALSE at location: 0
----------------------------------------
SO: 0xc00000065e79e6f0 , type: 56, owner: 0xc000000648d79818, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc000000674757da0, name= transaction , file=ktccts.h LINE:410 ID:, pg=0
(trans) flg = 0x00000021, flg2 = 0x00080000, flg3 = 0x00000000, prx = 0x0000000000000000, ros = 2147483647, crtses=0xc0000006609c9eb0
flg = 0x00000021: ALC RCV
flg2 = 0x00080000: NIP
flg3 = 0x00000000:
bsn = 0xef bndsn = 0xef spn = 0xef
efd = 11 rfd = 0 DID:
file:kql.c lineno:3170
parent xid: 0x0000.000.00000000
env [0xc00000065e79eb08]: (scn: 0x0000.00000000 xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 statement num=0 parent xid: 0x0000.000.00000000 st-scn: 0x0000.00000000 hi-scn: 0x0000.00000000 ma-scn: 0x0000.00000000 flg: 0x00000000)
cev: (spc = 0 arsp = 0x0000000000000000 ubkds (ubk:tsn: 0 rdba: 0x00000000 flag:0x0 hdl:0x0000000000000000 addr:0x0000000000000000) useg tsn: 0 rdba: 0x00000000
hwm uba: 0x00000000.0000.00 col uba: 0x00000000.0000.00
num bl: 0 bk list: 0x0)
cr opc: 0x0 spc: 0 uba: 0x00000000.0000.00
Begin scn:0x0000.00000000 uba:0x00000000.0000.00 ts:1421417318[01/16/2015 22:08:38]
Undo blks: 0 recs: 0
ccbstg: 0x00000000
(enqueue) released enqueue or enqueue in flux
lock_flag: 0x0, lock: 0xc00000065e79e768, res: 0xc000000674e6bd68
own: 0xc0000006609c9eb0, sess: 0xc0000006609c9eb0, prv: 0xc00000065e79e778
xga: 0x0000000000000000, heap: UGA
tsnl:0xc00000066db73320 nent:0 nxt:0x0000000000000000
Trans IMU st: 0 Pool index 65535, Redo pool 0xc00000065e79eeb0, Undo pool 0xc00000065e79ef98
Redo pool range [0x9fffffffbf31b700 0x9fffffffbf31b700 0x9fffffffbf31df00]
Undo pool range [0x9fffffffbf318f00 0x9fffffffbf318f00 0x9fffffffbf31b700]
chnf control flags 0x0 CHNF hwm uba uba: 0x00000000.0000.00 ----------------------------------------
SO: 0xc000000665b53568, type: 79, owner: 0xc00000065e79e6f0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc000000674757da0, name=LIBRARY OBJECT PIN, file=kgl.h LINE:8551 ID:, pg=0
LibraryObjectPin: Address=c000000665b53568 Handle=c00000066d3c9ec0 RequestMode=X User=c0000006609c9eb0 Session=c0000006609c9eb0 Count=0 Mask=0000 Flags=[00] SavepointNum=0xef
LibraryHandle: Address=c00000066d3c9ec0 Hash=5ac4b440 LockMode=X PinMode=S LoadLockMode=0 Status=INVL
ObjectName: Name=USER1.FUNC_NAME
FullHashValue=1b93084d9ed4e650c5bf9beb5ac4b440 Namespace=TABLE/PROCEDURE(01) Type=FUNCTION(08) Identifier=101791 OwnerIdn=117
Statistics: InvalidationCount=1 ExecutionCount=147 LoadCount=11 ActiveLocks=27 TotalLockCount=261 TotalPinCount=310
Counters: BrokenCount=1 RevocablePointer=2 KeepDependency=0 BucketInUse=10007 HandleInUse=10007 HandleReferenceCount=0
Concurrency: DependencyMutex=c00000066d3c9f70(0, 248, 0, 0) Mutex=c00000066d3c9ff0(0, 81582, 527, 0)
Flags=PIN/TIM/[00002801]
WaitersLists:
Lock=c00000066d3c9f50[c00000066d3c9f50,c00000066d3c9f50]
Pin=c00000066d3c9f30[c000000665b535d8,c000000665b535d8]
LoadLock=c00000066d3c9fa8[c00000066d3c9fa8,c00000066d3c9fa8]
Timestamp: Current=12-18-2014 00:01:57
HandleReference: Address=c00000066d3ca070 Handle=c000000669ef9cc8 Flags=OWN[200]
LibraryObject: Address=c000000641e61b98 HeapMask=0000-2011-2015-0000 Flags=EXS/LOC[0004] Flags2=[0000] PublicFlags=NST/DBG[0003]
DataBlocks:
Block: #='0' name=KGLH0^5ac4b440 pins=0 Change=NONE
Heap=c00000066d335a38 Pointer=c000000641e61c38 Extent=c000000641e61b18 Flags=I/-/P/A/-/-
FreedLocation=0 Alloc=7.804688 Size=7.953125 LoadTime=668321668
Block: #='4' name=PLMCD^5ac4b440 pins=26 Change=NONE
Heap=c000000641e3ccd0 Pointer=c0000002e293fca0 Extent=c0000002e293fc20 Flags=I/-/P/A/-/-
FreedLocation=0 Alloc=18.500000 Size=20.093750 LoadTime=668321850
Block: #='13' name=KGLA^5ac4b440 pins=26 Change=NONE
Heap=c000000641e3d408 Pointer=c0000002e3d4aad0 Extent=c0000002e3d4aa50 Flags=I/-/P/A/-/-
FreedLocation=0 Alloc=1.140625 Size=2.109375 LoadTime=668321885 ----------------------------------------
进一步找到调用者的调用者。
SO: 0xc000000648d7c4a0, type: 3, owner: 0xc000000674757da0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc000000674757da0, name=call, file=ksu.h LINE:12620 ID:, pg=0
(call) sess: cur c0000006609c9eb0, rec c0000006609c9eb0, usr c0000006609c9eb0; flg:28 fl2:1; depth:0
svpt(xcb:0x0000000000000000 sptn:0xea uba: 0x00000000.0000.00)
ksudlc FALSE at location: 0
最后定位到了进程。是一个oracle用户以XXXX从本地用户登录的。
发现这个进程等待的是library cache pin,最终阻塞者是930
proc=0xc000000674757da0, name=call, file=ksu.h LINE:12620 ID:, pg=0
(call) sess: cur c0000006609c9eb0, rec 0, usr c0000006609c9eb0; flg:40 fl2:1; depth:1
svpt(xcb:0x0000000000000000 sptn:0xec uba: 0x00000000.0000.00)
xctsp name:?
svpt(xcb:0x0000000000000000 sptn:0x0 uba: 0x00000000.0000.00)
status:INVALID next:0x0000000000000000
ksudlc FALSE at location: 0
----------------------------------------
SO: 0xc00000065e79e6f0 , type: 56, owner: 0xc000000648d79818, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc000000674757da0, name= transaction , file=ktccts.h LINE:410 ID:, pg=0
(trans) flg = 0x00000021, flg2 = 0x00080000, flg3 = 0x00000000, prx = 0x0000000000000000, ros = 2147483647, crtses=0xc0000006609c9eb0
flg = 0x00000021: ALC RCV
flg2 = 0x00080000: NIP
flg3 = 0x00000000:
bsn = 0xef bndsn = 0xef spn = 0xef
efd = 11 rfd = 0 DID:
file:kql.c lineno:3170
parent xid: 0x0000.000.00000000
env [0xc00000065e79eb08]: (scn: 0x0000.00000000 xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 statement num=0 parent xid: 0x0000.000.00000000 st-scn: 0x0000.00000000 hi-scn: 0x0000.00000000 ma-scn: 0x0000.00000000 flg: 0x00000000)
cev: (spc = 0 arsp = 0x0000000000000000 ubkds (ubk:tsn: 0 rdba: 0x00000000 flag:0x0 hdl:0x0000000000000000 addr:0x0000000000000000) useg tsn: 0 rdba: 0x00000000
hwm uba: 0x00000000.0000.00 col uba: 0x00000000.0000.00
num bl: 0 bk list: 0x0)
cr opc: 0x0 spc: 0 uba: 0x00000000.0000.00
Begin scn:0x0000.00000000 uba:0x00000000.0000.00 ts:1421417318[01/16/2015 22:08:38]
Undo blks: 0 recs: 0
ccbstg: 0x00000000
(enqueue) released enqueue or enqueue in flux
lock_flag: 0x0, lock: 0xc00000065e79e768, res: 0xc000000674e6bd68
own: 0xc0000006609c9eb0, sess: 0xc0000006609c9eb0, prv: 0xc00000065e79e778
xga: 0x0000000000000000, heap: UGA
tsnl:0xc00000066db73320 nent:0 nxt:0x0000000000000000
Trans IMU st: 0 Pool index 65535, Redo pool 0xc00000065e79eeb0, Undo pool 0xc00000065e79ef98
Redo pool range [0x9fffffffbf31b700 0x9fffffffbf31b700 0x9fffffffbf31df00]
Undo pool range [0x9fffffffbf318f00 0x9fffffffbf318f00 0x9fffffffbf31b700]
chnf control flags 0x0 CHNF hwm uba uba: 0x00000000.0000.00 ----------------------------------------
SO: 0xc000000665b53568, type: 79, owner: 0xc00000065e79e6f0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc000000674757da0, name=LIBRARY OBJECT PIN, file=kgl.h LINE:8551 ID:, pg=0
LibraryObjectPin: Address=c000000665b53568 Handle=c00000066d3c9ec0 RequestMode=X User=c0000006609c9eb0 Session=c0000006609c9eb0 Count=0 Mask=0000 Flags=[00] SavepointNum=0xef
LibraryHandle: Address=c00000066d3c9ec0 Hash=5ac4b440 LockMode=X PinMode=S LoadLockMode=0 Status=INVL
ObjectName: Name=USER1.FUNC_NAME
FullHashValue=1b93084d9ed4e650c5bf9beb5ac4b440 Namespace=TABLE/PROCEDURE(01) Type=FUNCTION(08) Identifier=101791 OwnerIdn=117
Statistics: InvalidationCount=1 ExecutionCount=147 LoadCount=11 ActiveLocks=27 TotalLockCount=261 TotalPinCount=310
Counters: BrokenCount=1 RevocablePointer=2 KeepDependency=0 BucketInUse=10007 HandleInUse=10007 HandleReferenceCount=0
Concurrency: DependencyMutex=c00000066d3c9f70(0, 248, 0, 0) Mutex=c00000066d3c9ff0(0, 81582, 527, 0)
Flags=PIN/TIM/[00002801]
WaitersLists:
Lock=c00000066d3c9f50[c00000066d3c9f50,c00000066d3c9f50]
Pin=c00000066d3c9f30[c000000665b535d8,c000000665b535d8]
LoadLock=c00000066d3c9fa8[c00000066d3c9fa8,c00000066d3c9fa8]
Timestamp: Current=12-18-2014 00:01:57
HandleReference: Address=c00000066d3ca070 Handle=c000000669ef9cc8 Flags=OWN[200]
LibraryObject: Address=c000000641e61b98 HeapMask=0000-2011-2015-0000 Flags=EXS/LOC[0004] Flags2=[0000] PublicFlags=NST/DBG[0003]
DataBlocks:
Block: #='0' name=KGLH0^5ac4b440 pins=0 Change=NONE
Heap=c00000066d335a38 Pointer=c000000641e61c38 Extent=c000000641e61b18 Flags=I/-/P/A/-/-
FreedLocation=0 Alloc=7.804688 Size=7.953125 LoadTime=668321668
Block: #='4' name=PLMCD^5ac4b440 pins=26 Change=NONE
Heap=c000000641e3ccd0 Pointer=c0000002e293fca0 Extent=c0000002e293fc20 Flags=I/-/P/A/-/-
FreedLocation=0 Alloc=18.500000 Size=20.093750 LoadTime=668321850
Block: #='13' name=KGLA^5ac4b440 pins=26 Change=NONE
Heap=c000000641e3d408 Pointer=c0000002e3d4aad0 Extent=c0000002e3d4aa50 Flags=I/-/P/A/-/-
FreedLocation=0 Alloc=1.140625 Size=2.109375 LoadTime=668321885 ----------------------------------------
进一步找到调用者的调用者。
SO: 0xc000000648d7c4a0, type: 3, owner: 0xc000000674757da0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc000000674757da0, name=call, file=ksu.h LINE:12620 ID:, pg=0
(call) sess: cur c0000006609c9eb0, rec c0000006609c9eb0, usr c0000006609c9eb0; flg:28 fl2:1; depth:0
svpt(xcb:0x0000000000000000 sptn:0xea uba: 0x00000000.0000.00)
ksudlc FALSE at location: 0
最后定位到了进程。是一个oracle用户以XXXX从本地用户登录的。
发现这个进程等待的是library cache pin,最终阻塞者是930
从session的等待事件可以看出,请求pin的handle就是
c00000066d3c9ec0,也就是
PROCESS 87:
----------------------------------------
SO: 0xc000000674757da0, type: 2, owner: 0x0000000000000000, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc000000674757da0, name=process, file=ksu.h LINE:12616 ID:, pg=0
(process) Oracle pid:87, ser:21, calls cur/top: 0xc000000648d79818/0xc000000648d7c4a0
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: 137 0 2
last post received-location: ksl2.h LINE:2362 ID:kslpsr
last process to post me: c00000065c7643d8 1 6
last post sent: 0 0 259
last post sent-location: kgl.h LINE:8669 ID:kgllkdl: post after freeing latch
last process posted by me: c00000065c76fb68 62 0
(latch info) wait_event=0 bits=0
Process Group: DEFAULT, pseudo proc: 0xc000000658884340
O/S info: user: oracle, term: UNKNOWN, ospid: 26253
OSD pid info: Unix process pid: 26253, image: oracle@hostname (TNS V1-V3)
PROCESS 87:
----------------------------------------
SO: 0xc000000674757da0, type: 2, owner: 0x0000000000000000, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc000000674757da0, name=process, file=ksu.h LINE:12616 ID:, pg=0
(process) Oracle pid:87, ser:21, calls cur/top: 0xc000000648d79818/0xc000000648d7c4a0
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: 137 0 2
last post received-location: ksl2.h LINE:2362 ID:kslpsr
last process to post me: c00000065c7643d8 1 6
last post sent: 0 0 259
last post sent-location: kgl.h LINE:8669 ID:kgllkdl: post after freeing latch
last process posted by me: c00000065c76fb68 62 0
(latch info) wait_event=0 bits=0
Process Group: DEFAULT, pseudo proc: 0xc000000658884340
O/S info: user: oracle, term: UNKNOWN, ospid: 26253
OSD pid info: Unix process pid: 26253, image: oracle@hostname (TNS V1-V3)
Short stack dump:
ksedsts()+544
----------------------------------------
SO: 0xc0000006609c9eb0, type: 4, owner: 0xc000000674757da0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc000000674757da0, name=session, file=ksu.h LINE:12624 ID:, pg=0
(session) sid: 547 ser: 54275 trans: 0xc00000065e79e6f0, creator: 0xc000000674757da0
flags: (0x100045) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x48009) -/DDLT2/INC
DID: , short-term DID:
txn branch: 0x0000000000000000
oct: 3, prv: 0, sql: 0xc0000006698e0ca8, psql: 0xc00000066de06458, user: 272/JSTS
ksuxds FALSE at location: 0
service name: SYS$USERS
client details:
O/S info: user: oracle, term: , ospid: 26247
machine: hostname program: sqlplus@hostname(TNS V1-V3)
ksedsts()+544
----------------------------------------
SO: 0xc0000006609c9eb0, type: 4, owner: 0xc000000674757da0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc000000674757da0, name=session, file=ksu.h LINE:12624 ID:, pg=0
(session) sid: 547 ser: 54275 trans: 0xc00000065e79e6f0, creator: 0xc000000674757da0
flags: (0x100045) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x48009) -/DDLT2/INC
DID: , short-term DID:
txn branch: 0x0000000000000000
oct: 3, prv: 0, sql: 0xc0000006698e0ca8, psql: 0xc00000066de06458, user: 272/JSTS
ksuxds FALSE at location: 0
service name: SYS$USERS
client details:
O/S info: user: oracle, term: , ospid: 26247
machine: hostname program: sqlplus@hostname(TNS V1-V3)
application name: SQL*Plus, hash value=3669949024
Current Wait Stack:
0: waiting for ' library cache pin '
handle address= 0xc00000066d3c9ec0 , pin address= 0xc000000665b53568 , 100*mode+namespace=0x18d9f00010003
wait_id=39 seq_num=40 snap_id=1
wait times: snap=14 min 30 sec, exc=14 min 30 sec, total=14 min 30 sec
wait times: max=15 min 0 sec, heur=14 min 30 sec
wait counts: calls=291 os=291
in_wait=1 iflags=0x15a2
There is at least one session blocking this session.
Dumping first 3 direct blockers:
inst: 1, sid: 930, ser: 427
inst: 1, sid: 1159, ser: 14923
inst: 1, sid: 4, ser: 263
Dumping final blocker:
inst: 1, sid: 930, ser: 427
There are 4 sessions blocked by this session.
Dumping one waiter:
inst: 1, sid: 621, ser: 48053
wait event: 'cursor: pin S wait on X'
p1: 'idn'=0x6e45d2e5
p2: 'value'=0x22300000000
p3: 'where'=0x500000000
row_wait_obj#: 4294967295, block#: 0, row#: 0, file# 0
min_blocked_time: 136 secs, waiter_cache_ver: 59785
Wait State:
fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1
之前的片段里有这个pin,可以根据地址定位
它获取了FUNC_NAME的handle排他锁,正在申请heep上的排他模式的pin。
Current Wait Stack:
0: waiting for ' library cache pin '
handle address= 0xc00000066d3c9ec0 , pin address= 0xc000000665b53568 , 100*mode+namespace=0x18d9f00010003
wait_id=39 seq_num=40 snap_id=1
wait times: snap=14 min 30 sec, exc=14 min 30 sec, total=14 min 30 sec
wait times: max=15 min 0 sec, heur=14 min 30 sec
wait counts: calls=291 os=291
in_wait=1 iflags=0x15a2
There is at least one session blocking this session.
Dumping first 3 direct blockers:
inst: 1, sid: 930, ser: 427
inst: 1, sid: 1159, ser: 14923
inst: 1, sid: 4, ser: 263
Dumping final blocker:
inst: 1, sid: 930, ser: 427
There are 4 sessions blocked by this session.
Dumping one waiter:
inst: 1, sid: 621, ser: 48053
wait event: 'cursor: pin S wait on X'
p1: 'idn'=0x6e45d2e5
p2: 'value'=0x22300000000
p3: 'where'=0x500000000
row_wait_obj#: 4294967295, block#: 0, row#: 0, file# 0
min_blocked_time: 136 secs, waiter_cache_ver: 59785
Wait State:
fixed_waits=0 flags=0x22 boundary=0x0000000000000000/-1
之前的片段里有这个pin,可以根据地址定位
它获取了FUNC_NAME的handle排他锁,正在申请heep上的排他模式的pin。
LibraryObjectPin: Address=c000000665b53568 Handle=c00000066d3c9ec0
RequestMode
=X
User=c0000006609c9eb0 Session=c0000006609c9eb0 Count=0 Mask=0000 Flags=[00] SavepointNum=0xef
LibraryHandle: Address=c00000066d3c9ec0 Hash=5ac4b440 LockMode=X PinMode=S LoadLockMode=0 Status=INVL
ObjectName: Name=USER1.FUNC_NAME
查看session 930
是USER1用户。
它在走db file sequential read正常干活。
SO: 0xc000000658b7acc0, type: 4, owner: 0xc00000065c76c958, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc00000065c76c958, name=session, file=ksu.h LINE:12624 ID:, pg=0
(session) sid: 930 ser: 427 trans: 0x0000000000000000, creator: 0xc00000065c76c958
flags: (0x100045) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x9) -/-/INC
DID: , short-term DID:
txn branch: 0x0000000000000000
oct: 3, prv: 0, sql: 0xc000000671443550, psql: 0xc000000671443550, user: 117/USER1
ksuxds FALSE at location: 0
service name: SYS$USERS
client details:
O/S info: user: oracle, term: , ospid: 3566
machine: hostname program: sqlplus@hostname (TNS V1-V3)
LibraryHandle: Address=c00000066d3c9ec0 Hash=5ac4b440 LockMode=X PinMode=S LoadLockMode=0 Status=INVL
ObjectName: Name=USER1.FUNC_NAME
查看session 930
是USER1用户。
它在走db file sequential read正常干活。
SO: 0xc000000658b7acc0, type: 4, owner: 0xc00000065c76c958, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc00000065c76c958, name=session, file=ksu.h LINE:12624 ID:, pg=0
(session) sid: 930 ser: 427 trans: 0x0000000000000000, creator: 0xc00000065c76c958
flags: (0x100045) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x9) -/-/INC
DID: , short-term DID:
txn branch: 0x0000000000000000
oct: 3, prv: 0, sql: 0xc000000671443550, psql: 0xc000000671443550, user: 117/USER1
ksuxds FALSE at location: 0
service name: SYS$USERS
client details:
O/S info: user: oracle, term: , ospid: 3566
machine: hostname program: sqlplus@hostname (TNS V1-V3)
application name: SQL*Plus, hash value=3669949024
Current Wait Stack:
0: waiting for 'db file sequential read'
file#=0x4d, block#=0xb055, blocks=0x1
wait_id=85190941 seq_num=63573 snap_id=1
wait times: snap=0.001055 sec, exc=0.001055 sec, total=0.001055 sec
wait times: max=infinite, heur=0.001055 sec
wait counts: calls=0 os=0
in_wait=1 iflags=0x5a0
There are 5 sessions blocked by this session.
Dumping one waiter:
inst: 1, sid: 547, ser: 54275
wait event: 'library cache pin'
p1: 'handle address'=0xc00000066d3c9ec0
p2: 'pin address'=0xc000000665b53568
p3: '100*mode+namespace'=0x18d9f00010003
并且已经已共享模式获取pin了,因此会阻塞任何排他pin
SO: 0xc0000006693d4308, type: 79, owner: 0xc0000006487959c0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc00000065c76c958, name=LIBRARY OBJECT PIN, file=kgl.h LINE:8551 ID:, pg=0
LibraryObjectPin : Address=c0000006693d4308 Handle=c00000066d3c9ec0 Mode=S Lock=c000000669500cd8 Context=9fffffffbf3f4058 User=c000000658b7acc0 Session=c000000658b7acc0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x718a7432
LibraryHandle: Address=c00000066d3c9ec0 Hash=5ac4b440 LockMode=X PinMode=S LoadLockMode=0 Status=INVL
ObjectName: Name=USER1.FUNC_NAME
FullHashValue=1b93084d9ed4e650c5bf9beb5ac4b440 Namespace=TABLE/PROCEDURE(01) Type=FUNCTION(08) Identifier=101791 OwnerIdn=117
Statistics: InvalidationCount=1 ExecutionCount=147 LoadCount=11 ActiveLocks=27 TotalLockCount=261 TotalPinCount=310
Counters: BrokenCount=1 RevocablePointer=2 KeepDependency=0 BucketInUse=10007 HandleInUse=10007 HandleReferenceCount=0
Concurrency: DependencyMutex=c00000066d3c9f70(0, 248, 0, 0) Mutex=c00000066d3c9ff0(0, 81548, 527, 0)
Flags=PIN/TIM/[00002801]
总结一下:
Current Wait Stack:
0: waiting for 'db file sequential read'
file#=0x4d, block#=0xb055, blocks=0x1
wait_id=85190941 seq_num=63573 snap_id=1
wait times: snap=0.001055 sec, exc=0.001055 sec, total=0.001055 sec
wait times: max=infinite, heur=0.001055 sec
wait counts: calls=0 os=0
in_wait=1 iflags=0x5a0
There are 5 sessions blocked by this session.
Dumping one waiter:
inst: 1, sid: 547, ser: 54275
wait event: 'library cache pin'
p1: 'handle address'=0xc00000066d3c9ec0
p2: 'pin address'=0xc000000665b53568
p3: '100*mode+namespace'=0x18d9f00010003
并且已经已共享模式获取pin了,因此会阻塞任何排他pin
SO: 0xc0000006693d4308, type: 79, owner: 0xc0000006487959c0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xc00000065c76c958, name=LIBRARY OBJECT PIN, file=kgl.h LINE:8551 ID:, pg=0
LibraryObjectPin : Address=c0000006693d4308 Handle=c00000066d3c9ec0 Mode=S Lock=c000000669500cd8 Context=9fffffffbf3f4058 User=c000000658b7acc0 Session=c000000658b7acc0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x718a7432
LibraryHandle: Address=c00000066d3c9ec0 Hash=5ac4b440 LockMode=X PinMode=S LoadLockMode=0 Status=INVL
ObjectName: Name=USER1.FUNC_NAME
FullHashValue=1b93084d9ed4e650c5bf9beb5ac4b440 Namespace=TABLE/PROCEDURE(01) Type=FUNCTION(08) Identifier=101791 OwnerIdn=117
Statistics: InvalidationCount=1 ExecutionCount=147 LoadCount=11 ActiveLocks=27 TotalLockCount=261 TotalPinCount=310
Counters: BrokenCount=1 RevocablePointer=2 KeepDependency=0 BucketInUse=10007 HandleInUse=10007 HandleReferenceCount=0
Concurrency: DependencyMutex=c00000066d3c9f70(0, 248, 0, 0) Mutex=c00000066d3c9ff0(0, 81548, 527, 0)
Flags=PIN/TIM/[00002801]
总结一下:
当一个session需要执行一个失效的函数时,会先尝试编译它。
当时的场景是一个共享pin阻塞了已握有排他锁并且请求排他pin的session 547(下面的最后一行),session 547又阻塞了其它一系列session。
从下面结果可以看出持有共享pin的session非常多,因此无论杀掉顶端的谁,都会有另一个接替它。
而单杀547也没用,因为任何一个试图执行这个函数的session都会取代session 547,尝试编译函数。
[oracle@server2 tmp]$ grep -E "LibraryObjectPin.*Handle=c00000066d3c9ec0 " systemstate.txt
LibraryObjectPin: Address=c0000006693d4308 Handle=c00000066d3c9ec0 Mode=S Lock=c000000669500cd8 Context=9fffffffbf3f4058 User=c000000658b7acc0 Session=c000000658b7acc0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x718a7432
LibraryObjectPin: Address=c000000669673810 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006693cea90 Context=9fffffffbf3f5560 User=c0000006749a0380 Session=c0000006749a0380 Count=2 Mask=2011 Flags=[08] SavepointNum=0x67277fce
LibraryObjectPin: Address=c00000066dd075a8 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066cc5fde8 Context=9fffffffbf3f5560 User=c0000006749d8d90 Session=c0000006749d8d90 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6951278f
LibraryObjectPin: Address=c0000006691faaa8 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006695aa460 Context=9fffffffbf30e968 User=c000000674a4d160 Session=c000000674a4d160 Count=2 Mask=2011 Flags=[08] SavepointNum=0x4f07776e
LibraryObjectPin: Address=c000000670f88e28 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006714e1348 Context=9fffffffbf3f4ce0 User=c000000660a79c40 Session=c000000660a79c40 Count=2 Mask=2011 Flags=[08] SavepointNum=0x69110f1f
LibraryObjectPin: Address=c00000066c47df38 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066d4e5e18 Context=9fffffffbf3f5c78 User=c000000658b422b0 Session=c000000658b422b0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x76a2a921
LibraryObjectPin: Address=c0000006657a0700 Handle=c00000066d3c9ec0 Mode=S Lock=c000000665a20c80 Context=9fffffffbf3f5c78 User=c000000674af6f90 Session=c000000674af6f90 Count=2 Mask=2011 Flags=[08] SavepointNum=0x694604a1
LibraryObjectPin: Address=c000000669836080 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006699792d0 Context=9fffffffbf3f5738 User=c000000660b5f430 Session=c000000660b5f430 Count=2 Mask=2011 Flags=[08] SavepointNum=0x74f94aca
LibraryObjectPin: Address=c000000665704d38 Handle=c00000066d3c9ec0 Mode=S Lock=c000000665784710 Context=9fffffffbf30f278 User=c000000660b97e40 Session=c000000660b97e40 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6ed2b998
LibraryObjectPin: Address=c00000066c67d340 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066c887118 Context=9fffffffbf3f5c78 User=c000000674849770 Session=c000000674849770 Count=2 Mask=2011 Flags=[08] SavepointNum=0x7633a5fd
LibraryObjectPin: Address=c000000669b7b5b8 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006698eef10 Context=9fffffffbf3f5c78 User=c000000658902f00 Session=c000000658902f00 Count=2 Mask=2011 Flags=[08] SavepointNum=0x44946bc2
LibraryObjectPin: Address=c0000006657d80e0 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006659b8750 Context=9fffffffbf3f5c78 User=c00000065893b910 Session=c00000065893b910 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6456cbad
LibraryObjectPin: Address=c0000006657c5180 Handle=c00000066d3c9ec0 Mode=S Lock=c000000665519c28 Context=9fffffffbf3f5c78 User=c00000065c95c708 Session=c00000065c95c708 Count=2 Mask=2011 Flags=[08] SavepointNum=0x673d409d
LibraryObjectPin: Address=c00000066c8c3c08 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066c887970 Context=9fffffffbf3f5c78 User=c00000066095ba40 Session=c00000066095ba40 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6def4315
LibraryObjectPin: Address=c0000006714e06f0 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006714e08f0 Context=9fffffffbf3f5c78 User=c000000658a240b0 Session=c000000658a240b0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x446a428a
LibraryObjectPin: Address=c00000066d4e6570 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066d4e6670 Context=9fffffffbf3f5c78 User=c000000660a028c0 Session=c000000660a028c0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6b7c93f3
LibraryObjectPin: Address=c0000006709b9138 Handle=c00000066d3c9ec0 Mode=S Lock=c000000670950368 Context=9fffffffbf3f5c78 User=c000000658acdee0 Session=c000000658acdee0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x4732e580
LibraryObjectPin: Address=c0000006650dae98 Handle=c00000066d3c9ec0 Mode=S Lock=c000000665783eb8 Context=9fffffffbf3f5c78 User=c000000674abe580 Session=c000000674abe580 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6765a1cd
LibraryObjectPin: Address=c000000665a62048 Handle=c00000066d3c9ec0 Mode=S Lock=c000000665b44aa8 Context=9fffffffbf3f5c78 User=c000000660aeb060 Session=c000000660aeb060 Count=2 Mask=2011 Flags=[08] SavepointNum=0x7efb0ed4
LibraryObjectPin: Address=c00000066cdb0ac0 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066d4e55c0 Context=9fffffffbf3f5c78 User=c000000658bb6680 Session=c000000658bb6680 Count=2 Mask=2011 Flags=[08] SavepointNum=0x43b840af
LibraryObjectPin: Address=c000000671230360 Handle=c00000066d3c9ec0 Mode=S Lock=c00000067094fb10 Context=9fffffffbf3f5c78 User=c000000658bef090 Session=c000000658bef090 Count=2 Mask=2011 Flags=[08] SavepointNum=0x784ba771
LibraryObjectPin: Address=c00000066c451f20 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066c8868c0 Context=9fffffffbf3f5c78 User=c000000674ba6d20 Session=c000000674ba6d20 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6f5fb29b
LibraryObjectPin: Address=c00000066d87d020 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066d87da78 Context=9fffffffbf3f56f8 User=c0000006588ca4f0 Session=c0000006588ca4f0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6fe4a9a0
LibraryObjectPin: Address=c0000006692d30c8 Handle=c00000066d3c9ec0 Mode=S Lock=c000000669b15340 Context=9fffffffbf3f5c78 User=c0000006748bab90 Session=c0000006748bab90 Count=2 Mask=2011 Flags=[08] SavepointNum=0x426605cd
LibraryObjectPin: Address=c0000006692d2188 Handle=c00000066d3c9ec0 Mode=S Lock=c000000669c62550 Context=9fffffffbf3f5c78 User=c0000006589afce0 Session=c0000006589afce0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6d7dc5ce
LibraryObjectPin: Address=c000000665b53568 Handle=c00000066d3c9ec0 RequestMode=X User=c0000006609c9eb0 Session=c0000006609c9eb0 Count=0 Mask=0000 Flags=[00] SavepointNum=0xef
也可以直接看阻塞session
按照行号一个一个看,也能看出除了547自己以外,都是被547阻塞的。
[oracle@server2 tmp]$ grep "inst: 1, sid: 930" systemstate.txt -n
88195: inst: 1, sid: 930, ser: 427
97336: inst: 1, sid: 930, ser: 427
372971: inst: 1, sid: 930, ser: 427
374618: inst: 1, sid: 930, ser: 427
374622: inst: 1, sid: 930, ser: 427
376597: inst: 1, sid: 930, ser: 427
在虚机上重现
创建函数
create or replace function f1 return integer is
cnt int;
begin
select count(*) into cnt from t;
sys.dbms_lock.sleep(1000);
return cnt;
end f1;
/
执行过程中,启第二个session删掉表T,然后再执行。这时第二个session会尝试编译,于是在第一个session执行结束之前都会等待library cache pin
IN SPID SID EVENT SQL_ID BLKSESS
-- ------------- ---------- --------------------------------- ------------- ---------------
1 7068 16 library cache pin 97d19v4a3t67u 1 125
从下面结果可以看出持有共享pin的session非常多,因此无论杀掉顶端的谁,都会有另一个接替它。
而单杀547也没用,因为任何一个试图执行这个函数的session都会取代session 547,尝试编译函数。
[oracle@server2 tmp]$ grep -E "LibraryObjectPin.*Handle=c00000066d3c9ec0 " systemstate.txt
LibraryObjectPin: Address=c0000006693d4308 Handle=c00000066d3c9ec0 Mode=S Lock=c000000669500cd8 Context=9fffffffbf3f4058 User=c000000658b7acc0 Session=c000000658b7acc0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x718a7432
LibraryObjectPin: Address=c000000669673810 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006693cea90 Context=9fffffffbf3f5560 User=c0000006749a0380 Session=c0000006749a0380 Count=2 Mask=2011 Flags=[08] SavepointNum=0x67277fce
LibraryObjectPin: Address=c00000066dd075a8 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066cc5fde8 Context=9fffffffbf3f5560 User=c0000006749d8d90 Session=c0000006749d8d90 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6951278f
LibraryObjectPin: Address=c0000006691faaa8 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006695aa460 Context=9fffffffbf30e968 User=c000000674a4d160 Session=c000000674a4d160 Count=2 Mask=2011 Flags=[08] SavepointNum=0x4f07776e
LibraryObjectPin: Address=c000000670f88e28 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006714e1348 Context=9fffffffbf3f4ce0 User=c000000660a79c40 Session=c000000660a79c40 Count=2 Mask=2011 Flags=[08] SavepointNum=0x69110f1f
LibraryObjectPin: Address=c00000066c47df38 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066d4e5e18 Context=9fffffffbf3f5c78 User=c000000658b422b0 Session=c000000658b422b0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x76a2a921
LibraryObjectPin: Address=c0000006657a0700 Handle=c00000066d3c9ec0 Mode=S Lock=c000000665a20c80 Context=9fffffffbf3f5c78 User=c000000674af6f90 Session=c000000674af6f90 Count=2 Mask=2011 Flags=[08] SavepointNum=0x694604a1
LibraryObjectPin: Address=c000000669836080 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006699792d0 Context=9fffffffbf3f5738 User=c000000660b5f430 Session=c000000660b5f430 Count=2 Mask=2011 Flags=[08] SavepointNum=0x74f94aca
LibraryObjectPin: Address=c000000665704d38 Handle=c00000066d3c9ec0 Mode=S Lock=c000000665784710 Context=9fffffffbf30f278 User=c000000660b97e40 Session=c000000660b97e40 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6ed2b998
LibraryObjectPin: Address=c00000066c67d340 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066c887118 Context=9fffffffbf3f5c78 User=c000000674849770 Session=c000000674849770 Count=2 Mask=2011 Flags=[08] SavepointNum=0x7633a5fd
LibraryObjectPin: Address=c000000669b7b5b8 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006698eef10 Context=9fffffffbf3f5c78 User=c000000658902f00 Session=c000000658902f00 Count=2 Mask=2011 Flags=[08] SavepointNum=0x44946bc2
LibraryObjectPin: Address=c0000006657d80e0 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006659b8750 Context=9fffffffbf3f5c78 User=c00000065893b910 Session=c00000065893b910 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6456cbad
LibraryObjectPin: Address=c0000006657c5180 Handle=c00000066d3c9ec0 Mode=S Lock=c000000665519c28 Context=9fffffffbf3f5c78 User=c00000065c95c708 Session=c00000065c95c708 Count=2 Mask=2011 Flags=[08] SavepointNum=0x673d409d
LibraryObjectPin: Address=c00000066c8c3c08 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066c887970 Context=9fffffffbf3f5c78 User=c00000066095ba40 Session=c00000066095ba40 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6def4315
LibraryObjectPin: Address=c0000006714e06f0 Handle=c00000066d3c9ec0 Mode=S Lock=c0000006714e08f0 Context=9fffffffbf3f5c78 User=c000000658a240b0 Session=c000000658a240b0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x446a428a
LibraryObjectPin: Address=c00000066d4e6570 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066d4e6670 Context=9fffffffbf3f5c78 User=c000000660a028c0 Session=c000000660a028c0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6b7c93f3
LibraryObjectPin: Address=c0000006709b9138 Handle=c00000066d3c9ec0 Mode=S Lock=c000000670950368 Context=9fffffffbf3f5c78 User=c000000658acdee0 Session=c000000658acdee0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x4732e580
LibraryObjectPin: Address=c0000006650dae98 Handle=c00000066d3c9ec0 Mode=S Lock=c000000665783eb8 Context=9fffffffbf3f5c78 User=c000000674abe580 Session=c000000674abe580 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6765a1cd
LibraryObjectPin: Address=c000000665a62048 Handle=c00000066d3c9ec0 Mode=S Lock=c000000665b44aa8 Context=9fffffffbf3f5c78 User=c000000660aeb060 Session=c000000660aeb060 Count=2 Mask=2011 Flags=[08] SavepointNum=0x7efb0ed4
LibraryObjectPin: Address=c00000066cdb0ac0 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066d4e55c0 Context=9fffffffbf3f5c78 User=c000000658bb6680 Session=c000000658bb6680 Count=2 Mask=2011 Flags=[08] SavepointNum=0x43b840af
LibraryObjectPin: Address=c000000671230360 Handle=c00000066d3c9ec0 Mode=S Lock=c00000067094fb10 Context=9fffffffbf3f5c78 User=c000000658bef090 Session=c000000658bef090 Count=2 Mask=2011 Flags=[08] SavepointNum=0x784ba771
LibraryObjectPin: Address=c00000066c451f20 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066c8868c0 Context=9fffffffbf3f5c78 User=c000000674ba6d20 Session=c000000674ba6d20 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6f5fb29b
LibraryObjectPin: Address=c00000066d87d020 Handle=c00000066d3c9ec0 Mode=S Lock=c00000066d87da78 Context=9fffffffbf3f56f8 User=c0000006588ca4f0 Session=c0000006588ca4f0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6fe4a9a0
LibraryObjectPin: Address=c0000006692d30c8 Handle=c00000066d3c9ec0 Mode=S Lock=c000000669b15340 Context=9fffffffbf3f5c78 User=c0000006748bab90 Session=c0000006748bab90 Count=2 Mask=2011 Flags=[08] SavepointNum=0x426605cd
LibraryObjectPin: Address=c0000006692d2188 Handle=c00000066d3c9ec0 Mode=S Lock=c000000669c62550 Context=9fffffffbf3f5c78 User=c0000006589afce0 Session=c0000006589afce0 Count=2 Mask=2011 Flags=[08] SavepointNum=0x6d7dc5ce
LibraryObjectPin: Address=c000000665b53568 Handle=c00000066d3c9ec0 RequestMode=X User=c0000006609c9eb0 Session=c0000006609c9eb0 Count=0 Mask=0000 Flags=[00] SavepointNum=0xef
也可以直接看阻塞session
按照行号一个一个看,也能看出除了547自己以外,都是被547阻塞的。
[oracle@server2 tmp]$ grep "inst: 1, sid: 930" systemstate.txt -n
88195: inst: 1, sid: 930, ser: 427
97336: inst: 1, sid: 930, ser: 427
372971: inst: 1, sid: 930, ser: 427
374618: inst: 1, sid: 930, ser: 427
374622: inst: 1, sid: 930, ser: 427
376597: inst: 1, sid: 930, ser: 427
在虚机上重现
创建函数
create or replace function f1 return integer is
cnt int;
begin
select count(*) into cnt from t;
sys.dbms_lock.sleep(1000);
return cnt;
end f1;
/
执行过程中,启第二个session删掉表T,然后再执行。这时第二个session会尝试编译,于是在第一个session执行结束之前都会等待library cache pin
IN SPID SID EVENT SQL_ID BLKSESS
-- ------------- ---------- --------------------------------- ------------- ---------------
1 7068 16 library cache pin 97d19v4a3t67u 1 125
来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/26239116/viewspace-1425743/,如需转载,请注明出处,否则将追究法律责任。
转载于:http://blog.itpub.net/26239116/viewspace-1425743/