用Oracle跟踪诊断挂起的会话

1.简介

本文通过例子简要介绍了如何利用Oracle的跟踪以及内部数据字典表诊断某些挂起的会话。

--测试脚本

conn test/test

create orreplace procedure sp_test

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%'

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)

输入sid的值:66

原值3: (SELECT PADDR FROMV$SESSION WHERE SID=&sid)

新值3: (SELECT PADDR FROMV$SESSION WHERE SID=66)

PID

----------

在跟踪文件中查找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

输入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

google

最后编辑于：2017.12.11 03:56:03

人面猴
序言：七十年代末，一起剥皮案震惊了整个滨河市，随后出现的几起案子，更是在滨河造成了极大的恐慌，老刑警刘岩，带你破解...
沈念sama阅读 211,884评论 6赞 492
死咒
序言：滨河连续发生了三起死亡事件，死亡现场离奇诡异，居然都是意外死亡，警方通过查阅死者的电脑和手机，发现死者居然都...
沈念sama阅读 90,347评论 3赞 385
救了他两次的神仙让他今天三更去死
文/潘晓璐我一进店门，熙熙楼的掌柜王于贵愁眉苦脸地迎上来，“玉大人，你说我怎么就摊上这事。” “怎么了？”我有些...
开封第一讲书人阅读 157,435评论 0赞 348
道士缉凶录：失踪的卖姜人
文/不坏的土叔我叫张陵，是天一观的道长。经常有香客问我，道长，这世上最难降的妖魔是什么？我笑而不...
开封第一讲书人阅读 56,509评论 1赞 284
港岛之恋（遗憾婚礼）
正文为了忘掉前任，我火速办了婚礼，结果婚礼上，老公的妹妹穿的比我还像新娘。我一直安慰自己，他们只是感情好，可当我...
茶点故事阅读 65,611评论 6赞 386
恶毒庶女顶嫁案：这布局不是一般人想出来的
文/花漫我一把揭开白布。她就那样静静地躺着，像睡着了一般。火红的嫁衣衬着肌肤如雪。梳的纹丝不乱的头发上，一...
开封第一讲书人阅读 49,837评论 1赞 290
城市分裂传说
那天，我揣着相机与录音，去河边找鬼。笑死，一个胖子当着我的面吹牛，可吹牛的内容都是我干的。我是一名探鬼主播，决...
沈念sama阅读 38,987评论 3赞 408
双鸳鸯连环套：你想象不到人心有多黑
文/苍兰香墨我猛地睁开眼，长吁一口气：“原来是场噩梦啊……” “哼！你这毒妇竟也来了？” 一声冷哼从身侧响起，我...
开封第一讲书人阅读 37,730评论 0赞 267
万荣杀人案实录
序言：老挝万荣一对情侣失踪，失踪者是张志新（化名）和其女友刘颖，没想到半个月后，有当地人在树林里发现了一具尸体，经...
沈念sama阅读 44,194评论 1赞 303
护林员之死
正文独居荒郊野岭守林人离奇死亡，尸身上长有42处带血的脓包…… 初始之章·张勋以下内容为张勋视角年9月15日...
茶点故事阅读 36,525评论 2赞 327
白月光启示录
正文我和宋清朗相恋三年，在试婚纱的时候发现自己被绿了。大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
茶点故事阅读 38,664评论 1赞 340
活死人
序言：一个原本活蹦乱跳的男人离奇死亡，死状恐怖，灵堂内的尸体忽然破棺而出，到底是诈尸还是另有隐情，我是刑警宁泽，带...
沈念sama阅读 34,334评论 4赞 330
日本核电站爆炸内幕
正文年R本政府宣布，位于F岛的核电站，受9级特大地震影响，放射性物质发生泄漏。R本人自食恶果不足惜，却给世界环境...
茶点故事阅读 39,944评论 3赞 313
男人毒药：我在死后第九天来索命
文/蒙蒙一、第九天我趴在偏房一处隐蔽的房顶上张望。院中可真热闹，春花似锦、人声如沸。这庄子的主人今日做“春日...
开封第一讲书人阅读 30,764评论 0赞 21
一桩弑父案，背后竟有这般阴谋
文/苍兰香墨我抬头看了看天上的太阳。三九已至，却和暖如春，着一层夹袄步出监牢的瞬间，已是汗流浃背。一阵脚步声响...
开封第一讲书人阅读 31,997评论 1赞 266
情欲美人皮
我被黑心中介骗来泰国打工，没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留，地道东北人。一个月前我还...
沈念sama阅读 46,389评论 2赞 360
代替公主和亲
正文我出身青楼，却偏偏与公主长得像，于是被迫代替她去往敌国和亲。传闻我的和亲对象是个残疾皇子，可洞房花烛夜当晚...
茶点故事阅读 43,554评论 2赞 349

用Oracle跟踪诊断挂起的会话

1.简介

2.通过SYSTEMSTATE跟踪

3.通过HANGANALYZE跟踪

4.小结

5.参考文档

推荐阅读更多精彩内容