DDL觸發器設定導致DDL無法執行（二）

從物件定義是找不到問題的原因的，只能透過10046跟蹤一下：

SQL> ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT FOREVER, LEVEL 12';

Session altered.

SQL> CREATE TABLE T_CREATE (ID NUMBER);
CREATE TABLE T_CREATE (ID NUMBER)
*
ERROR at line 1:
ORA-00604: error occurred at recursive SQL level 1
ORA-30511: invalid DDL operation in system triggers
ORA-06512: at line 24
ORA-06512: at line 24

SQL> ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT OFF';

Session altered.

查詢得到的TRACE檔案：

*** ACTION NAME:() 2012-01-31 12:15:24.811
*** MODULE NAME:(sqlplus@hpserver2.enmotech.com (TNS V1-V3)) 2012-01-31 12:15:24.811
*** SERVICE NAME:(SYS$USERS) 2012-01-31 12:15:24.811
*** SESSION ID:(146.138) 2012-01-31 12:15:24.811
Skipped error 604 during the execution of DBFW_CONSOLE_ACCESS.TRIGGER_LOGIN
*** 2012-01-31 12:15:24.811
ksedmp: internal or fatal error
ORA-00604: error occurred at recursive SQL level 1
ORA-30511: invalid DDL operation in system triggers
ORA-06512: at line 3
*** 2012-01-31 12:26:10.929
*** ACTION NAME:() 2012-01-31 12:26:10.929
*** MODULE NAME:(SQL*Plus) 2012-01-31 12:26:10.929
A deadlock among DDL and parse locks is detected.
This deadlock is usually due to user errors in
the design of an application or from issuing a set
of concurrent statements which can cause a deadlock.
This should not be reported to Oracle Support.
The following information may aid in finding
the errors which cause the deadlock:
ORA-04020: deadlock detected while trying to lock object EYGLE.BIN$trcEn8qthIjgQKjAEwAm+g==$0
--------------------------------------------------------
  object   waiting  waiting       blocking blocking
  handle   session     lock mode   session     lock mode
--------  -------- -------- ----  -------- -------- ----
0xb88364d8  0xb8f713c8 0xb56ca598    X  0xb8f713c8 0xb56ca7c0    X
--------------------------------------------------------
---------- DUMP OF WAITING AND BLOCKING LOCKS ----------
--------------------------------------------------------
------------- WAITING LOCK -------------
----------------------------------------
SO: 0xb56ca598, type: 53, owner: 0xb73c2990, flag: INIT/-/-/0x00
LIBRARY OBJECT LOCK: lock=b56ca598 handle=b88364d8 request=X
call pin=(nil) session pin=(nil) hpc=0000 hlc=0000
htl=0xb56ca618[0xb56ca840,0xb53b1e18] htb=0xb53b1e18 ssga=0xb53b13b0
user=b8f713c8 session=b8f713c8 count=0 flags=[0000] savepoint=0x1494
LIBRARY OBJECT HANDLE: handle=b88364d8 mtx=0xb8836608(0) cdp=0
name=EYGLE.BIN$trcEn8qthIjgQKjAEwAm+g==$0
hash=41d7b6fc85abfd51d2baef487c92dc95 timestamp=01-17-2012 17:33:09
namespace=TABL flags=KGHP/TIM/FUL/FUP/SML/[0e000000]
kkkk-dddd-llll=0000-0701-0701 lock=X pin=X latch#=3 hpc=01d6 hlc=01d6
lwt=0xb8836580[0xb56ca5c8,0xb56ca5c8] ltm=0xb8836590[0xb8836590,0xb8836590]
pwt=0xb8836548[0xb8836548,0xb8836548] ptm=0xb8836558[0xb8836558,0xb8836558]
ref=0xb88365b0[0xb88365b0,0xb88365b0] lnd=0xb88365c8[0xb88365c8,0xb88365c8]
  LIBRARY OBJECT: bject=b48a8d18
  type=TABL flags=EXS/LOC/UPD/PRG[0985] pflags=[0040] status=VALD load=0
  DATA BLOCKS:
  data#     heap  pointer    status pins change whr
  ----- -------- -------- --------- ---- ------ ---
      0 b8836418 b48a8e30 I/P/A/-/-    0 NONE   00
      8 b48a88a8 b03cdbf8 I/P/A/-/-    1 UPDATE 00
      9 b48a8978 b03cd428 I/P/A/-/-    1 NONE   00
     10 b48a8a00 b03cd040 I/P/A/-/-    1 UPDATE 00
