徹底搞清楚library cache lock的成因和解決方法(4)

jss001發表於2009-02-18

現在我們來dump 系統狀態(systemstate),看看更詳細的資訊。

首先簡單的介紹一下 event systemstate。很多人把 systemstate 事件理解為dump發生的那一刻的系統內所有程式的資訊,這是個錯誤的概念,事實上,
轉儲 system state 產生的跟蹤檔案是從dump那一刻開始到dump任務完成之間一段事件內的系統內所有程式的資訊。

dump systemstate產生的跟蹤檔案包含了系統中所有程式的程式狀態等資訊。每個程式對應跟蹤檔案中的一段內容,反映該程式的狀態資訊,包括程式資訊, 會話資訊,enqueues資訊(主要是lock的資訊),緩衝區的資訊和該程式在SGA區中持有的(held)物件的狀態等資訊。

那麼通常在什麼情況下使用systemstate比較合適呢? Oracle推薦的使用systemstate事件的幾種情況是:

  • 資料庫 hang 住了
  • 資料庫很慢
  • 程式正在hang
  • 資料庫出現某些錯誤
  • 資源爭用

dump systemstate的語法為: ALTER SESSION SET EVENTS 'immediate trace name systemstate level 10';

也可以使用ORADEBUG實現這個功能
ORADEBUG DUMP SYSTEMSTATE level 10

如果希望在資料庫發生某種錯誤時除非systemstate事件,可以在引數檔案(spfile或者pfile)中設定event引數,
例如,當系統發生死鎖(出現ORA-00060錯誤)時dump systemstate:
event = "60 trace name systemstate level 10"

言歸正傳,我們dump系統狀態:SQL> ALTER SESSION SET EVENTS 'IMMEDIATE TRACE NAME SYSTEMSTATE LEVEL 8';

Session altered.

SQL> host
>cd /ora9i/app/oracle/admin/csmisc/udump
> ll -ctl
-rw-r----- 1 ora9i dba 1070863 Jan 10 13:02 csmisc2_ora_22580.trc
-rw-r----- 1 ora9i dba 1345368 Jan 10 13:01 csmisc2_ora_22568.trc-rwxrwxrwx 1 ora9i dba 44114 Jan 10 12:52 ass1015.awk
-rw-r----- 1 ora9i dba 407133 Jan 7 15:10 csmisc2_ora_2708.trc
-rw-r----- 1 ora9i dba 640 Jan 7 14:48 csmisc2_ora_835.trc
-rw-r----- 1 ora9i dba 1590 Dec 30 22:50 csmisc2_ora_16244.trc
-rw-r----- 1 ora9i dba 1308403 Dec 30 22:44 csmisc2_ora_16033.trc
-rw-r----- 1 ora9i dba 616 Dec 28 14:16 csmisc2_ora_2176.trc
-rw-r----- 1 ora9i dba 644 Dec 8 18:22 csmisc2_ora_21083.trc
>
> mailx -s "22568" < csmisc2_ora_22568.trc

這個跟蹤檔案很大(因為它包含了所有程式的資訊),那麼我們從哪裡開始看起呢?

首先,透過在跟蹤檔案中查詢字串"waiting for 'library cache lock'",我們找到了被阻塞程式的資訊:

PROCESS 28: ----------------被阻塞的Oracle程式,這裡PROCESS 28對應了V$PROCESS中的PID的值,
也就是說我們可以根據這一資訊在V$PROCESS和V$SESSION找到被阻塞的會話的資訊
----------------------------------------
SO: c000000109c83bf0, type: 2, owner: 0000000000000000, flag: INIT/-/-/0x00
(process) Oracle pid=28, calls cur/top: c00000010b277890/c00000010b277890, 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: 0 0 15
last post sent-location: ksasnd
last process posted by me: c000000109c7ff90 1 6
(latch info) wait_event=0 bits=0
Process Group: DEFAULT, pseudo proc: c000000109eefda0
O/S info: user: ora9i, term: pts/th, ospid: 22580 ----------------該程式的作業系統程式號,對應於V$PROCESS中的SPID
OSD pid info: Unix process pid: 22580
, image: (TNS V1-V3)
----------------------------------------
SO: c000000109f02c68, type: 4, owner: c000000109c83bf0, flag: INIT/-/-/0x00
(session) trans: 0000000000000000, creator: c000000109c83bf0, flag: (100041) USR/- BSY/-/-/-/-/-
DID: 0002-001C-00000192, short-term DID: 0000-0000-00000000
txn branch: 0000000000000000
oct: 0, prv: 0, sql: c00000011f8ea068, psql: c00000011f8ea068, user: 50/PUBUSER
O/S info: user: ora9i, term: , ospid: 22536, machine: cs_dc02
program:
(TNS V1-V3)
application name: SQL*Plus, hash
value=3669949024
waiting for 'library cache lock' blocking sess=0x0 seq=18589 wait_time=0
handle address=c000000122e2a6d8, lock address=c00000011a449e20, 100*mode+namespace=515

。。。 。。。

SO: c00000010b277890, type: 3, owner: c000000109c83bf0, flag: INIT/-/-/0x00
(call) sess: cur c000000109f02c68, rec 0, usr c000000109f02c68; depth: 0
----------------------------------------
SO: c00000011a449e20, type: 51, owner: c00000010b277890, flag: INIT/-/-/0x00
LIBRARY OBJECT LOCK: lock=c00000011a449e20 handle=c000000122e2a6d8 request=S
call pin=0000000000000000 session pin=0000000000000000
htl=c00000011a449e90[c00000011a4bc350,c00000011a4bc350] htb=c00000011a4bc350
user=c000000109f02c68 session=c000000109f02c68 count=0 flags=[00] savepoint=463
the rest of the object was already dumped

。。。 。。。

請注意下面的資訊: waiting for 'library cache lock' blocking sess=0x0 seq=18589 wait_time=0
handle address=c000000122e2a6d8, lock address=c00000011a449e20, 100*mode+namespace=515

這段資訊告訴我們ORACLE PID為 28的程式(PROCESS 28),正在等待'library cache lock' ,透過‘handle address=c000000122e2a6d8’我們可以找到阻塞它的會話的ORACLE PID資訊。

還要注意這段資訊: LIBRARY OBJECT LOCK: lock=c00000011a449e20 handle=c000000122e2a6d8 request=S
call pin=0000000000000000 session pin=0000000000000000
htl=c00000011a449e90[c00000011a4bc350,c00000011a4bc350] htb=c00000011a4bc350
user=c000000109f02c68 session=c000000109f02c68 count=0 flags=[00] savepoint=463

這裡就是阻塞PROCESS 28程式的會話的資訊。

簡單的記住這個依據的要點是:

waiting session的'handle address'的值對應於blocking session的'handle'的值。


回過頭來,看看這個值,它應於上面我們在V$SESSION_WAIT中看到的P1和P2的值:
SQL> select to_number('C000000122E2A6D8','XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX') from dual;

TO_NUMBER('C000000122E2A6D8','XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX')
----------------------------------------------------------------
1.3835E+19

SQL>

[@more@]

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/18921899/viewspace-1017540/,如需轉載,請註明出處,否則將追究法律責任。

相關文章