解析errorstack 跟踪文件的输出

By on 2010/10/21 at 8:45 上午 in dba

本文标题:解析errorstack 跟踪文件的输出【本站如从外站转载,会注明出处】
本文链接:http://www.validba.net/2010/10/%e8%a7%a3%e6%9e%90errorstack-%e8%b7%9f%e8%b8%aa%e6%96%87%e4%bb%b6%e7%9a%84%e8%be%93%e5%87%ba/

errorstack（errorstack可以理解为错误堆栈） 跟踪文件的内容对于解决数据库异常非常的重要，通常情况下errorstack tracefile可能来自于下列几种情况：

  • 自动转储，在数据库发生ORA-600、ORA-7445或其他错误时，Oracle会在bdump或udump目录产生一个tarce文件，并将这个文件名记录在alert文件中；
  • 使用ORADEBUG DUMP ERRORSTACK命令跟踪某个进程时，Oracle会在udump目录产生一个errorstack 跟踪文件，记录了当前指定进程的一些执行调用情况，最后可通过oradebug tracefile_name活动该跟踪文件的具体路径；
  • 通过设置errorstack 事件，转储当前session或实例级某个特定的错误信息时；

errorstack 跟踪文件中可以挖掘的有用的信息有：

  • Process infomation

乃个进程导致了本次错误的发生，进程ID；进程所执行的程序；数据库的服务名等这些信息对于我们判断和解决问题有着很好的指导作用。

Oracle process number: 68
Unix process pid: 12679, image: oracleIBUDB2@db2

*** 2010-10-19 17:41:01.163
*** ACTION NAME:(Test Window - Script for procedu) 2010-10-19 17:41:01.162
*** MODULE NAME:(PL/SQL Developer) 2010-10-19 17:41:01.162
*** SERVICE NAME:(IBUDB) 2010-10-19 17:41:01.162
*** SESSION ID:(480.42965) 2010-10-19 17:41:01.162
  • Current SQL statement

在进程信息的下方列出了当前出错的SQL语句，SQL语句对于我们了解数据库当前的行为非常重要，导致出错的可能是某个具体的SQL语句也可能是某个PLSQL程序；如果是PLSQL程序，还列出了出错的具体行号和程序名称。

*** 2010-10-22 10:30:19.052
ksedmp: internal or fatal error
ORA-06502: PL/SQL: numeric or value error
Current SQL statement for this session:
BEGIN ique_attendance.P_YESTERDAY_ATTEN_FAIL_NOTIFY; END;
----- PL/SQL Call Stack -----
  object      line  object
  handle    number  name
0x6776a30c       586  package body IQUEWEB.IQUE_ATTENDANCE
0x6776a30c       677  package body IQUEWEB.IQUE_ATTENDANCE
0x6d0b1124         1  anonymous block
----- Call Stack Trace -----
calling              call     entry                argument values in hex
location             type     point                (? means dubious value)
-------------------- -------- -------------------- ----------------------------
sdtcs_getexecname: use overriding value for executable
sdtcs_getexecname: ignored overriding value [oracleIBUDB1]

对于PLSQL程序，我们可以根据上面列出的object name 利用下面的SQL查询dba_source试图，找到586和677行查看具体的操作。

col text format a100
set linesize 100 pagesize 100
select line,text from dba_source where owner='IQUEWEB' and name='IQUE_ATTENDANCE';

某些特定的环境PLSQL程序可能是加密的，这个时候查询dba_source也没用，只能根据tracefile中的cursor信息进行分析.

  • Process Stack

Process stack部分可以发现当前进程的等待和锁定信息，在一些死锁或者性能很差的跟踪文件中这方面的信息非常重要，可以了解当前进程的请求过程以及跟该进程相关的UGA,PGA的堆栈信息

PROCESS STATE
-------------
Process global information:
     process: 0x74950678, call: 0x6dd384f0, xact: (nil), curses: 0x74bd3520, usrses: 0x74bd3520
  ----------------------------------------
  SO: 0x74950678, type: 2, owner: (nil), flag: INIT/-/-/0x00
  (process) Oracle pid=75, calls cur/top: 0x6dd384f0/0x6dd384f0, flag: (0) -
            int error: 0, call error: 0, sess error: 0, txn error 0
  (post info) last post received: 0 0 53
              last post received-location: kjata: wake up enqueue owner
              last process to post me: 7493a418 1 6
              last post sent: 0 0 26
              last post sent-location: ksasnd
              last process posted by me: 7493dbc8 1 6
    (latch info) wait_event=0 bits=0
...............
  • Session Stack

 进程所创建的具体的session、session初始化的信息以及session创建的cursor的信息

CURRENT SESSION'S INSTANTIATION STATE
-------------------------------------
current session=0x74bd3520
KGI STATE DUMP START
-------------------------------------
INSTANTIATION OBJECT: object=0xb74d5140
type="PL/SQL"[0] lock=0x70da416c handle=0x701cc2e4 body=(nil) level=0
flags=SHR/NST/[45] executions=2
..............
CURSORS: size=16 count=11 next=12
index cursor      tag  context flags
----- ------ -------- -------- ---------------
    1      2 0xb73ed5a0 0xb73cc8a0 LRU/PRS/[03]
    2      4 0xb73ed464 0xb73cc700 PRS/[02]
    3      6 0xb73eda08 0xb73cbba0 LRU/PRS/[03]
    4      9 0xb73edad4 0xb73cc7d0 LRU/PRS/[03]
    5     22 0xb73ed770 0xb73cbfb0 LRU/PRS/[03]
    6     23 0xb73ed770 0xb73cc080 LRU/PRS/[03]
    7     24 0xb73ed770 0xb73cc150 LRU/PRS/[03]
    8     26 0xb73ed684 0xb73cbee0 LRU/PRS/[03]
    9     25 0xb73eda60 0xb73cbd40 LRU/PRS/[03]
   10      5 0xb73ed6f0 0xb73cbe10 LRU/PRS/[03]
   11     11 0xb73ee870 0xb73cc970 LRU/PRS/[03]