------------- BLOCKING LOCK ------------
----------------------------------------
SO: 0xb56ca7c0, type: 53, owner: 0xb73c20f0, flag: INIT/-/-/0x00
LIBRARY OBJECT LOCK: lock=b56ca7c0 handle=b88364d8 mode=X
call pin=(nil) session pin=(nil) hpc=0000 hlc=0000
htl=0xb56ca840[0xb53b1e18,0xb56ca618] htb=0xb53b1e18 ssga=0xb53b13b0
user=b8f713c8 session=b8f82a10 count=2 flags=[0000] savepoint=0xd70
LIBRARY OBJECT HANDLE: handle=b88364d8 mtx=0xb8836608(0) cdp=0
name=EYGLE.BIN$trcEn8qthIjgQKjAEwAm+g==$0
hash=41d7b6fc85abfd51d2baef487c92dc95 timestamp=01-17-2012 17:33:09
namespace=TABL flags=KGHP/TIM/FUL/FUP/SML/[0e000000]
kkkk-dddd-llll=0000-0701-0701 lock=X pin=X latch#=3 hpc=01d6 hlc=01d6
lwt=0xb8836580[0xb56ca5c8,0xb56ca5c8] ltm=0xb8836590[0xb8836590,0xb8836590]
pwt=0xb8836548[0xb8836548,0xb8836548] ptm=0xb8836558[0xb8836558,0xb8836558]
ref=0xb88365b0[0xb88365b0,0xb88365b0] lnd=0xb88365c8[0xb88365c8,0xb88365c8]
  LIBRARY OBJECT: bject=b48a8d18
  type=TABL flags=EXS/LOC/UPD/PRG[0985] pflags=[0040] status=VALD load=0
  DATA BLOCKS:
  data#     heap  pointer    status pins change whr
  ----- -------- -------- --------- ---- ------ ---
      0 b8836418 b48a8e30 I/P/A/-/-    0 NONE   00
      8 b48a88a8 b03cdbf8 I/P/A/-/-    1 UPDATE 00
      9 b48a8978 b03cd428 I/P/A/-/-    1 NONE   00
     10 b48a8a00 b03cd040 I/P/A/-/-    1 UPDATE 00
--------------------------------------------------------
This lock request was aborted.
*** 2012-01-31 17:25:14.137
A deadlock among DDL and parse locks is detected.
This deadlock is usually due to user errors in
the design of an application or from issuing a set
of concurrent statements which can cause a deadlock.
This should not be reported to Oracle Support.
The following information may aid in finding
the errors which cause the deadlock:
ORA-04020: deadlock detected while trying to lock object EYGLE.BIN$trcI7ykLAu7gQKjAEwAnkA==$0
--------------------------------------------------------
  object   waiting  waiting       blocking blocking
  handle   session     lock mode   session     lock mode
