使用error stack診斷特定錯誤資訊

 

在實際應用開發中，我們有很多精力傾注在除錯程式和異常情況的排查上。使用設計邏輯和場景開發的程式碼，經常被生產資料一次次的“攻破”。快速的定位錯誤資料和報錯語句是我們提高工作效率的關鍵。本篇介紹使用Oracle的error stack方法來定位程式包中報錯的SQL和取值。

 

1、場景展現

 

我們選擇Oracle 11g來進行試驗。

 

 

SQL> select * from v$version where rownum<3;

 

BANNER

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

Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production

PL/SQL Release 11.2.0.1.0 – Production

 

 

資料表T包括object_id和object_name列。其中object_id為主鍵列。

 

 

SQL> create table t (object_id number, object_name varchar2(100));

Table created

 

SQL> alter table t add constraint pk_t primary key (object_id);

Table altered

 

 

灌入一部分基礎資料，作為原始值。

 

 

SQL> insert into t select object_id, object_name from dba_objects where wner='SCOTT';

20 rows inserted

 

SQL> commit;

Commit complete

 

 

為了進行實驗，我們建立一個procedure程式段，從dba_objects中選取資料插入到資料表T中。程式定義如下：

 

 

SQL> create or replace procedure P_ERRORSTACK_TEST

  2  is

  3  type t_objs_list is table of dba_objects%rowtype index by binary_integer;

  4  t_obj_infos t_objs_list;

  5  begin

  6    select *

  7    bulk collect into t_obj_infos

  8    from dba_objects;

  9 

 10    if (t_obj_infos.count<>0) then

 11       for i in t_obj_infos.first..t_obj_infos.last loop

 12           insert into t

 13           values (t_obj_infos(i).object_id, t_obj_infos(i).object_name);

 14       end loop;

 15    end if;

 16  end P_ERRORSTACK_TEST;

 17  /

 

Procedure created

 

 

注意三個細節：首先，我們是逐條進行資料的插入動作的，而不是insert into select方式。第二，我們在for迴圈裡面插入資料，迴圈次數多，實際上不能逐條進行檢查判斷。第三，我們插入的是dba_objects所有的資料，必然一部分插入資料和原始資料表中存在主鍵衝突的情況。

 

實際執行中，報錯。

 

 

SQL> exec P_ERRORSTACK_TEST;

 

begin P_ERRORSTACK_TEST; end;

 

ORA-00001: 違反唯一約束條件 (SCOTT.PK_T)

ORA-06512: 在 "SCOTT.P_ERRORSTACK_TEST", line 12

ORA-06512: 在 line 1

 

 

有過除錯和測試經驗的朋友們非常熟悉這樣的情景。大批次資料測試的時候，儲存過程作業包括成千上萬相同或者不同的SQL，執行資料海量。執行半天之後，報錯。類似的錯誤還有如長度（數字字串）超過限制、將空值null插入到非空約束欄位，違反外來鍵約束等等。

 

這樣的原因無非幾種，一是程式的Bug，開發人員沒有考慮到業務場景，一般出現在null值計算結果null上。其二是設計問題，業務人員和設計人員沒有考慮到當前這樣的異常場景。最後也是比較麻煩的，就是測試資料來源有問題，需要進行額外清理工作。

 

無論原因是上述哪種，有兩件事情是必須做到，是哪句SQL報錯，報錯的資料引數值是什麼。

 

當然，我們可以認為加入除錯程式碼來輸入執行過程，從而實現定位。我們更方便的是使用error stack的診斷事件方法來進行定位。

 

2、Error Stack診斷

 

Oracle是一個極其複雜的體系。為了便於進行除錯和診斷，Oracle提供了很多的“後門”裝置。我們最熟悉的10046和10053就是用來診斷SQL語句執行過程和最佳化器工作情況的。

 

Error Stack是另一種診斷事件。當啟動診斷事件時候，需要設定一個錯誤編號ora。在啟動跟蹤過程中，一旦報錯指定的code，Oracle就會將當前資訊，如SQL和記憶體棧情況dump成trace檔案。

 

和10046一樣，error stack也有對應的level取值。目前我們常用的取值有4個等級。一般為了進行診斷，筆者建議將最高等級資訊輸出比較好。

 

下面我們使用error stack來解決問題。

 

 

--啟動error stack監控過程

SQL> alter session set events '1 trace name errorstack level 4';

Session altered

 

SQL> exec P_ERRORSTACK_TEST;

 

begin P_ERRORSTACK_TEST; end;

 

ORA-00001: 違反唯一約束條件 (SCOTT.PK_T)

ORA-06512: 在 "SCOTT.P_ERRORSTACK_TEST", line 12

ORA-06512: 在 line 1

 

--關閉過程

SQL> alter session set events '1 trace name errorstack off';

Session altered

 

 

注意：error stack可以在system和session level進行設定。我們使用session level就可以滿足大部分場景的處理要求了。

 

檢查檢視v$diag_info，來定位trace檔案位置。

 

 

SQL> select value from v$diag_info where name='Default Trace File';

 

VALUE

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

/u01/diag/rdbms/wilson/wilson/trace/wilson_ora_3813.trc

 

 

