正常情况下，SQL的性能问题应该使用10046 trace进行分析，但是对于正在运行的存储过程，你却无法知道它卡在哪一步上了。
因为从v$session中只能看到最外层的存储过程执行，从10046看，因为prase阶段已经过去，也无法抓到当前的SQL语句。
以下介绍一个通过error stack分析正在运行的存储过程的实例。
对于一个正在运行的进程取errorstack和10046 trace：
sqlplus / as sysdba
oradebug setospid 14227
oradebug unlimit
oradebug Event 10046 trace name context forever, level 12
oradebug dump errorstack 3
<wait 1 minute>
oradebug dump errorstack 3
oradebug Event 10046 trace name context off;
oradebug tracefile_name
Format your 10046 trace file:
$tkprof <trace file> <output file>
For example:
$cd /u01/OracleAPP/oracle/admin/R1020/udump
$ls -ltr
$tkprof r1020_ora_14227.trc 14227.output
以下拿error stack输出做例子：
当前SQL还是最外层的调用：
*** 2014-09-29 11:19:01.723
ksedmp: internal or fatal error
Current SQL statement for this session:
call test(:1,:2,:3);
session当前正在执行的语句，也还是最外层的调用：
SO: c000000cf3d469a0, type: 4, owner: c000000cf3aff038, flag: INIT/-/-/0x00
(session) sid: 2154 trans: c000000cd6f2e558, creator: c000000cf3aff038, flag: (8100041) USR/- BSY/-/-/-/-/-
DID: 0001-0E13-00C964B6, short-term DID: 0000-0000-00000000
txn branch: c000000ccc19da48
oct: 170, prv: 0, sql: c000000cfdbef790, psql: c000000cf8911380, user: 81/CRM_APP
<=====sql: c000000cfdbef790
LIBRARY OBJECT LOCK: lock=c000000bf08347f0 handle=c000000cfdbef790 mode=N
call pin=0000000000000000 session pin=0000000000000000 hpc=0000 hlc=0000
htl=c000000bf0834870[c000000bf029f4e8,c000000c0fd03380] htb=c000000be508fd68 ssga=c000000be508fb30
user=c000000cf3d469a0 session=c000000cf3d469a0 count=1 flags=[0000] savepoint=0x54223b5e
LIBRARY OBJECT HANDLE: handle=c000000cfdbef790 mtx=c000000cfdbef8c0(1) lct=422374 pct=1 cdp=1
name=call test(:1,:2,:3);
这时，我们在此文件中使用关键字”cursor pin”查询(因为正在被执行的cursor是被pin住的):
KGX Atomic Operation Log c000000c46c068b8
Mutex c000000cb0bb3c50(0, 4) idn d1fc642e oper SHRD
Cursor Pin uid 2154 efd 0 whr 5 slp 0
opr=4 pso=c000000be618afd0 flg=0
pcs=c000000cb0bb3c50 nxt=0000000000000000 flg=18 cld=0 hd=c000000cf96a06c8 par=c000000c59a406d8
ct=1 hsh=0 unp=0000000000000000 unn=0 hvl=b0bb43f0 nhv=0 ses=0000000000000000
hep=c000000cb0bb3cd0 flg=80 ld=1 ob=c000000c38ab25f8 ptr=c000000c16e28c18 fex=c000000c16e27f28
—————————————-
SO: c000000cbbad7cc0, type: 53, owner: c000000cf3d469a0, flag: INIT/-/-/0x00
LIBRARY OBJECT LOCK: lock=c000000cbbad7cc0 handle=c000000cf9f2bb00 mode=N
call pin=0000000000000000 session pin=0000000000000000 hpc=0000 hlc=0000
htl=c000000cbbad7d40[c000000c0f625548,c000000be618b050] htb=c000000be508ff28 ssga=c000000be508fb30
user=c000000cf3d469a0 session=c000000cf3d469a0 count=1 flags=[0000] savepoint=0x54223b5f
LIBRARY OBJECT HANDLE: handle=c000000cf9f2bb00 mtx=c000000cf9f2bc30(1) lct=2203 pct=125 cdp=1
name=
SELECT * from test where c1= :B1 and c2=:B2 and C3=:B3
hash=ac2274f043d741eddeab7ad9d1fc642e timestamp=09-18-2014 21:06:00
<=====找到你了。handle=c000000cf9f2bb00。
Cursor Pin uid 2154 efd 0 whr 4 slp 0
opr=4 pso=c000000c0fd03300 flg=0
pcs=c000000cbabfc900 nxt=0000000000000000 flg=18 cld=0 hd=c000000cfdbef608 par=c000000cbabfd330
ct=0 hsh=0 unp=0000000000000000 unn=0 hvl=babfd160 nhv=0 ses=0000000000000000
hep=c000000cbabfc980 flg=80 ld=1 ob=c000000cbabfc510 ptr=c000000ca7f764e8 fex=c000000ca7f757f8
—————————————-
SO: c000000bf08347f0, type: 53, owner: c000000cf3d469a0, flag: INIT/-/-/0x00
LIBRARY OBJECT LOCK: lock=c000000bf08347f0 handle=c000000cfdbef790 mode=N
call pin=0000000000000000 session pin=0000000000000000 hpc=0000 hlc=0000
htl=c000000bf0834870[c000000bf029f4e8,c000000c0fd03380] htb=c000000be508fd68 ssga=c000000be508fb30
user=c000000cf3d469a0 session=c000000cf3d469a0 count=1 flags=[0000] savepoint=0x54223b5e
LIBRARY OBJECT HANDLE: handle=c000000cfdbef790 mtx=c000000cfdbef8c0(1) lct=422374 pct=1 cdp=1
name=call test(:1,:2,:3);
<====当然还有最外层这个cursor
Cursor Pin uid 2154 efd 0 whr 5 slp 0
opr=4 pso=c000000c0ffd6730 flg=0
pcs=c000000cb5fbe988 nxt=0000000000000000 flg=18 cld=0 hd=c000000cf7faf950 par=c000000cb5fbf3b8
ct=0 hsh=0 unp=0000000000000000 unn=0 hvl=b5fbf1e8 nhv=0 ses=0000000000000000
hep=c000000cb5fbea08 flg=80 ld=1 ob=c000000cb5fbe598 ptr=c000000cb5fbb710 fex=c000000cb5fbaa20
—————————————-
SO: c000000be6194b10, type: 53, owner: c000000cf3d469a0, flag: INIT/-/-/0x00
LIBRARY OBJECT LOCK: lock=c000000be6194b10 handle=c000000cf7fafb80 mode=N
call pin=0000000000000000 session pin=0000000000000000 hpc=0000 hlc=0000
htl=c000000be6194b90[c000000be508ffe8,c000000c0ffd67b0] htb=c000000be508ffe8 ssga=c000000be508fb30
user=c000000cf3d469a0 session=c000000cf3d469a0 count=1 flags=[0000] savepoint=0x54223a54
LIBRARY OBJECT HANDLE: handle=c000000cf7fafb80 mtx=c000000cf7fafcb0(0) lct=17870500 pct=1 cdp=1
name=table_1_ff_159_0_0_0
<====以及一些LIBRARY OBJECT对象(可以忽略)
使用关键字“sqltxt(c000000cf9f2bb00)”查询可以找到该cursor使用的绑定变量的值：
Cursor#37(9fffffffbf3b2828) state=ROW curiob=9fffffffbf340638
curflg=c7 fl2=0 par=0000000000000000 ses=c000000cf3d469a0
sqltxt(c000000cf9f2bb00)=
SELECT * from test where c1= :B1 and c2=:B2 and C3=:B3
hash=ac2274f043d741eddeab7ad9d1fc642e
parent=c000000c59a406d8 maxchild=01 plk=c000000cbbad7cc0 ppn=n
cursor instantiation=9fffffffbf340638 used=1411529567
child#0(c000000cf96a06c8) pcs=c000000cb0bb3c50
clk=c000000be618afd0 ci=c000000c38ab2710 pn=c000000c46c068b8 ctx=c000000c16e28c18
kgsccflg=0 llk[9fffffffbf340640,9fffffffbf340640] idx=0
xscflg=c0151476 fl2=5000001 fl3=402a210c fl4=100
Bind bytecodes
Opcode = 1 Unoptimized
Offsi = 48, Offsi = 0
Opcode = 1 Unoptimized
Offsi = 48, Offsi = 32
Opcode = 1 Unoptimized
Offsi = 48, Offsi = 64
kkscoacd
Bind#0
oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
oacflg=03 fl2=1206001 frm=00 csi=00 siz=176 off=0
kxsbbbfp=9fffffffbeed1f40 bln=22 avl=04 flg=05
value=10001
Bind#1
oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
oacflg=03 fl2=1206001 frm=00 csi=00 siz=0 off=24
kxsbbbfp=9fffffffbeed1f58 bln=22 avl=04 flg=01
value=11409
Bind#2
oacdty=01 mxl=128(100) mxlc=00 mal=00 scl=00 pre=00
oacflg=03 fl2=1206001 frm=01 csi=852 siz=0 off=48
kxsbbbfp=9fffffffbeed1f70 bln=128 avl=09 flg=01
value=”222410641″
<=====当前使用的绑定变量的值。
参与此主题的后续讨论，请回复blog，或者访问我们的中文社区，跟帖”分享：使用error stack 抓取存储过程的当前SQL“。
了解更多博文信息请访问Oracle数据库产品技术支持-博客文章索引