Oracle ErrorStack怎么用

小編給大家分享一下Oracle ErrorStack怎么用，希望大家閱讀完這篇文章之后都有所收獲，下面讓我們一起去探討吧！

一、概述

在Oracle數據庫運行過程中，我們經常會遇到這樣或那樣的錯誤，但是錯誤的提示并不具體，加大了我們在診斷問題時的難度。

ErrorStack是Oracle提供的一種對于錯誤堆棧進行跟蹤的方法，通過設置跟蹤可以將一些指定錯誤的后臺信息詳細的轉儲出來，寫入跟蹤文件，幫助我們診斷問題。

備注：

1、當oracle發生關鍵的錯誤諸如：ora-600,Errorstack是自動被oracle dump寫入trace文件中。

2、當你在alert.log里面看見這類錯誤，并提示已經產生trace文件。打開對應的trace后，你會發現這類trace文件一般都是以“ksedmp:internal or fatal error"開頭，"kesdmp"意味著Kernel Service Error Dump，這一行下面的內容就是errorstack記錄的錯誤堆棧！

Errorstack dump也可以通過使用Oradebug errorstack 3手工調用，前提是先使用Oradebug setospid設定了目標進程之后。Oradebug Errorstack對于診斷一個session似乎Hang住(但是在v$session_wait里面并未出現合理的wait event)或者是比正常時消耗更多資源時，獲取當前session執行sql、具體的變量值等等信息，從而幫助你找到問題根源！

二、跟蹤級別和方法

ErrorStack主要有4個跟蹤級別，如下

• 0 僅轉儲錯誤堆棧
  

• 1 轉儲錯誤堆棧和函數調用堆棧
  

• 2 Level 1 + ProcessState
  

• 3 Level 2 + Context area （一般我們診斷問題，都是使用這個級別的跟蹤！）
  

ErrorStack設置方法，如下（僅指定特定的錯誤代碼，只有這個特定的錯誤出現時才能被觸發！）

• 實例級別：alter system set events='984 trace name errorstack forever,level 3' scope=spfile;
  

• 會話級別: alter session set events='984 trace name errorstack forever,level 3';
  

• oradebug： 1、oradebug setospid xxxx; 2、oradebug dump errorstack 3   --當前session正在運行的語句

三、ErrorStack跟蹤文件中的內容

Errorstack跟蹤文件有很多信息，這里我們主要講解對我們診斷問題最有用的四個部分的內容（其它很多內容我們無法看懂），如下

• 從Errorstack跟蹤文件中發現當前正在執行SQL文本。
  

• 從Errorstack跟蹤文件中發現當前正在執行PL/SQL包和PL/SQL source code line number。
  

• 從Errorstack跟蹤文件中發現當前bind variable value。
  

• 從Errorstack跟蹤文件中發現一個cursor正在使用多少private memory(UGA)。
  

針對上面的四個部分，我將通過一個具體的errorstack跟蹤文件示例來展示盒加深理解，errorstack的跟蹤文件如下（具體生成方式代碼，放在最后了）。這一部分的內容主要參考tanelpoder大牛的博客。

1、從Errorstack跟蹤文件中發現當前正在執行SQL文本

這一部分非常容易找到，當前sql語句的文本信息在跟蹤文件的最前面部分(可以搜索Current SQL statement for this session)

Trace file /u01/oracle/diag/rdbms/cn100/cn100/trace/cn100_ora_10848.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, Oracle Label Security, OLAP, Data Mining,
Oracle Database Vault and Real Application Testing options
ORACLE_HOME = /u01/oracle/product/11.2.0
System name:    Linux
Node name:      192oracle.cn100.com
Release:        2.6.32-358.el6.x86_64
Version:        #1 SMP Fri Feb 22 00:31:26 UTC 2013
Machine:        x86_64
Instance name: cn100
Redo thread mounted by this instance: 1
Oracle process number: 26
Unix process pid: 10848, image: oracle@192oracle.cn100.com (TNS V1-V3)


