使用error stack 抓取儲存過程的當前SQL

正常情況下，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

oradebug dump errorstack 3
oradebug Event 10046 trace name context off;
oradebug tracefile_name

Format your 10046 trace file:
$tkprof

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"

<=====當前使用的繫結變數的值。