--------  -------- -------- ----  -------- -------- ----
0xb209bfc0  0xb8f713c8 0xb56c3aa0    X  0xb8f713c8 0xb56756f0    X
--------------------------------------------------------
---------- DUMP OF WAITING AND BLOCKING LOCKS ----------
--------------------------------------------------------
------------- WAITING LOCK -------------
----------------------------------------
SO: 0xb56c3aa0, type: 53, owner: 0xb77d5078, flag: INIT/-/-/0x00
LIBRARY OBJECT LOCK: lock=b56c3aa0 handle=b209bfc0 request=X
call pin=(nil) session pin=(nil) hpc=0000 hlc=0000
htl=0xb56c3b20[0xb5675770,0xb53b1b08] htb=0xb53b1b08 ssga=0xb53b13b0
user=b8f713c8 session=b8f713c8 count=0 flags=[0000] savepoint=0x386e
LIBRARY OBJECT HANDLE: handle=b209bfc0 mtx=0xb209c0f0(0) cdp=0
name=EYGLE.BIN$trcI7ykLAu7gQKjAEwAnkA==$0
hash=f2ab522fb35d982d1fbc28237e665464 timestamp=01-17-2012 17:34:17
namespace=TABL flags=KGHP/TIM/FUP/SML/[0a000000]
kkkk-dddd-llll=0000-0701-0701 lock=X pin=X latch#=2 hpc=0038 hlc=0038
lwt=0xb209c068[0xb56c3ad0,0xb56c3ad0] ltm=0xb209c078[0xb209c078,0xb209c078]
pwt=0xb209c030[0xb209c030,0xb209c030] ptm=0xb209c040[0xb209c040,0xb209c040]
ref=0xb209c098[0xb209c098,0xb209c098] lnd=0xb209c0b0[0xb209c0b0,0xb209c0b0]
  LIBRARY OBJECT: bject=b0c49fd8
  type=TABL flags=EXS/LOC/UPD/PRG[0985] pflags=[0040] status=VALD load=0
  DATA BLOCKS:
  data#     heap  pointer    status pins change whr
  ----- -------- -------- --------- ---- ------ ---
      0 b209bf00 b0c4a0f0 I/P/A/-/-    0 NONE   00
      8 b0c49b68 b0201480 I/P/A/-/-    1 UPDATE 00
      9 b0c49c38 b0200cb0 I/P/A/-/-    1 NONE   00
     10 b0c49cc0 b01af398 I/P/A/-/-    1 UPDATE 00
------------- BLOCKING LOCK ------------
----------------------------------------
SO: 0xb56756f0, type: 53, owner: 0xb77d47d8, flag: INIT/-/-/0x00
LIBRARY OBJECT LOCK: lock=b56756f0 handle=b209bfc0 mode=X
call pin=(nil) session pin=(nil) hpc=0000 hlc=0000
htl=0xb5675770[0xb53b1b08,0xb56c3b20] htb=0xb53b1b08 ssga=0xb53b13b0
user=b8f713c8 session=b8f6fe60 count=2 flags=[0000] savepoint=0x35eb
LIBRARY OBJECT HANDLE: handle=b209bfc0 mtx=0xb209c0f0(0) cdp=0
name=EYGLE.BIN$trcI7ykLAu7gQKjAEwAnkA==$0
hash=f2ab522fb35d982d1fbc28237e665464 timestamp=01-17-2012 17:34:17
namespace=TABL flags=KGHP/TIM/FUP/SML/[0a000000]
kkkk-dddd-llll=0000-0701-0701 lock=X pin=X latch#=2 hpc=0038 hlc=0038
lwt=0xb209c068[0xb56c3ad0,0xb56c3ad0] ltm=0xb209c078[0xb209c078,0xb209c078]
pwt=0xb209c030[0xb209c030,0xb209c030] ptm=0xb209c040[0xb209c040,0xb209c040]
ref=0xb209c098[0xb209c098,0xb209c098] lnd=0xb209c0b0[0xb209c0b0,0xb209c0b0]
  LIBRARY OBJECT: bject=b0c49fd8
  type=TABL flags=EXS/LOC/UPD/PRG[0985] pflags=[0040] status=VALD load=0
  DATA BLOCKS:
  data#     heap  pointer    status pins change whr
  ----- -------- -------- --------- ---- ------ ---
      0 b209bf00 b0c4a0f0 I/P/A/-/-    0 NONE   00
      8 b0c49b68 b0201480 I/P/A/-/-    1 UPDATE 00
      9 b0c49c38 b0200cb0 I/P/A/-/-    1 NONE   00
     10 b0c49cc0 b01af398 I/P/A/-/-    1 UPDATE 00