从上面的信息可以看出session工创建了16个cursor。下面的部分就是对应的每个cursor的相关信息了

  • Cursor Stack

重点出现了，这部分区域是我们了解的核心，从这里可以发现session所创建的所有的cursor，每个cursor执行的sql语句以及sql语句中的绑定变量信息

Current cursor: 13, pgadep: 0
   pgactx: 64b3baf8 ctxcbk: 0 ctxqbc: 0 ctxrws: 0
Cursor Dump:
----------------------------------------
Cursor 2 (b74d0294): CURBOUND  curiob: b720dc40
 curflg: c7 curpar: 0 curusr: 6d curses 74bd3520
 cursor name: SELECT MAX(A.CDATE) FROM IQUE_KQ_DATACOLLECT_LOG A
 child pin: 0, child lock: 72404898, parent lock: 660d3944
 xscflg: 80141076, parent handle: 6815d114, xscfl2: 4000001, xscfl3: 208c
 bhp size: 1400/1476
----------------------------------------
Cursor 4 (b74d030c): CURROW  curiob: b720ea68
 curflg: c7 curpar: 0 curusr: 6d curses 74bd3520
 cursor name: SELECT USER_ID, USER_NAME, EMAIL, ATTENDENCY_TYPE FROM IQUE_USERS_V U WHERE U.ATTENDENCY_TYPE IN ('F', 'X', 'S', 'N')
 child pin: 7181cee0, child lock: 71012d48, parent lock: 64d0c60c
 xscflg: c0141076, parent handle: 6eb31004, xscfl2: 4400001, xscfl3: 50200c
  nxt: 3.0x00000004  nxt: 2.0x00000204  nxt: 1.0x00000920
Cursor frame allocation dump:
frm: -------- Comment --------  Size  Seg Off
 bhp size: 1692/2044
 whp size: 5640/6256
Dump of CURRENT WORK HEAP:
******************************************************
HEAP DUMP heap name="kxs heap"  desc=0x
.................
Cursor 5 (b74d0348): CURBOUND  curiob: b74008e4
 curflg: c7 curpar: 0 curusr: 6d curses 74bd3520
 cursor name: SELECT A.LEAVE_START_DATE, A.LEAVE_END_DATE FROM IQUE_LEAVE_APPLICATIONS A, IQUE_WORKFLOW_ENTRY B WHERE A.APPLIER_ID =
 :B4 AND A.WORKFLOW_ENTRY_ID = B.ID AND (A.LEAVE_START_DATE <= :B3 AND A.LEAVE_END_DATE >= :B2 ) AND B.STATE = :B1
 child pin: 0, child lock: 7100a660, parent lock: 64d06684
 xscflg: 80150476, parent handle: 69079bf0, xscfl2: 5000001, xscfl3: 210c
Dumping Literal Information
Bind Pos: 0, Bind Len: 3, Bind Val:
Bind Pos: 1, Bind Len: 7, Bind Val:
Bind Pos: 2, Bind Len: 7, Bind Val:
Bind Pos: 3, Bind Len: 2, Bind Val:
 bhp size: 1916/2224
 bind 0: dty=2 mxl=22(21) mal=00 scl=00 pre=00 oacflg=03 oacfl2=a06001 size=64 offset=0
   No bind buffers allocated
 bind 1: dty=12 mxl=07(07) mal=00 scl=00 pre=00 oacflg=03 oacfl2=a06001 size=0 offset=24
   No bind buffers allocated
 bind 2: dty=12 mxl=07(07) mal=00 scl=00 pre=00 oacflg=03 oacfl2=a06001 size=0 offset=32
   No bind buffers allocated
 bind 3: dty=2 mxl=22(21) mal=00 scl=00 pre=00 oacflg=03 oacfl2=a06001 size=0 offset=40
   No bind buffers allocated
..................

Cursor 14 (b74d0564): CURBOUND  curiob: b74d75f8
 curflg: 7 curpar: 0 curusr: 0 curses 74bf3dc4
 cursor name: select obj#,type#,ctime,mtime,stime,status,dataobj#,flags,oid$, spare1, spare2 from obj$ where owner#=:1 and name=:2 a
nd namespace=:3 and remoteowner is null and linkname is null and subname is null
 child pin: 0, child lock: 70da3c08, parent lock: 7100eab0
 xscflg: a0141476, parent handle: 70915e5c, xscfl2: 5000401, xscfl3: 210c
 bhp size: 2856/3356
 bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=0001 size=24 offset=0
   bfp=b74d75d4 bln=22 avl=03 flg=05
   value=109
 bind 1: dty=1 mxl=32(15) mal=00 scl=00 pre=00 oacflg=18 oacfl2=0001 size=32 offset=0
   bfp=b74d759c bln=32 avl=15 flg=05
   value="IQUE_ATTENDANCE"
 bind 2: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=0001 size=24 offset=0
   bfp=b74d82fc bln=24 avl=02 flg=05
   value=2

简单的枚举了ERRORSTACK tracefile中的信息，在碰见问题的时候我们可以尝试着通过分析tracefile自己解决问题，Oracle中的tracefile包含了大量有用的信息，这也是Oracle技术支持远程解决问题的法宝。

CopyRight Validba'S Home 版权所有.本站为个人学习之用,评论时请遵守本国法律

Relative Posts

Tags:

Reader's Comments »

  1. By Kory on 2011/12/15 at 2:59 下午

    The expertise shines trhgouh. Thanks for taking the time to answer.

Leave a Reply