ITPub博客

首页 > 数据库 > Oracle > 使用error stack 抓取存储过程的当前SQL

使用error stack 抓取存储过程的当前SQL

原创 Oracle 作者:pxbibm 时间:2014-10-23 16:03:17 0 删除 编辑

正常情况下,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"

<=====当前使用的绑定变量的值。

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/12798004/viewspace-1308165/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论
  • 博文量
    240
  • 访问量
    2165645