1.简介
本文通过例子简要介绍了如何利用Oracle的跟踪以及内部数据字典表诊断某些挂起的会话。
--测试脚本
conn test/test
create orreplace procedure sp_test
as
begin
dbms_lock.sleep(seconds=>600);
end;
/
假定以下的场景:
Client A以test用户登陆到数据库中执行过程sp_test
sql>execsp_test;
几秒后Client B以test用户登陆到数据库中执行批量complie存储过程的操作,在执行
sql>alterprocedure sp_test compile;
的时候发现进程挂起,下面示例如何诊断挂起的会话。
2.通过SYSTEMSTATE跟踪
设置跟踪:
sql>conntest/test
sql>ALTERSESSION SET EVENTS 'IMMEDIATE TRACE NAME SYSTEMSTATE LEVEL 8';
获取跟踪文件为:_ora_676046.trc
由于分析跟踪文件需要知道会话的pid,通过以下查询获取:
sql> columnsql_text format a60
sql> selectt1.sid,t1.status,t2.sql_text
2fromv$session t1,v$sqlarea t2
3where t1.sql_hash_value = t2.hash_value
4andt1.username = 'TEST'a
5andsql_text like '%compile%'
6/
SID STATUSSQL_TEXT
------- --------------------------------------------------------------------
66 INACTIVE alter procedure sp_test compile
获取pid:
sql> SELECTPID FROM V$PROCESS
2WHERE ADDR =
3(SELECT PADDR FROM V$SESSION WHERE SID=&sid)
4/
输入sid的值:66
原值3: (SELECT PADDR FROMV$SESSION WHERE SID=&sid)
新值3: (SELECT PADDR FROMV$SESSION WHERE SID=66)
PID
----------
58
在跟踪文件中查找process 58
PROCESS 58:
----------------------------------------
SO: 70000006f2a2140, type: 2, owner: 0, flag:INIT/-/-/0x00
(process) Oracle pid=58, calls cur/top:700000071023710/700000071023710, flag: (0) -
int error: 0, call error: 0, sesserror: 0, txn error 0
(post info) last post received: 0 0 4
last post received-location:kslpsr
last process to post me:70000006f291340 1 6
last post sent: 0 0 16
last post sent-location: ksasnd
last process posted by me:70000006f291340 1 6
(latch info) wait_event=0 bits=0
Process Group: DEFAULT, pseudo proc:70000006f2beda0
O/S info: user: oracle, term: UNKNOWN,ospid: 2089002
OSD pid info: Unix process pid: 2089002,image: oracle@ecx (TNS V1-V3)
----------------------------------------
SO: 70000006fee0798, type: 8, owner:70000006f2a2140, flag: INIT/-/-/0x00
(FOB) flags=2 fib ptr=6ffaa408 incno=0pending i/o cnt=0
----------------------------------------
SO: 70000006fee0628, type: 8, owner:70000006f2a2140, flag: INIT/-/-/0x00
(FOB) flags=2 fib ptr=6ffa0e78 incno=1pending i/o cnt=0
----------------------------------------
SO: 70000006f2efae0, type: 4, owner:70000006f2a2140, flag: INIT/-/-/0x00
(session) trans: 70000007023b2f8, creator:70000006f2a2140, flag: (100041) USR/- BSY/-/-/-/-/-
DID: 0001-003A-0000153E,short-term DID: 0000-0000-00000000
txn branch: 0
oct: 0, prv: 0, sql:7000000688721e0, psql: 70000007d7c38e8, user: 68/TEST
O/S info: user: hxd, term: HEXIAODONG,ospid: 2144:1804, machine: FORESEE\HEXIAODONG
program: sqlplus.exe
application name: SQL*Plus, hashvalue=3669949024
waiting for'library cache pin' blocking sess=0x0 seq=96 wait_time=0
handleaddress=7000000689304c0, pin address=700000074021108,100*mode+namespace=12d
注意‘waiting for 'library cache pin' blocking’部分,表明该Session正在等待,然后我可以通过‘handle address=7000000689304c0’获取blocking进程。在跟踪文件中查找7000000689304c0可以发现:
PROCESS 63:
----------------------------------------
............... .............................. ...............
SO: 70000007400fb18, type: 51, owner:70000006f2fe340, flag: INIT/-/-/0x00
LIBRARY OBJECT LOCK: lock=70000007400fb18handle=7000000689304c0 mode=N
call pin=70000007d35bca0 session pin=0
htl=70000007400fb88[70000007300a620,70000007300a620]htb=70000007300a620
user=70000006f2fe340session=70000006f2fe340 count=1 flags=PNC/[04] savepoint=102
the rest of the object was already dumped
----------------------------------------
............... ............... ..............................
----------------------------------------
SO: 70000006f2de840, type: 4, owner:700000072019cc0, flag: INIT/-/-/0x00
(session) trans: 0, creator: 0, flag: (2)-/REC -/-/-/-/-/-
DID: 0000-0000-00000000,short-term DID: 0000-0000-00000000
txn branch: 0
oct: 0, prv: 0, sql:700000072d96c58, psql: 700000072d96c58, user: 0/SYS
temporary object counter: 0
----------------------------------------
SO:7000000719f1080, type: 52, owner: 700000072019cc0, flag: INIT/-/-/0x00
LIBRARY OBJECT PIN: pin=7000000719f1080handle=700000072e28340 mode=S lock=70000007110e968
user=70000006f2fe340session=70000006f2fe340 count=2 mask=0011 savepoint=102 flags=[00]
----------------------------------------
SO: 70000007d35bca0, type: 52, owner:700000072019cc0, flag: INIT/-/-/0x00
LIBRARY OBJECT PIN: pin=70000007d35bca0handle=7000000689304c0 mode=S lock=70000007400fb18
user=70000006f2fe340 session=70000006f2fe340 count=3 mask=0011savepoint=102 flags=[00]
可以看到该进程锁定了‘某些’资源。通过以下查询获得相应的Session正在执行的sql语句:
sql> columnsql_text format a60
sql> selectt1.sid,t1.status,t2.sql_text
2fromv$session t1,v$sqlarea t2,v$process t3
3where t1.sql_hash_value = t2.hash_value
4andt1.paddr = t3.addr
5andt3.pid = &pid
6/
输入pid的值:63
原值5: and t3.pid = &pid
新值5: and t3.pid = 63
SID STATUSSQL_TEXT
------------------ ---------------------------------------
88 ACTIVEBEGIN sp_test; END;
该Session正在执行过程sp_test,从而阻塞了其他Session编译该过程。
3.通过HANGANALYZE跟踪
HANGANALYZE跟踪给出了当前系统一个宏观的视图。
--以sysdba登陆执行
sql> showuser
USER为"SYS"
sql> oradebughanganalyze 3
Hang Analysis in/data/app/oracle/admin/query/udump/query_ora_2236466.trc
sql>
--以下为生成的跟踪文件
/data/app/oracle/admin/query/udump/query_ora_1613868.trc
Oracle9iEnterprise Edition Release 9.2.0.5.0 - 64bit Production
With thePartitioning, OLAP and Oracle Data Mining options
JServer Release9.2.0.5.0 - Production
ORACLE_HOME =/data/app/oracle/product/9.2.0
System name:AIX
Node name:ecx
Release:2
Version:5
Machine:00580DAD4C00
Instance name:query
Redo threadmounted by this instance: 1
Oracle processnumber: 67
Unix processpid: 1613868, image: oracle@ecx (TNS V1-V3)
*** SESSIONID:(27.60605) 2004-12-14 13:58:56.861
*** 2004-12-1413:58:56.861
==============
HANG ANALYSIS:
==============
Open chainsfound:
Chain 1 : :
<0/88/64186/0x6f2a3a40/475250/PL/SQL lock timer>
--<0/66/28252/0x6f2a2140/2089002/library cache pin>
Other chainsfound:
Chain 2 : :
<0/8/15/0x6f293b40/241800/wakeup timemanager>
Chain 3 : :
<0/27/60605/0x6f2a4e40/1613868/NoWait>
Chain 4 : :
<0/140/64779/0x6f2a9440/2117764/NoWait>
Extrainformation that will be dumped at higher levels:
[level4] :1 node dumps -- [REMOTE_WT] [LEAF] [LEAF_NW]
[level5] :3 node dumps -- [SINGLE_NODE] [SINGLE_NODE_NW] [IGN_DMP]
[level6] :1 node dumps -- [NLEAF]
[level 10]:76 node dumps -- [IGN]
State of nodes
([nodenum]/cnode/sid/sess_srno/session/ospid/state/start/finish/[adjlist]/predecessor):
[0]/0/1/1/0x6f2c4c50/282766/IGN/1/2//none
[1]/0/2/1/0x6f2c56e0/286864/IGN/3/4//none
[2]/0/3/1/0x6f2c6170/278666/IGN/5/6//none
[3]/0/4/1/0x6f2c6c00/237708/IGN/7/8//none
[4]/0/5/1/0x6f2c7690/245896/IGN/9/10//none
[5]/0/6/1/0x6f2c8120/307352/IGN/11/12//none
[6]/0/7/1/0x6f2c8bb0/299158/IGN/13/14//none
[7]/0/8/15/0x6f2c9640/241800/SINGLE_NODE/15/16//none
[8]/0/9/16437/0x6f2ca0d0//IGN/17/18//none
[9]/0/10/57955/0x6f2cab60/966866/IGN/19/20//none
[11]/0/12/18499/0x6f2cc080/798812/IGN/21/22//none
[12]/0/13/22777/0x6f2ccb10/655582/IGN/23/24//none
[13]/0/14/29669/0x6f2cd5a0/995546/IGN/25/26//none
[15]/0/16/39305/0x6f2ceac0/762106/IGN/27/28//none
[16]/0/17/41716/0x6f2cf550/1282088/IGN/29/30//none
[17]/0/18/18405/0x6f2cffe0/1765548/IGN/31/32//none
[19]/0/20/50960/0x6f2d1500/594074/IGN/33/34//none
[20]/0/21/1037/0x6f2d1f90/1347680/IGN/35/36//none
[21]/0/22/64906/0x6f2d2a20/667806/IGN/37/38//none
[22]/0/23/58042/0x6f2d34b0//IGN/39/40//none
[23]/0/24/44630/0x6f2d3f40/561236/IGN/41/42//none
[24]/0/25/27987/0x6f2d49d0/913526/IGN/43/44//none
[25]/0/26/23641/0x6f2d5460//IGN/45/46//none
[26]/0/27/60605/0x6f2d5ef0/1613868/SINGLE_NODE_NW/47/48//none
[27]/0/28/6814/0x6f2d6980/2252902/IGN/49/50//none
[29]/0/30/38893/0x6f2d7ea0/2117764/IGN/51/52//none
[30]/0/31/4083/0x6f2d8930//IGN/53/54//none
[31]/0/32/591/0x6f2d93c0/2084874/IGN/55/56//none
[32]/0/33/25228/0x6f2d9e50/2146418/IGN/57/58//none
[33]/0/34/19839/0x6f2da8e0/757874/IGN/59/60//none
[34]/0/35/52004/0x6f2db370/2314262/IGN/61/62//none
[36]/0/37/20217/0x6f2dc890/1343694/IGN/63/64//none
[37]/0/38/37361/0x6f2dd320/426096/IGN/65/66//none
[38]/0/39/62842/0x6f2dddb0/979190/IGN/67/68//none
[40]/0/41/36124/0x6f2df2d0/974900/IGN/69/70//none
[41]/0/42/52280/0x6f2dfd60/868410/IGN/71/72//none
[42]/0/43/32767/0x6f2e07f0/1056914/IGN/73/74//none
[43]/0/44/56466/0x6f2e1280/573512/IGN/75/76//none
[44]/0/45/39703/0x6f2e1d10/815272/IGN/77/78//none
[45]/0/46/58422/0x6f2e27a0/2236466/IGN/79/80//none
[46]/0/47/38349/0x6f2e3230/1933528/IGN/81/82//none
[47]/0/48/7314/0x6f2e3cc0/2056290/IGN/83/84//none
[48]/0/49/45536/0x6f2e4750/483434/IGN/85/86//none
[49]/0/50/11157/0x6f2e51e0/2318564/IGN/87/88//none
[50]/0/51/45405/0x6f2e5c70/708838/IGN/89/90//none
[51]/0/52/3753/0x6f2e6700/1679438/IGN/91/92//none
[52]/0/53/65049/0x6f2e7190/991338/IGN/93/94//none
[53]/0/54/47799/0x6f2e7c20/585760/IGN/95/96//none
[56]/0/57/61869/0x6f2e9bd0/1069080/IGN/97/98//none
[57]/0/58/25525/0x6f2ea660/2293878/IGN/99/100//none
[58]/0/59/51692/0x6f2eb0f0/2334944/IGN/101/102//none
[60]/0/61/21926/0x6f2ec610/1245364/IGN/103/104//none
[62]/0/63/3648/0x6f2edb30/1020084/IGN/105/106//none
[63]/0/64/20755/0x6f2ee5c0//IGN/107/108//none
[64]/0/65/57016/0x6f2ef050//IGN/109/110//none
[65]/0/66/28252/0x6f2efae0/2089002/NLEAF/111/114/[87]/none
[66]/0/67/9980/0x6f2f0570/2281662/IGN/115/116//none
[68]/0/69/13320/0x6f2f1a90/659626/IGN/117/118//none
[69]/0/70/47485/0x6f2f2520/2097404/IGN/119/120//none
[72]/0/73/4628/0x6f2f44d0/1032362/IGN/121/122//none
[73]/0/74/16535/0x6f2f4f60/970800/IGN/123/124//none
[74]/0/75/35508/0x6f2f59f0/1011894/IGN/125/126//none
[75]/0/76/13639/0x6f2f6480/1572996/IGN/127/128//none
[76]/0/77/24426/0x6f2f6f10/487514/IGN/129/130//none
[78]/0/79/33586/0x6f2f8430/1081504/IGN/131/132//none
[81]/0/82/35351/0x6f2fa3e0/491738/IGN/133/134//none
[82]/0/83/24257/0x6f2fae70/581672/IGN/135/136//none
[83]/0/84/18408/0x6f2fb900/2154508/IGN/137/138//none
[84]/0/85/7723/0x6f2fc390/766196/IGN/139/140//none
[86]/0/87/4841/0x6f2fd8b0/2023476/IGN/141/142//none
[87]/0/88/64186/0x6f2fe340/475250/LEAF/112/113//65
[88]/0/89/556/0x6f2fedd0/954576/IGN/143/144//none
[89]/0/90/5502/0x6f2ff860/1724668/IGN/145/146//none
[97]/0/98/30290/0x6f304ce0/639148/IGN/147/148//none
[98]/0/99/22667/0x6f305770/463022/IGN/149/150//none
[120]/0/121/5289/0x6f313fd0/839808/IGN/151/152//none
[122]/0/123/28636/0x6f3154f0/1310798/IGN/153/154//none
[124]/0/125/36699/0x6f316a10/1159176/IGN/155/156//none
[128]/0/129/19465/0x6f319450/925860/IGN/157/158//none
[139]/0/140/64779/0x6f320880/2117764/SINGLE_NODE_NW/159/160//none
[152]/0/153/64790/0x6f3291d0/880808/IGN/161/162//none
====================
END OF HANGANALYSIS
从Chain 1部分,我们看到SID为66的会话在等待SID为88的会话。
4.小结
通过设置跟踪可以很容易定位会话挂起背后的原因,本例只是简单的介绍了通过跟踪如何诊断数据库中出现的问题,其他‘高级’用法有待进一步的挖掘。
5.参考文档
metalink
来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/6906/viewspace-21673/,如需转载,请注明出处,否则将追究法律责任。
转载于:http://blog.itpub.net/6906/viewspace-21673/