*** 2014-07-01 11:16:36.260
*** SESSION ID:(61.13360) 2014-07-01 11:16:36.260
*** CLIENT ID:() 2014-07-01 11:16:36.260
*** SERVICE NAME:(SYS$USERS) 2014-07-01 11:16:36.260
*** MODULE NAME:(SQL*Plus) 2014-07-01 11:16:36.260
*** ACTION NAME:() 2014-07-01 11:16:36.260
 
dbkedDefDump(): Starting a non-incident diagnostic dump (flags=0x0, level=3, mask=0x0)
----- Error Stack Dump -----
ORA-01438: value larger than specified precision allowed for this column
----- Current SQL Statement for this session (sql_id=b8n03s73k7d39) -----  --可以看到，當前SQL就在這一行下面
INSERT INTO DH_T VALUES (:B2 ,:B1 )
----- PL/SQL Stack -----
----- PL/SQL Call Stack -----
  object      line  object
  handle    number  name
0x1075fcd10         6  procedure DBMON.P_DH1
0xfcfaebe8         7  procedure DBMON.P_DH2
0x10e7d6420         1  anonymous block

----- Call Stack Trace -----
calling              call     entry                argument values in hex      
location             type     point                (? means dubious value)     
-------------------- -------- -------------------- ----------------------------
skdstdst()+36        call     kgdsdst()            000000000 ? 000000000 ?
                                                   7FFF332C8AD8 ? 000000001 ?
                                                   7FFF332CCFD8 ? 000000000 ?
......為了排版,后續省略......

2、從Errorstack跟蹤文件中發現當前正在執行PL/SQL包和PL/SQL source code line number

Errorstack跟蹤文件和前面一樣，如下

注意上面跟蹤文件中PL/SQL標紅那一部分，就是我們關注的部分。

如果進行errorstack跟蹤式，跟蹤進程執行的是一個PL/SQL調用，那么PL/SQL調用堆也將被跟蹤下來(在PL/SQL Call Stack部分)。這部分告訴你錯誤發生時Oracle在執行具體哪個PL/SQL過程（包or函數）以及errorstack跟蹤過程中的具體哪個調用發生錯誤。這對我們診斷問題非常有幫助

PL/SQL Call Stack包含三列，如下

1. object handle
   

2. line number
   

3. object name
   

下面我們一一介紹這三列的含義：

1、object handle

object handle是這個對象(PL/SQL過程、包、函數、匿名塊)被load進library cache中的內存地址，可以通過這個映射地址和X$KGLOB.KGLHDADR表列關聯起來以發現那個對象是正在被處理。如下

SQL> select kglnaown,kglnaobj,kglhdadr from X$KGLOB a where KGLHDADR='00000001075FCD10';

KGLNAOWN   KGLNAOBJ   KGLHDADR

---------- ---------- ----------------

DBMON      P_DH1      00000001075FCD10

2、line number

這個是非常重要的信息，它將告訴你當errorstack調用發生時正在執行的PL/SQL代碼（可以定位到代碼中的具體行）。例如，在如上的輸出中，在這個匿名塊的第1行調用了DBMON.P_DH2存儲過程，而DBMON.P_DH2存儲過程在第7行調用了另外一個存儲過程DBMON.P_DH1，當errorstack跟蹤發生時正在執行DBMON.P_DH2存儲過程中的第6行代碼。

3、object name

PL/SQL存儲的對象名(或者匿名塊，當對象并沒有存儲在一個過程中)，如果是匿名塊(匿名塊的文本可以通過V$SQL發現),你可以關聯這個地址和V$SQL.ADDRESS來發現匿名塊的文本信息。

以上的PL/SQL call stack僅僅包含三行。

0x1075fcd10         6  procedure DBMON.P_DH1
0xfcfaebe8          7  procedure DBMON.P_DH2
0x10e7d6420         1  anonymous block

應該從下而上來閱讀一個PL/SQL call stack，例如

1.底部的行可以告訴我們正在執行一個匿名塊以及在這個匿名塊的第一行，它在調用DBMON.P_DH2存儲過程