此時，我們在指定目錄下面可以找到檔案。

 

 

[oracle@bspdev ~]$ cd /u01/diag/rdbms/wilson/wilson/trace/

[oracle@bspdev trace]$ ls -l | grep 3813

-rw-r----- 1 oracle oinstall  7866074 Sep  4 05:20 wilson_ora_3813.trc

-rw-r----- 1 oracle oinstall   210205 Sep  4 05:20 wilson_ora_3813.trm

 

 

下面要做的就是解析trace檔案。

 

3、Trace檔案解析

 

應該說，使用最高level生成的診斷檔案，體積是很大的。其中一些內部的資訊，也是很有學習和參考意義。但是對於診斷來說，資料檢索定位是非常重要的。

 

首先，我們在檔案頭，可以發現錯誤SQL語句的資訊。Oracle顯然在報錯的時候，將SQL語句捕獲到。

 

 

dbkedDefDump(): Starting a non-incident diagnostic dump (flags=0x0, level=4, mask=0x0)

----- Error Stack Dump -----

ORA-00001: 違反唯一約束條件 (SCOTT.PK_T)

----- Current SQL Statement for this session (sql_id=ccf9mag4p402f) -----

INSERT INTO T VALUES (:B1 , :B2 )

----- PL/SQL Stack -----

----- PL/SQL Call Stack -----

  object      line  object

  handle    number  name

0x4b5df860        12  procedure SCOTT.P_ERRORSTACK_TEST

0x497b9ee0         1  anonymous block

 

 

在error stack呼叫結構中，我們可以定位到具體是哪一個方法報錯，哪一個SQL報錯。Object handle表示PL/SQL程式塊在記憶體中快取的結構。這裡，我們定位到了報錯語句SQL，是sql_id= ccf9mag4p402f的insert語句。

 

之後，在trace檔案中進行檢索sql_id資訊，找到了語句的執行過程Trace。

 

 

----- Dump Cursor sql_id=ccf9mag4p402f xsc=0x559a168 cur=0x700d60 -----

 

LibraryHandle:  Address=4b5d671c Hash=c952004e LockMode=N PinMode=0 LoadLockMode=0 Status=VALD

  ObjectName:  Name=INSERT INTO T VALUES (:B1 , :B2 )

 

    FullHashValue=ecb9f90364e2dbcec6393353c952004e Namespace=SQL AREA(00) Type=CURSOR(00) Identifier=3377594446 wnerIdn=84

  Statistics:  InvalidationCount=0 ExecutionCount=143716 LoadCount=2 ActiveLocks=1 TotalLockCount=1 TotalPinCount=1

  Counters:  BrokenCount=1 RevocablePointer=1 KeepDependency=1 KeepHandle=1 BucketInUse=1 HandleInUse=1

  Concurrency:  DependencyMutex=4b5d6784(0, 3, 0, 0) Mutex=4b5d67d0(43, 22, 0, 6)

 （篇幅原因，有省略……）

 kgsccflg=9 llk[0x559a16c,0x559a16c] idx=1004f

 xscflg=c0110676 fl2=1d020000 fl3=422a2188 fl4=100

----- Bind Byte Code (IN) -----

  Opcode = 6   Bind Rpi Scalar Sql In(may be out) Nocopy NoSkip

  Offsi = 36, ffsi = 0

  Opcode = 6   Bind Rpi Scalar Sql In(may be out) Nocopy NoSkip

  Offsi = 36, ffsi = 20

----- 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 ff=0

  kxsbbbfp=0072e3d4  bln=22  avl=04  flg=09

  value=73180

 Bind#1

  oacdty=01 mxl=128(128) mxlc=00 mal=00 scl=00 pre=00

  oacflg=13 fl2=206001 frm=01 csi=873 siz=128 ff=0

  kxsbbbfp=0072e404  bln=128  avl=07  flg=09

  value="PK_DEPT"

 Frames pfr 0x559a110 siz=2572 efr 0x559a088 siz=2532

 Cursor frame. dump

  enxt: 3.0x000004c4  enxt: 2.0x00000028  enxt: 1.0x000004f8

  pnxt: 1.0x00000028

 kxscphp=0x739424 siz=1000 inu=384 nps=224

 kxscbhp=0x33e3060 siz=1000 inu=92 nps=0

Starting SQL statement dump

SQL Information

user_id=84 user_name=SCOTT module=PL/SQL Developer action=Command Window - New

sql_id=ccf9mag4p402f plan_hash_value=0 problem_type=0

 

 

注意後面標紅的部分說明這個SQL有兩個繫結變數，重要的是記錄了繫結變數當前的取值：object_id為73180。表明SQL在插入到73180的時候，報錯發生。

 

我們驗證一下。

 

 

SQL> select object_id from t;

 

 OBJECT_ID

----------

     73179

     73180

     73181

     73182

 （篇幅原因，有省略……）

 

     78028

 

20 rows selected

 

 

當前資料表中已經存在73180，主鍵重複必然報錯。

 

4、結論

 

Error stack是一個非常方便的小工具，可以在診斷、除錯程式的時候幫助解決很多問題。