--------------------------------------------------------
This lock request was aborted.
*** 2012-01-31 17:39:16.132
WAIT #2: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=37 tim=1296877691535577
*** 2012-01-31 17:40:12.165
WAIT #2: nam='SQL*Net message from client' ela= 54719914 driver id=1650815232 #bytes=1 p3=0 obj#=37 tim=1296877746255669
XCTEND rlbk=0, rd_only=1
=====================
PARSING IN CURSOR #10 len=33 dep=0 uid=60 ct=1 lid=60 tim=1296877746256995 hv=4051323229 ad='b2088510'
CREATE TABLE T_CREATE (ID NUMBER)
END OF STMT
PARSE #10:c=0,e=885,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=1296877746256954
BINDS #10:
=====================
.
.
.
=====================
PARSING IN CURSOR #13 len=753 dep=1 uid=58 ct=47 lid=58 tim=1296877746275168 hv=2905514213 ad='b8852970'
declare
  li ora_name_list_t;
  n integer;
  cSQL clob;
begin
  if dbfw_console_access.is_local then
    if ora_dict_obj_type = 'TABLE' and
       ora_dict_obj_owner = 'DBFW_CONSOLE_ACCESS' and
       ora_dict_obj_name = 'EVENT' then
      null;
    else
      n := ora_sql_txt(li);
      for i in 1 .. n loop
        cSQL := cSQL || li(i);
      end loop;
      if cSQL is not null then
        insert into dbfw_console_access.event(id,username,sessionid,event,text)
          select dbfw_console_access.event_seq.nextval,
                 sys_context('USERENV','SESSION_USER'),
                 sys_context('USERENV','SESSIONID'),
                 'DDL',
                 cSQL
            from dual;
        end if;
    end if;
  end if;
end;
END OF STMT
PARSE #13:c=0,e=20,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1296877746275166
BINDS #13:
=====================
PARSING IN CURSOR #5 len=213 dep=2 uid=58 ct=2 lid=58 tim=1296877746275611 hv=1466247469 ad='b88468c0'
INSERT INTO DBFW_CONSOLE_ACCESS.EVENT(ID,USERNAME,SESSIONID,EVENT,TEXT) SELECT DBFW_CONSOLE_ACCESS.EVENT_SEQ.NEXTVAL, SYS_CONTEXT('USERENV','SESSION_USER'),
SYS_CONTEXT('USERENV','SESSIONID'), 'DDL', :B1 FROM DUAL
END OF STMT
PARSE #5:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=1296877746275608
BINDS #5:
kkscoacd
 Bind#0
  oacdty=112 mxl=4000(4000) mxlc=00 mal=00 scl=00 pre=00
  oacflg=01 fl2=206001 frm=01 csi=873 siz=4000 ff=0
  kxsbbbfp=7fa2b3cf99c0  bln=4000  avl=40  flg=05
  value=