2.第二行可以告訴我們DBMON.P_DH2存儲過程在第7行調用了另外一個存儲過程DBMON.P_DH1

3.DBMON.P_DH2存儲過程中的第6行代碼出現錯誤，errorstack信息被轉儲。

通過查詢DBA_SOURCE，我們可以與errorstack跟蹤文件中的PL/SQL call stack部分信息進行驗證，如下。  

你可以發現會話正在執行的PL/SQL第6行（一個insert語句導致錯誤）。

通常,當error dump，crash，hang發生時(頂部的行是”parent" function遞歸調用的“child”function正在執行的代碼)，PL/SQL errorstack告訴我們精確的PL/SQL code。     

3、從Errorstack跟蹤文件中發現當前bind variable value

為什么找到具體的語句后，我們還需要尋找具體的綁定變量值？？可以歸納為如下四種原因

1. 一個會話可能以某種方式變的非常消耗CPU,并且會話的wait等待時間沒有任何意義.
   

2. 你需要調查什么SQL正在被執行，并且你需要查看SQL帶有的綁定變量
   

3. SQL的執行計劃是正常的，但是性能卻非常低下
   

4. 可以假設當某些表或者行源變的大的時候，存在數據傾斜，CBO沒有計算出正確的執行計劃。
   

因此，你需要知道當問題發生時SQL使用的綁定變量是什么，不幸的是Oracle中并沒有一個V$視圖讓我們去查看某個session的當前綁定變量值。V$SQL_BIND_CAPTURE視圖僅僅隨機的采樣綁定變量值，并不存儲所有的被使用的綁定變量值，而dbms_xplan.display_cursor中顯示的也只是第一次窺探的綁定變量值.

Oracle 11gR2中實時的SQL Monitoring特性能夠達到此目的。在V$SQL_MONITOR中有一列BIND_XML,此列包含正在運行的足夠長時間(默認占用CPU超過5s的SQL，都會出現在次視圖中)的bind variable values.但是這個只有在11gR2并且具有Diag+Tuning pack licenses時才有效。

注意：由于SQL語句的綁定變量值存在于進程的PGA中的私有內存中，因此不能輕易的跟蹤另一個進程私有內存。errorstack跟蹤文件中中包含CURSORDUMP,也就包含我們想要得到的bind variable value。

我們繼續看開始的跟蹤文件，如下

打開跟蹤文件，通常第一步做的是搜索第一個"Session Cursor Dump",當搜索它的時候，將看到如下的輸出

----- Session Cursor Dump -----
Current cursor: 2, pgadep=1

Open cursors(pls, sys, hwm, max): 3(1, 1, 64, 1000)
 NULL=0 SYNTAX=0 PARSE=0 BOUND=3 FETCH=0 ROW=0
Cached frame pages(total, free):
 4k(11, 8), 8k(0, 0), 16k(0, 0), 32k(0, 0)

----- Current Cursor -----

  xsc=0x7f5227898580 ctx=0xf92d7aa8 pgactx=0xf92d7aa8 ctxcbk=0xf92d74f8 ctxqbc=(nil) ctxrws=0x10293a4c0
----- Explain Plan Dump -----
----- Compact Format (Stream) -----
 
Dumping stream from 0 to 22
----------------------------------
 
0000: 143 137  23   1   1   0 105   0   0   0   1   0   0   0   0  21   9   4   6   7    ......i.............
0020:   0 142                                                                            ..
----- Plan Table -----
 
============
Plan Table
============
--------------------------------------------+-----------------------------------+
| Id  | Operation                 | Name    | Rows  | Bytes | Cost  | Time      |
--------------------------------------------+-----------------------------------+
| 0   | INSERT STATEMENT          |         |       |       |     1 |           |
| 1   |  LOAD TABLE CONVENTIONAL  |         |       |       |       |           |
--------------------------------------------+-----------------------------------+
 
Content of other_xml column
===========================
  db_version     : 11.2.0.1
  parse_schema   : DBMON
  plan_hash      : 0
  plan_hash_2    : 0
 
Compilation Environment Dump
optimizer_mode_hinted               = false
optimizer_features_hinted           = 0.0.0
parallel_execution_enabled          = true
parallel_query_forced_dop           = 0

......為了排版,后續省略......

我們可以發現如下有用的內容

1. Current cursor: 2,這個告訴我們在這個會話的UGA打開的cursor中，當前正在執行Cursor# 6 游標
   

2. the pgadep：1變量告訴我們PGA depth，也就是這個查詢執行的遞歸的深度
   

如果pgadep為0，它意味著這個查詢是一個top-level查詢，正在被用戶或者應用通過OCI接口在執行。

pgadep為1，意味著它是一個遞歸的查詢，通過遞歸程序接口(RPI)來執行，可能是數據字典查詢或者僅僅通過PL/SQL調用執行的SQL。

所以，能夠發現當前正在執行的當前查詢的綁定變量值，我們需要做的是在trace file中朝前搜索Cursor2#，如下

注意：這個搜索詞是大小寫敏感的。

Cursor#2(0x7f5227951aa0) state=BOUND curiob=0x7f5227898580
 curflg=cd fl2=0 par=(nil) ses=0x129a8edc0
----- Dump Cursor sql_id=b8n03s73k7d39 xsc=0x7f5227898580 cur=0x7f5227951aa0 -----

LibraryHandle:  Address=f68ce8d8 Hash=c723b469 LockMode=N PinMode=0 LoadLockMode=0 Status=VALD
  ObjectName:  Name=INSERT INTO DH_T VALUES (:B2 ,:B1 )

    FullHashValue=38f6bac85b76f427b45003c1c723b469 Namespace=SQL AREA(00) Type=CURSOR(00) Identifier=3341005929 OwnerIdn=148
  Statistics:  InvalidationCount=0 ExecutionCount=1 LoadCount=2 ActiveLocks=1 TotalLockCount=1 TotalPinCount=1
  Counters:  BrokenCount=1 RevocablePointer=1 KeepDependency=1 KeepHandle=1 BucketInUse=0 HandleInUse=0
  Concurrency:  DependencyMutex=f68ce988(0, 1, 0, 0) Mutex=f68cea00(61, 19, 0, 6)
  Flags=RON/PIN/TIM/PN0/DBN/[10012841]
  WaitersLists:
    Lock=f68ce968[f68ce968,f68ce968]
    Pin=f68ce978[f68ce948,f68ce948]
  Timestamp:  Current=07-01-2014 11:16:35
  LibraryObject:  Address=f6b87d18 HeapMask=0000-0001-0001 Flags=EXS[0000] Flags2=[0000] PublicFlags=[0000]
    ChildTable:  size='16'
      Child:  id='0' Table=f6b88bc8 Reference=f6b88668 Handle=fab7b4c0
    Children:
      Child:  childNum='0'
        LibraryHandle:  Address=fab7b4c0 Hash=0 LockMode=N PinMode=S LoadLockMode=0 Status=VALD
          Name:  Namespace=SQL AREA(00) Type=CURSOR(00)
          Statistics:  InvalidationCount=0 ExecutionCount=1 LoadCount=1 ActiveLocks=1 TotalLockCount=1 TotalPinCount=2
          Counters:  BrokenCount=1 RevocablePointer=1 KeepDependency=0 KeepHandle=0 BucketInUse=0 HandleInUse=0
          Concurrency:  DependencyMutex=fab7b570(0, 0, 0, 0) Mutex=f68cea00(61, 19, 0, 6)
          Flags=RON/PIN/PN0/EXP/[10012111]
          WaitersLists:
            Lock=fab7b550[fab7b550,fab7b550]
            Pin=fab7b560[fab7b530,fab7b530]
          LibraryObject:  Address=f6569b20 HeapMask=0000-0001-0001 Flags=EXS[0000] Flags2=[0000] PublicFlags=[0000]
            DataBlocks:
              Block:  #='0' name=CCUR^c723b469 pins=0 Change=NONE
                Heap=f6a0b38 Pointer=f6569c08 Extent=f6569aa0 Flags=I/-/P/A/-/-
                FreedLocation=0 Alloc=3.093750 Size=3.937500 LoadTime=11473268840
              Block:  #='6' name=SQLA^c723b469 pins=0 Change=NONE
                Heap=f6b88438 Pointer=f92d7aa8 Extent=f92d6e48 Flags=I/-/P/A/-/E
                FreedLocation=0 Alloc=8.890625 Size=11.859375 LoadTime=0
          NamespaceDump:
            Child Cursor:  Heap0=0xf6569c08 Heap6=0xf92d7aa8 Heap0 Load Time=07-01-2014 11:16:35 Heap6 Load Time=07-01-2014 11:16:35
  NamespaceDump:
    Parent Cursor:  sql_id=b8n03s73k7d39 parent=0xf6b87e00 maxchild=1 plk=y ppn=n    kkscs=0xf6b88308 nxt=(nil) flg=18 cld=0 hd=0xfab7b4c0 par=0xf6b87e00
   Mutex 0xf6b88308(0, 0) idn 3000000000
   ct=0 hsh=0 unp=(nil) unn=0 hvl=f6b88c60 nhv=0 ses=(nil)
   hep=0xf6b88398 flg=80 ld=1 ob=0xf6569b20 ptr=0xf92d7aa8 fex=0xf92d6e48
cursor instantiation=0x7f5227898580 used=1404184595 exec_id=16777216 exec=1
 child#0(0xfab7b4c0) pcs=0xf6b88308
  clk=0x10d6111e0 ci=0xf6569c08 pn=0xfdf4c890 ctx=0xf92d7aa8
 kgsccflg=1 llk[0x7f5227898588,0x7f5227898588] idx=6a
 xscflg=c0110676 fl2=d120000 fl3=422a2188 fl4=100
----- Bind Byte Code (IN) -----
  Opcode = 6   Bind Rpi Scalar Sql In(may be out) Nocopy NoSkip
  Offsi = 48, Offsi = 0
  Opcode = 6   Bind Rpi Scalar Sql In(may be out) Nocopy NoSkip
  Offsi = 48, Offsi = 32
----- Bind Info (kkscoacd) -----
 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=7f5227943d08  bln=22  avl=05  flg=09
  value=1234335
 Bind#1
  oacdty=01 mxl=2000(200) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=01 csi=852 siz=2000 off=0
  kxsbbbfp=7f5227943d48  bln=2000  avl=05  flg=09
  value="oradh"
 Frames pfr 0x7f5227897c18 siz=3424 efr 0x7f5227897b38 siz=3376
 Cursor frame dump
  enxt: 3.0x00000550  enxt: 2.0x00000040  enxt: 1.0x000007a0
  pnxt: 1.0x00000030
 kxscphp=0x7f5227961030 siz=984 inu=584 nps=360
 kxscbhp=0x7f5227961920 siz=984 inu=152 nps=0
 kxscwhp=0x7f5227960f40 siz=4056 inu=56 nps=0

注意：重點關注上面標紅字體部份

ErrorStack dump是我們可以很可靠的找到SQL語句當前使用的綁定變量值一種方法。另外，還有如下說明：

• 在errorstack跟蹤文件中發現Cursor#2，它的state=BOUND，意味著綁定變量值已經被賦予的
  

• SQL文本是我們在前面已經查找出來的，我們可以看到兩個綁定變量值
  

• Bind variale numbering是從0開始，所以如果我們想搜索第一個綁定值，需要搜索Bind#0
  

4、從Errorstack跟蹤文件中發現一個cursor正在使用多少private memory(UGA)

繼續我們前面的示例，跟蹤文件中能夠度量一個session的某些游標使用了多少UGA私有內存。如下

 Cursor#2游標部分：
 Cursor frame dump
  enxt: 3.0x00000550  enxt: 2.0x00000040  enxt: 1.0x000007a0
  pnxt: 1.0x00000030
 kxscphp=0x7f5227961030 siz=984 inu=584 nps=360
 kxscbhp=0x7f5227961920 siz=984 inu=152 nps=0
 kxscwhp=0x7f5227960f40 siz=4056 inu=56 nps=0
 Cursor#1游標部分：
 Cursor frame dump
  enxt: 12.0x000005c0  enxt: 11.0x00000fd8  enxt: 10.0x00000fa0  enxt: 9.0x00000658
  enxt: 8.0x00000228  enxt: 7.0x00000fd8  enxt: 6.0x00000fa0  enxt: 5.0x00000248
  enxt: 4.0x00000fa0  enxt: 3.0x00000410  enxt: 2.0x00000480  enxt: 1.0x00000f70
  pnxt: 1.0x00000030
 kxscphp=0x7f5227960c70 siz=2792 inu=1056 nps=424
 kxscbhp=0x7f5227960e50 siz=10376 inu=10008 nps=8768

在cursor frame dump部分我們可以看見kxsc開始的一些信息，這些意味著Kernel eXECUTION Shared Cursor，其中的每一行的siz參數告訴我們當前分配的私有內存大小。當然，我們需要匯總所有的siz，這個值就是此游標的memory usage。

下面是我的一些猜測匯總：

01.Heap description     Meaning  

02.kxscphp              Cursor permanent heap. Allocated when cursor is opened     

03.kxscdfhp             Cursor default heap - default duration allocations  

04.kxscehp              Cursor ephemeral heap - short lived duration allocations  

05.kxscwhp              Cursor Work heap - used when actually executing the cursor (workareas etc)  

06.kxscbhp              Cursor Bind heap - this is where bind variable values and their metadata are kept.

四、實驗代碼

1、創建表和PL/SQL函數

create table dh_t (id number(2,1),name varchar2(200));
create or replace procedure p_dh2 as
  v_id number :=1234335;
  v_name varchar2(200) :='oradh';
begin
   --just for errorstack test
   insert into dh_t values (v_id,v_name);
   commit;
end;
/
create or replace procedure p_dh3 as
   v_cnt number;
begin
   ----just for errorstack test
   select count(*) into v_cnt from dh_t;
   dbms_output.put_line('the dh_t count is '||v_cnt);
   p_dh2;
end;
/

2、進行errorstack跟蹤

SQL*Plus: Release 11.2.0.1.0 Production on Tue Jul 1 11:15:52 2014
Copyright (c) 1982, 2009, Oracle.  All rights reserved.
Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, Oracle Label Security, OLAP, Data Mining,
Oracle Database Vault and Real Application Testing options
SQL> set linesize 200 pagesize 999
SQL> col tracefile format a100
SQL> select spid,tracefile from v$process a where addr=(select paddr from v$session where sid=(select sid from v$mystat where rownum=1));

SPID                     TRACEFILE
---------------    --------------------------------------------------------------------------------------------------
10848                    /u01/oracle/diag/rdbms/cn100/cn100/trace/cn100_ora_10848.trc

SQL> alter session set events='1438 trace name errorstack forever,level 3';
Session altered.
SQL> exec p_dh3;
BEGIN p_dh3; END;

*
ERROR at line 1:
ORA-01438: value larger than specified precision allowed for this column
ORA-06512: at "DBMON.P_DH1", line 6
ORA-06512: at "DBMON.P_DH2", line 7
ORA-06512: at line 1

[oracle@192oracle ~]$ ls -ltr /u01/oracle/diag/rdbms/cn100/cn100/trace/cn100_ora_10848.trc
-rw-r----- 1 oracle oinstall 12190347 Jul  1 11:16 /u01/oracle/diag/rdbms/cn100/cn100/trace/cn100_ora_10848.trc

看完了這篇文章，相信你對“Oracle ErrorStack怎么用”有了一定的了解，如果想了解更多相關知識，歡迎關注億速云行業資訊頻道，感謝各位的閱讀！