彻底搞清楚library cache lock的成因和解决方法(二)
上一个例子中我们主要借助于X$KGLLK基表和event systemstate解决问题,那么如果你不了解X$KGLLK基表,或者忘记了如何使用它,那也不要紧张,这里再介绍一种常规的方法。
从system state 的转储信息中,我们已经注意到PROCESS 28当前正在等待'library cache lock'。
'handle address'表示的就是正持有 PROCESS 28 进程所等待的library cache中的地址。
现在我们继续在跟踪文件中查找包含 'handle=c000000122e2a6d8' 字符串的ORACLE PROCESS,也就是查找blocking session的信息,发现信息如下:
PROCESS 26: ----------------阻塞其他会话的Oracle进程,这里PROCESS 26对应了V$PROCESS中的PID的值
----------------------------------------
SO: c000000109c831e0, type: 2, owner: 0000000000000000, flag: INIT/-/-/0x00
(process) Oracle pid=26, calls cur/top: c00000010b2774d0/c00000010b2774d0, flag: (0) -
int error: 0, call error: 0, sess error: 0, txn error 0
(post info) last post received: 17 24 6
last post received-location: ksusig
last process to post me: c000000109c840f8 25 0
last post sent: 751404 0 15
last post sent-location: ksasnd
last process posted by me: c000000109c836e8 1 6
(latch info) wait_event=0 bits=0
Process Group: DEFAULT, pseudo proc: c000000109eefda0
O/S info: user: ora9i, term: UNKNOWN, ospid: 20552
OSD pid info: Unix process pid: 20552, image: oracle@cs_dc02 (TNS V1-V3)
----------------------------------------
SO: c0000001180b9510, type: 8, owner: c000000109c831e0, flag: INIT/-/-/0x00
(FOB) flags=2 fib ptr=162e1b48 incno=0 pending i/o cnt=0
----------------------------------------
SO: c0000001180b9458, type: 8, owner: c000000109c831e0, flag: INIT/-/-/0x00
(FOB) flags=2 fib ptr=162deb18 incno=0 pending i/o cnt=0
----------------------------------------
SO: c0000001180b8230, type: 8, owner: c000000109c831e0, flag: INIT/-/-/0x00
(FOB) flags=2 fib ptr=162de848 incno=0 pending i/o cnt=0
----------------------------------------
SO: c0000001180b7b00, type: 8, owner: c000000109c831e0, flag: INIT/-/-/0x00
(FOB) flags=2 fib ptr=162de578 incno=0 pending i/o cnt=0
----------------------------------------
SO: c000000108c99e28, type: 4, owner: c000000109c831e0, flag: INIT/-/-/0x00
c000000108c99e28 对应的就是V$SESSION 中的SADDR的值,通过这个信息就可以找到blocking session的SID等信息
(session) trans: c0000001169403c0, creator: c000000109c831e0, flag: (100041) USR/- BSY/-/-/-/-/-
DID: 0002-001A-0000007D, short-term DID: 0000-0000-00000000
txn branch: c00000011b825e18
oct: 0, prv: 0, sql: 800003fb0005f7b0, psql: c00000011fbe3f98, user: 50/PUBUSER
O/S info: user: report16, term: , ospid: 20550, machine: cs_dc02
program: sqlplus@cs_dc02 (TNS V1-V3)
application name: SQL*Plus, hash value=3669949024
waiting for 'SQL*Net message from dblink' blocking sess=0x0 seq=3319 wait_time=0
driver id=28444553, #bytes=1, =0
-------------------
这里,
#bytes 表示个server process通过database link发送给另一个server process的字节数(bytes)
driver id 是一个10进制数,我们需要把它转化为16进制数,然后就会发现它对应于我们通过event 10046中的相应的信息:
*** 2005-01-10 11:44:48.200
WAIT #1: nam='SQL*Net message from dblink' ela= 104397696 p1=675562835 p2=1 p3=0
WAIT #1: nam='SQL*Net message to dblink' ela= 4 p1=675562835 p2=1 p3=0
SQL> select to_char(675562835,'XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX') from dual;
TO_CHAR(675562835,'XXXXXXXXXXXXXX
---------------------------------
28444553
SQL>
temporary object counter: 0
----------------------------------------
SO: c00000011a4496b0, type: 51, owner: c000000108c99e28, flag: INIT/-/-/0x00
LIBRARY OBJECT LOCK: lock=c00000011a4496b0 handle=c00000012029f968 mode=N
call pin=0000000000000000 session pin=c00000011a44ad70
htl=c00000011a449720[c00000011a4baa78,c00000011a4baa78] htb=c00000011a4baa78
user=c000000108c99e28 session=c000000108c99e28 count=1 flags=[00] savepoint=173
LIBRARY OBJECT HANDLE: handle=c00000012029f968
namespace=CRSR flags=RON/KGHP/PN0/[10010000]
kkkk-dddd-llll=0000-0041-0041 lock=N pin=0 latch#=3
lwt=c00000012029f998[c00000012029f998,c00000012029f998] ltm=c00000012029f9a8[c00000012029f9a8,c00000012029f9a8]
pwt=c00000012029f9c8[c00000012029f9c8,c00000012029f9c8] ptm=c00000012029fa58[c00000012029fa58,c00000012029fa58]
ref=c00000012029f978[c0000001202a0068, c0000001202a0068] lnd=c00000012029fa70[c00000012029fa70,c00000012029fa70]
LIBRARY OBJECT: object=c00000012029f5c8
type=CRSR flags=EXS[0001] pflags= [00] status=VALD load=0
DEPENDENCIES: count=1 size=16
AUTHORIZATIONS: count=1 size=16 minimum entrysize=16
ACCESSES: count=1 size=16
DATA BLOCKS:
data# heap pointer status pins change
----- -------- -------- ------ ---- ------
0 c00000012029f8a8 c00000012029f288 I/P/A 0 NONE
6 c00000012029f6e8 c00000012029e7c8 I/-/A 0 NONE
----------------------------------------
。。。 。。。
----------------------------------------
SO: c00000011a44a150, type: 51, owner: c0000001169403c0, flag: INIT/-/-/0x00
////////////// X$KGLLK.KGLLKADR 对应于SO(SO: c00000011a44a150 //////////////
////////////// X$KGLLK.KGLLKUSE 和 x$kgllk.KGLLKSES 对应于owner的值(owner: c0000001169403c0)
LIBRARY OBJECT LOCK: lock=c00000011a44a150 handle=c000000122e2a6d8 mode=X
////////////// X$KGLLK.KGLLKADR 对应于SO 和 lock的值(SO: c00000011a44a150,lock=c00000011a44a150) //////////////
////////////// X$KGLLK.KGLLKHDL 对应于handle的值(handle=c000000122e2a6d8) ////////////////
call pin=0000000000000000 session pin=0000000000000000
////////////// X$KGLLK.KGLLKPNS 对应于session pin的值(session pin=0000000000000000) //////////////
htl=c00000011a44a1c0[c00000011a4bb328,c00000011a4bb328] htb=c00000011a4bb328
user=c000000108c99e28 session=c000000108c99e28 count=1 flags=[00] savepoint=179
user和session的值分别对应着x$kgllk.KGLLKUSE 和 x$kgllk.KGLLKSES,也对应于V$SESSION中阻塞其他会话的SADDR
////////////// X$KGLLK.KGLLKSPN对应于savepoint的值(savepoint=179) //////////////
LIBRARY OBJECT HANDLE: handle=c000000122e2a6d8
name=PUBUSER.CSNOZ629926699966
hash=eddf82b5 timestamp=01-08-2005 13:00:18 previous=NULL
namespace=TABL/PRCD/TYPE flags=KGHP/TIM/PTM/SML/[02000000]
kkkk-dddd-llll=0000-0709-0001 lock=X pin=X latch#=3
lwt=c000000122e2a708[c00000011a449e40,c00000011a449e40] ltm=c000000122e2a718[c000000122e2a718,c000000122e2a718]
pwt=c000000122e2a738[c000000122e2a738,c000000122e2a738] ptm=c000000122e2a7c8[c000000122e2a7c8,c000000122e2a7c8]
ref=c000000122e2a6e8[c000000122e2a6e8, c000000122e2a6e8] lnd=c000000122e2a7e0[c000000122e2a7e0,c000000122e2a7e0]
LOCK INSTANCE LOCK: id=LBcafc8485d0949f81
PIN INSTANCE LOCK: id=NBcafc8485d0949f81 mode=X release=F flags=[00]
LIBRARY OBJECT: object=c000000122e12f70
type=TABL flags=EXS/LOC/CRT[0015] pflags= [00] status=VALD load=0
DATA BLOCKS:
data# heap pointer status pins change
----- -------- -------- ------ ---- ------
0 c000000122e2a618 c000000122e13118 I/P/A 0 INSERT
3 c000000122e13178 0 -/P/- 1 NONE
8 c000000122e12c30 c000000122febdb8 I/P/A 1 UPDATE
9 c000000122e13090 0 -/P/- 1 NONE
10 c000000122e12ce0 c000000122acbc70 I/P/A 1 UPDATE
----------------------------------------
。。。 。。。
根据上述两个ORACLE进程号(ORACLE PID),我们可以找到他们的会话信息和操作系统进程信息
SQL> select spid,pid,addr from v$process where pid in (26,28);
SPID PID ADDR
------------ ---------- ----------------
20552 26 C000000109C831E0 ----------- 阻塞其他会话的Oracle进程
22580 28 C000000109C83BF0 ----------- 被阻塞的Oracle进程
SQL>
我们来进一步证实一下上述信息:
SQL>col username for a20
SQL> col osuser for a20
SQL> col machine for a20
SQL> l
1 select sid,serial#,username,osuser,machine,to_char(logon_time,'yyyy/mm/dd hh24:mi:ss') LogonTime
2* from v$session where paddr in ( select addr from v$process where spid ='&spid')
SQL> /
Enter value for spid: 20552 ----------- 阻塞其他会话的Oracle进程
old 2: from v$session where paddr in ( select addr from v$process where spid ='&spid')
new 2: from v$session where paddr in ( select addr from v$process where spid ='20552')
SID SERIAL# USERNAME OSUSER MACHINE LOGONTIME
---------- ---------- -------------------- -------------------- -------------------- -------------------
37 2707 PUBUSER report16 cs_dc02 2005/01/08 13:00:17
SQL> /
Enter value for spid: 22580 ----------- 被阻塞的Oracle进程
old 2: from v$session where paddr in ( select addr from v$process where spid ='&spid')
new 2: from v$session where paddr in ( select addr from v$process where spid ='22580')
SID SERIAL# USERNAME OSUSER MACHINE LOGONTIME
---------- ---------- -------------------- -------------------- -------------------- -------------------
30 24167 PUBUSER ora9i cs_dc02 2005/01/10 10:20:31
SQL> select sid,saddr,paddr,username,status,OSUSER from v$session where sid in (37,30);
SID SADDR PADDR USERNAME STATUS OSUSER
---------- ---------------- ---------------- -------------------- -------- --------------------
30 C000000109F02C68 C000000109C83BF0 PUBUSER ACTIVE ora9i
37 C000000108C99E28 C000000109C831E0 PUBUSER ACTIVE report16
SQL>
现在,问题已经水落石出了,解决方法和方法1中的一样(在操作系统中直接kill掉相应的操作系统进程)。
当然,处于研究的目的,我们可以进一步了解一下上述两个会话(SID 30 和 SID 37)所有已经持有锁的相关信息:
SQL> set linesize 150
SQL> set pages 10000
SQL> select * from v$lock where sid in (37,30);
ADDR KADDR SID TY ID1 ID2 LMODE REQUEST CTIME BLOCK
---------------- ---------------- ---------- -- ---------- ---------- ---------- ---------- ---------- ----------
C0000001169403C0 C000000116940538 37 TX 917507 26579 6 0 180478 2
C00000011676DAE0 C00000011676DB08 37 TM 18 0 3 0 180478 2
C00000010B30C4E8 C00000010B30C508 37 XR 4 0 2 0 180369 2
C00000010B30C460 C00000010B30C480 37 DX 21 0 1 0 68 0
SQL>
不难看出,会话37阻塞了其他会话
现在,我们再进一步看看会话37当前在哪些对象上加了锁:
SQL> select object_name,object_id from dba_objects where object_id in ('917507','18','4','21') order by object_id;
OBJECT_NAME OBJECT_ID
------------------------------ ----------
TAB$ 4
OBJ$ 18
COL$ 21
SQL> /
OBJECT_NAME OBJECT_ID
------------------------------ ----------
TAB$ 4
OBJ$ 18
COL$ 21
SQL>
接下来,再着重看看SID 为37的会话在library cache中请求和持有对象锁的详细信息:
SQL> col KGLNAOBJ for a30
SQL> col USER_NAME for a10
SQL> l
1 select INST_ID,USER_NAME,KGLNAOBJ,KGLLKSNM,KGLLKUSE,KGLLKSES,KGLLKMOD,KGLLKREQ
2* from x$kgllk where KGLLKSNM = 37
SQL> /
INST_ID USER_NAME KGLNAOBJ KGLLKSNM KGLLKUSE KGLLKSES KGLLKMOD KGLLKREQ
---------- ---------- ------------------------------ ---------- ---------------- ---------------- ---------- ----------
2 PUBUSER DBMS_OUTPUT 37 C000000108C99E28 C000000108C99E28 1 0
2 PUBUSER DBMS_OUTPUT 37 C000000108C99E28 C000000108C99E28 1 0
2 PUBUSER DBMS_STANDARD 37 C000000108C99E28 C000000108C99E28 1 0
2 PUBUSER PUBUSER 37 C000000108C99E28 C000000108C99E28 1 0
2 PUBUSER SELECT MINOR_VERSION FROM SY 37 C000000108C99E28 C000000108C99E28 1 0
S.CDC_SYSTEM$
2 PUBUSER SELECT MINOR_VERSION FROM SY 37 C000000108C99E28 C000000108C99E28 1 0
S.CDC_SYSTEM$
2 PUBUSER DBMS_CDC_PUBLISH 37 C000000108C99E28 C000000108C99E28 1 0
2 PUBUSER DBMS_CDC_PUBLISH 37 C000000108C99E28 C000000108C99E28 1 0
2 PUBUSER CSNOZ629926699966 37 C000000108C99E28 C000000108C99E28 3 0
2 PUBUSER DBMS_APPLICATION_INFO 37 C000000108C99E28 C000000108C99E28 1 0
2 PUBUSER DBMS_APPLICATION_INFO 37 C000000108C99E28 C000000108C99E28 1 0
2 PUBUSER DATABASE 37 C000000108C99E28 C000000108C99E28 1 0
12 rows selected.
SQL>
再看看SID为30的会话在library cache中请求和持有对象锁的详细信息:
SQL> select INST_ID,USER_NAME,KGLNAOBJ,KGLLKSNM,KGLLKUSE,KGLLKSES,KGLLKMOD,KGLLKREQ
2 from x$kgllk where KGLLKSNM = 30
3 /
INST_ID USER_NAME KGLNAOBJ KGLLKSNM KGLLKUSE KGLLKSES KGLLKMOD KGLLKREQ
---------- ---------- ------------------------------ ---------- ---------------- ---------------- ---------- ----------
2 PUBUSER PUBUSER 30 C000000109F02C68 C000000109F02C68 1 0
2 PUBUSER CSNOZ629926699966 30 C000000109F02C68 C000000109F02C68 0 2
2 PUBUSER DBMS_APPLICATION_INFO 30 C000000109F02C68 C000000109F02C68 1 0
2 PUBUSER DBMS_APPLICATION_INFO 30 C000000109F02C68 C000000109F02C68 1 0
2 PUBUSER DATABASE 30 C000000109F02C68 C000000109F02C68 1 0
SQL>
KGLNAOBJ 列包含了在librarky cache中的对象上执行命令的语句的前80个字符,其实从这里我们也可以大大缩小范围了
KGLLKSES 对应于V$SESSION 中的 SADDR列的值
KGLLKSNM 对应于V$SESSION 中的SID(Session ID)
KGLLKHDL 的值与方法1中跟踪文件中的'handle address'的值对应
KGLLKPNS 的值对应于方法1中跟踪文件中的'Ssession pin'的值
SQL> set linesize 2000
SQL> l
1 select INST_ID,USER_NAME,KGLNAOBJ,KGLLKSNM,KGLLKUSE,KGLLKSES,KGLLKMOD,KGLLKREQ,KGLLKPNS,KGLLKHDL
2* from x$kgllk where KGLLKSNM in (30,37) order by KGLLKSNM,KGLNAOBJ
SQL> /
INST_ID USER_NAME KGLNAOBJ KGLLKSNM KGLLKUSE KGLLKSES KGLLKMOD KGLLKREQ KGLLKPNS KGLLKHDL
---------- ------------------------------ ------------------------------------------------------------ ---------- ---------------- ---------------- ---------- ---------- ---------------- ----------------
2 PUBUSER DATABASE 30 C000000109F02C68 C000000109F02C68 1 0 00 C000000119F8EC58
2 PUBUSER DBMS_APPLICATION_INFO 30 C000000109F02C68 C000000109F02C68 1 0 00 C00000011CCDDA48
2 PUBUSER DBMS_APPLICATION_INFO 30 C000000109F02C68 C000000109F02C68 1 0 00 C00000011CCD81B8
2 PUBUSER PUBUSER 30 C000000109F02C68 C000000109F02C68 1 0 00 C00000011CBFDAA8
2 PUBUSER CSNOZ629926699966 30 C000000109F02C68 C000000109F02C68 0 2 00 C000000122E2A6D8
2 PUBUSER DATABASE 37 C000000108C99E28 C000000108C99E28 1 0 00 C000000119F8EC58
2 PUBUSER DBMS_APPLICATION_INFO 37 C000000108C99E28 C000000108C99E28 1 0 00 C00000011CCDDA48
2 PUBUSER DBMS_APPLICATION_INFO 37 C000000108C99E28 C000000108C99E28 1 0 00 C00000011CCD81B8
2 PUBUSER DBMS_CDC_PUBLISH 37 C000000108C99E28 C000000108C99E28 1 0 00 C00000011FEA4918
2 PUBUSER DBMS_CDC_PUBLISH 37 C000000108C99E28 C000000108C99E28 1 0 00 C0000001202A4988
2 PUBUSER DBMS_OUTPUT 37 C000000108C99E28 C000000108C99E28 1 0 00 C00000011CCB48B0
2 PUBUSER DBMS_OUTPUT 37 C000000108C99E28 C000000108C99E28 1 0 00 C00000011FFF5098
2 PUBUSER DBMS_STANDARD 37 C000000108C99E28 C000000108C99E28 1 0 00 C00000011CCF0ED8
2 PUBUSER PUBUSER 37 C000000108C99E28 C000000108C99E28 1 0 00 C00000011CBFDAA8
2 PUBUSER SELECT MINOR_VERSION FROM SYS.CDC_SYSTEM$ 37 C000000108C99E28 C000000108C99E28 1 0 C00000011A44AD70 C00000012029F968
2 PUBUSER SELECT MINOR_VERSION FROM SYS.CDC_SYSTEM$ 37 C000000108C99E28 C000000108C99E28 1 0 00 C0000001202A0228
2 PUBUSER CSNOZ629926699966 37 C000000108C99E28 C000000108C99E28 3 0 00 C000000122E2A6D8
17 rows selected.
SQL>