Dump of memory from 0x00007FA2B3CF99C0 to 0x00007FA2B3CF99E8
7FA2B3CF99C0 01002600 03800802 00000200 0092008A  [.&..............]
7FA2B3CF99D0 08000000 17006903 01000000 00000000  [.....i..........]
7FA2B3CF99E0 F9D69D36 5422DE81                    [6....."T]       
=====================
.
.
.
=====================
PARSING IN CURSOR #4 len=57 dep=3 uid=0 ct=12 lid=0 tim=1296877746278076 hv=0 ad='b40eead8'
drop table "EYGLE"."BIN$trcI7ykLAu7gQKjAEwAnkA==$0" purge
END OF STMT
PARSE #4:c=0,e=158,p=0,cr=0,cu=0,mis=1,r=0,dep=3,og=4,tim=1296877746278074
BINDS #4:
=====================
.
.
.
=====================
PARSING IN CURSOR #7 len=753 dep=4 uid=58 ct=47 lid=58 tim=1296877746356839 hv=2905514213 ad='b8852970'
declare
  li ora_name_list_t;
  n integer;
  cSQL clob;
begin
  if dbfw_console_access.is_local then
    if ora_dict_obj_type = 'TABLE' and
       ora_dict_obj_owner = 'DBFW_CONSOLE_ACCESS' and
       ora_dict_obj_name = 'EVENT' then
      null;
    else
      n := ora_sql_txt(li);
      for i in 1 .. n loop
        cSQL := cSQL || li(i);
      end loop;
      if cSQL is not null then
        insert into dbfw_console_access.event(id,username,sessionid,event,text)
          select dbfw_console_access.event_seq.nextval,
                 sys_context('USERENV','SESSION_USER'),
                 sys_context('USERENV','SESSIONID'),
                 'DDL',
                 cSQL
            from dual;
        end if;
    end if;
  end if;
end;
END OF STMT
PARSE #7:c=0,e=26,p=0,cr=0,cu=0,mis=0,r=0,dep=4,og=1,tim=1296877746356836
BINDS #7:
=====================
PARSING IN CURSOR #14 len=213 dep=5 uid=58 ct=2 lid=58 tim=1296877746357237 hv=1466247469 ad='b88468c0'
INSERT INTO DBFW_CONSOLE_ACCESS.EVENT(ID,USERNAME,SESSIONID,EVENT,TEXT) SELECT DBFW_CONSOLE_ACCESS.EVENT_SEQ.NEXTVAL, SYS_CONTEXT('USERENV','SESSION_USER'),
SYS_CONTEXT('USERENV','SESSIONID'), 'DDL', :B1 FROM DUAL
END OF STMT
PARSE #14:c=0,e=15,p=0,cr=0,cu=0,mis=0,r=0,dep=5,og=1,tim=1296877746357234
BINDS #14:
kkscoacd
 Bind#0
  oacdty=112 mxl=4000(4000) mxlc=00 mal=00 scl=00 pre=00
  oacflg=01 fl2=206001 frm=01 csi=873 siz=4000 ff=0
  kxsbbbfp=7fa2b3d2d680  bln=4000  avl=40  flg=05
  value=
Dump of memory from 0x00007FA2B3D2D680 to 0x00007FA2B3D2D6A8
7FA2B3D2D680 01002600 03800802 00000200 0092008A  [.&..............]
7FA2B3D2D690 0A000000 31006903 01000000 00000000  [.....i.1........]
7FA2B3D2D6A0 30937991 2DB5F5E9                    [.y.0...-]       
=====================
.
.
.
=====================
PARSING IN CURSOR #11 len=51 dep=7 uid=0 ct=10 lid=0 tim=1296877746421849 hv=0 ad='b40e3b50'
drop index "EYGLE"."BIN$trcI7ykNAu7gQKjAEwAnkA==$0"
END OF STMT
PARSE #11:c=5000,e=19651,p=1,cr=66,cu=0,mis=1,r=0,dep=7,og=4,tim=1296877746421846
BINDS #11:
EXEC #1:c=10999,e=55067,p=2,cr=154,cu=18,mis=0,r=0,dep=6,og=4,tim=1296877746421937
ERROR #1:err=30511 tim=793245673
STAT #12 id=1 cnt=1 pid=0 pos=1 bj=0 p='NESTED LOOPS  (cr=12 pr=0 pw=0 time=184 us)'
STAT #12 id=2 cnt=1 pid=1 pos=1 bj=32 p='TABLE ACCESS BY INDEX ROWID CCOL$ (cr=4 pr=0 pw=0 time=33 us)'
STAT #12 id=3 cnt=1 pid=2 pos=1 bj=54 p='INDEX RANGE SCAN I_CCOL1 (cr=3 pr=0 pw=0 time=19 us)'
STAT #12 id=4 cnt=1 pid=1 pos=2 bj=21 p='TABLE ACCESS BY INDEX ROWID COL$ (cr=8 pr=0 pw=0 time=149 us)'
STAT #12 id=5 cnt=1 pid=4 pos=1 bj=47 p='INDEX UNIQUE SCAN I_COL3 (cr=4 pr=0 pw=0 time=79 us)'
STAT #2 id=1 cnt=2 pid=0 pos=1 bj=0 p='SORT ORDER BY (cr=3 pr=0 pw=0 time=67 us)'
STAT #2 id=2 cnt=3 pid=1 pos=1 bj=702 p='TABLE ACCESS FULL RECYCLEBIN$ (cr=3 pr=0 pw=0 time=40 us)'
EXEC #14:c=17998,e=65066,p=2,cr=373,cu=57,mis=0,r=0,dep=5,og=1,tim=1296877746422333
ERROR #14:err=604 tim=793245673
EXEC #7:c=17998,e=65535,p=2,cr=374,cu=82,mis=0,r=0,dep=4,og=1,tim=1296877746422463
ERROR #7:err=30511 tim=793245673
XCTEND rlbk=1, rd_only=1
STAT #3 id=1 cnt=1 pid=0 pos=1 bj=0 p='SORT ORDER BY (cr=3 pr=0 pw=0 time=75 us)'
STAT #3 id=2 cnt=3 pid=1 pos=1 bj=702 p='TABLE ACCESS FULL RECYCLEBIN$ (cr=3 pr=0 pw=0 time=48 us)'
EXEC #5:c=73990,e=147097,p=5,cr=882,cu=104,mis=0,r=0,dep=2,og=1,tim=1296877746422739
ERROR #5:err=604 tim=793245673
EXEC #13:c=73990,e=147555,p=5,cr=883,cu=130,mis=0,r=0,dep=1,og=1,tim=1296877746422827
ERROR #13:err=30511 tim=793245673
WAIT #10: nam='log file sync' ela= 76283 buffer#=2642 p2=4987314 p3=0 obj#=-1 tim=1296877746499472
WAIT #10: nam='SQL*Net break/reset to client' ela= 3 driver id=1650815232 break?=1 p3=0 obj#=-1 tim=1296877746499549
WAIT #10: nam='SQL*Net break/reset to client' ela= 92 driver id=1650815232 break?=0 p3=0 obj#=-1 tim=1296877746499674
WAIT #10: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1296877746499688
*** 2012-01-31 17:40:22.304
WAIT #10: nam='SQL*Net message from client' ela= 9656896 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1296877756156629
=====================
PARSING IN CURSOR #19 len=55 dep=0 uid=60 ct=42 lid=60 tim=1296877756157111 hv=524428051 ad='0'
ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT OFF'
END OF STMT
PARSE #19:c=0,e=198,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=1296877756157104
EXEC #19:c=0,e=83,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=1296877756157288

不難看出，導致問題產生的原因是由於在執行了CREATE TABLE語句後，觸發器引發了刪除回收站中的索引和表的DDL，而這個DDL又會再次引發觸發器的觸發，從而在一個會話中引入了死鎖。

不過為什麼觸發器會導致回收站中的索引和表的DROP動作呢，查詢後發現，原來觸發器的觸發動作是一個INSERT語句，而當前表中資料已滿，需要擴充套件新的空間，而恰好這個物件所在的表空間也沒有剩餘空間了，所以Oracle不得以要清除RECYCLEBIN中的物件來釋放新的空間：

SQL> select table_name, tablespace_name from dba_tables
2 WHERE TABLE_NAME = 'EVENT'
3 AND WNER = 'DBFW_CONSOLE_ACCESS';

TABLE_NAME                     TABLESPACE_NAME
------------------------------ ------------------------------
EVENT                          USERS

SQL> SELECT SUM(BYTES)/1024/1024 FROM DBA_FREE_SPACE WHERE TABLESPACE_NAME = 'USERS';

SUM(BYTES)/1024/1024
--------------------

找到問題的原因解決起來就很簡單了，不過由於DDL觸發器會導致INSERT，因此除了PURGE之外，所有其他的嘗試都會報錯：

SQL> conn / as sysdba
Connected.
SQL> purge table eygle.t_pwd;

Table purged.

SQL> select * from dba_recyclebin;

no rows selected

SQL> CREATE TABLE T_CREATE (ID NUMBER);

Table created.

好在PURGE語句沒有導致觸發器的觸發，從而避免了錯誤的產生，如果PURGE同樣導致觸發器執行，或者RECYCLEBIN中沒有物件可以清除，那麼當前的問題可能就很難用常規手段解決了。

這也說明一個問題，在DDL觸發器中執行的操作一定要謹慎，否則很容易導致系統的故障。