Systemstates分析会话阻塞—锁表

模拟会话被阻塞

--会话1
SQL> select sid from v$mystat where rownum=1;

       SID
----------
        15

SQL> create table t_xifenfei (id number,name varchar2(20));

Table created.

SQL> insert into t_xifenfei values(1,'xifenfei');

1 row created.

SQL> insert into t_xifenfei values(2,'www.xifenfei');

1 row created.

SQL> commit;

Commit complete.

SQL> select * from t_xifenfei;

        ID NAME
---------- ----------------------------------------
         1 xifenfei
         2 www.xifenfei

SQL> delete from t_xifenfei where id=1;

1 row deleted.

--会话2
SQL>  select sid from v$mystat where rownum=1;

       SID
----------
       143

SQL> delete from chf.t_xifenfei where id=1;
--hang住

新打开会话做Systemstates
我们假设不知道会话1和会话2的sid,现在特定的使用Systemstates分析问题,后面给出简单分析方法

SQL> oradebug setmypid
Statement processed.
SQL> oradebug unlimit
Statement processed.
SQL> oradebug dump systemstate 10
Statement processed.
SQL> oradebug dump systemstate 10
Statement processed.
SQL> oradebug tracefile_name
/u01/oracle/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_31027.trc
SQL> exit

阅读trace文件
会话2在这样的情况下hang住,而其他会话正常,第一反应是在lock级别阻塞了,而这个又是DML操作,很自然想到是TX,于是在trace文件中搜索”enq: TX” ,找到对应记录,然后向上找到对应的进程号,开始读相关内容,发现有小信息如下:

PROCESS 20: 
  ----------------------------------------
--客户端信息
    client details:
      O/S info: user: oracle, term: pts/0, ospid: 30622
      machine: xifenfei program: sqlplus@xifenfei (TNS V1-V3)
      application name: SQL*Plus, hash value=3669949024

--进程相关session信息
    (session) sid: 15 ser: 151 trans: 0x343a4c2c, creator: 0x35fe2218
              flags: (0x45) USR/- flags_idl: (0x0) -/-/-/-/-/-
              flags2: (0x40009) -/-/INC
              DID: , short-term DID: 
              txn branch: (nil)
              oct: 0, prv: 0, sql: (nil), psql: 0x2f6e7b68, user: 84/CHF

--被阻塞会话信息
    There are 1 sessions blocked by this session.
    Dumping one waiter:
      inst: 1, sid: 143, ser: 229
      wait event: 'enq: TX - row lock contention'
        p1: 'name|mode'=0x54580006
        p2: 'usn<<16 | slot'=0x40005
        p3: 'sequence'=0x252
      row_wait_obj#: 75928, block#: 171, row#: 0, file# 4
      min_blocked_time: 296 secs, waiter_cache_ver: 7860
    Wait State:
      fixed_waits=0 flags=0x22 boundary=(nil)/-1

--54580006 is split into ASCII 54 + ASCII 58 (TX) + Mode 0006 (X) ...

SQL> select object_type,object_name,owner from dba_objects where object_id=75928;  

OBJECT_TYP OBJECT_NAME          OWNER
---------- -------------------- ----------
TABLE      T_XIFENFEI           CHF

--持有锁的信息
      (enqueue) TX-00040005-00000252	DID: 0001-0014-0000009C
      lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  res_flag: 0x6
      mode: X, lock_flag: 0x0, lock: 0x343a4c6c, res: 0x353606a8
      own: 0x355ae5b8, sess: 0x355ae5b8, proc: 0x35fe2218, prv: 0x353606b0
--通过上述信息可以分析出结论:
sqlplus登录的sid=15的会话占用了TX mode=6(mode:x)的锁,阻塞了sid=143会话对chf.t_xifenfei表操作

找出被阻塞进程相关信息(sid 为143的进程),搜索”sid: 143″,阅读相关进程信息

PROCESS 21: 
  ----------------------------------------
--相关session信息
 (session) sid: 143 ser: 229 trans: 0x343915a0, creator: 0x35fe2d3c
              flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
              flags2: (0x40009) -/-/INC
              DID: , short-term DID: 
              txn branch: (nil)
              oct: 7, prv: 0, sql: 0x2f6cb234, psql: 0x2f6dd5cc, user: 0/SYS

--当前等待信息
 Current Wait Stack:
     0: waiting for 'enq: TX - row lock contention'
        name|mode=0x54580006, usn<<16 | slot=0x40005, sequence=0x252
        wait_id=12 seq_num=13 snap_id=1
        wait times: snap=5 min 1 sec, exc=5 min 1 sec, total=5 min 1 sec
        wait times: max=infinite, heur=5 min 1 sec
        wait counts: calls=101 os=101
        in_wait=1 iflags=0x15a0

--阻塞该会话的session信息
    There is at least one session blocking this session.
      Dumping 1 direct blocker(s):
        inst: 1, sid: 15, ser: 151
      Dumping final blocker:
        inst: 1, sid: 15, ser: 151
    Wait State:
      fixed_waits=0 flags=0x22 boundary=(nil)/-1

--请求锁信息
      SO: 0x352f8fcc, type: 8, owner: 0x35765fe8, flag: INIT/-/-/0x00 if: 0x1 c: 0x1
       proc=0x35fe2d3c, name=enqueue, file=ksq1.h LINE:380, pg=0
      (enqueue) TX-00040005-00000252	DID: 0001-0015-0000003B
      lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  res_flag: 0x6
      req: X, lock_flag: 0x10, lock: 0x352f8ff8, res: 0x353606a8
      own: 0x356f49b8, sess: 0x356f49b8, proc: 0x35fe2d3c, prv: 0x353606b8
--通过对被阻塞对象分析,可以得出和阻塞者相同的信息

对该问题的常规分析思路

--查询等待事件
SQL> select event,p1,p2,p3 from v$session where wait_class#<>6;

EVENT                                  P1         P2         P3
------------------------------ ---------- ---------- ----------
SQL*Net message to client      1650815232          1          0
enq: TX - row lock contention  1415053318     262149        594

--查询锁信息(因为通过上面的等待事件分析,TX可能引起会话hang)
SQL> SELECT * FROM v$lock where type in ('TM','TX');

ADDR     KADDR           SID TYPE        ID1        ID2      LMODE    REQUEST      CTIME      BLOCK
-------- -------- ---------- ---- ---------- ---------- ---------- ---------- ---------- ----------
352F8FCC 352F8FF8        143 TX       262149        594          0          6       4181          0
B69CC7A8 B69CC7D8        143 TM        75928          0          3          0       4181          0
B69CC7A8 B69CC7D8         15 TM        75928          0          3          0       4266          0
343A4C2C 343A4C6C         15 TX       262149        594          6          0       4267          1

--通过TM查询出来对应对象
SQL>  select object_type,object_name,owner from dba_objects where object_id=75928; 

OBJECT_TYP OBJECT_NAME          OWNER
---------- -------------------- ----------
TABLE      T_XIFENFEI           CHF

--通过观察v$lock查询结果可以知道:
15会话的TX MODE=6的锁阻塞了143会话想会的的TX MODE=6的锁,从而是的143会话hang住

Systemstates分析参考文档:Understanding and Reading Systemstates或者[ID 423153.1]

找出 alter system kill session ‘sid,serial#’ kill 掉的数据库会话对应进程

当我们使用alter system kill session ‘sid,serial#’ 在数据库中kill掉某个会话的时候,如果你观察仔细会发现v$session.paddr发生了改变,从而是的不能直接通过关联v$process.add找出spid,然后进行其他操作.本文提供三种方法找该种情况下spid的方法.
数据库版本

SQL> select * from v$version;

BANNER
-----------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - Production
PL/SQL Release 11.2.0.3.0 - Production
CORE    11.2.0.3.0      Production
TNS for Linux: Version 11.2.0.3.0 - Production
NLSRTL Version 11.2.0.3.0 - Production

会话1

SQL> select sid, SERIAL#,paddr from v$session where 
  2  sid=(select sid from v$mystat where rownum=1);

       SID    SERIAL# PADDR
---------- ---------- --------
       133         53 35FE16F4

会话2

SQL> select sid, SERIAL#,paddr from v$session where 
  2  sid=(select sid from v$mystat where rownum=1);

       SID    SERIAL# PADDR
---------- ---------- --------
       143         21 35FE2D3C

会话3

SQL> alter system kill session '133,53';

System altered.

SQL> alter system kill session '143,21';

System altered.

SQL> select sid, SERIAL#,paddr,status from v$session where sid in(133,143);

       SID    SERIAL# PADDR    STATUS
---------- ---------- -------- ----------------
       133         53 3547A3F4 KILLED
       143         21 3547A3F4 KILLED

证明alter system kill session后,v$session中的paddr发生了改变,这个时候如果需要找出原来的spid,不能使用v$session.paddr和v$process.addr关联获得

找出kill掉的spid方法1

SQL> select spid, program from v$process 
  2      where program!= 'PSEUDO' 
  3      and addr not in (select paddr from v$session)
  4      and addr not in (select paddr from v$bgprocess)
  5      and addr not in (select paddr from v$shared_server);

SPID                                             PROGRAM
------------------------------------------------ ------------------------------
14260                                            oracle@xifenfei (L001)
14256                                            oracle@xifenfei (L000)
15300                                            oracle@xifenfei (TNS V1-V3)
14179                                            oracle@xifenfei (D000)
15318                                            oracle@xifenfei (TNS V1-V3)
14252                                            oracle@xifenfei (N000)


SQL> !ps -ef|grep 15300|grep -v grep
oracle   15300 14052  0 03:22 ?        00:00:00 oracleora11g (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))

SQL> !ps -ef|grep 15318|grep -v grep
oracle   15318 15315  0 03:22 ?        00:00:00 oracleora11g (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))

找出kill 掉的spid 方法2

SQL> SELECT s.username,s.status,
  2  x.ADDR,x.KSLLAPSC,x.KSLLAPSN,x.KSLLASPO,x.KSLLID1R,x.KSLLRTYP,
  3  decode(bitand (x.ksuprflg,2),0,null,1)
  4  FROM x$ksupr x,v$session s
  5  WHERE s.paddr(+)=x.addr
  6  and bitand(ksspaflg,1)!=0;

USERNAME   STATUS           ADDR       KSLLAPSC   KSLLAPSN KSLLASPO                   KSLLID1R KSLL DE
---------- ---------------- -------- ---------- ---------- ------------------------ ---------- ---- --
           ACTIVE           35FD5990          6         26 14121                             0      1
           ACTIVE           35FD6FD8          1         69 14055                             0      1
           ACTIVE           35FD8620          1         69 14055                             0      1
           ACTIVE           35FD9C68          1         69 14055                             0      1
           ACTIVE           35FDB2B0          8         27 15300                             0      1
           ACTIVE           35FDC8F8         12         36 15300                             0      1
           ACTIVE           35FDDF40          1         69 14055                             0      1
           ACTIVE           35FDF588          1         69 14055                             0      1
           ACTIVE           35FE3860          7         26 14236                             0      1
           ACTIVE           35FE4EA8          1         69 14224                             0      1
           ACTIVE           35FE64F0         63          2 14311                           377 EV   1
           ACTIVE           35FEA7C8          3         26 14155                           258 EV   1
           ACTIVE           35FE9180         59          2 14248                           378 EV   1
           ACTIVE           35FE9CA4         12          2 14603                             0      1
           ACTIVE           35FD64B4          1         69 14055                             0      1
           ACTIVE           35FD7AFC          2         27 14055                             0      1
           ACTIVE           35FD9144          2         27 15300                             0      1
           ACTIVE           35FDA78C          3         26 14171                             0      1
           ACTIVE           35FDBDD4         17          2 15255                             0      1
           ACTIVE           35FDD41C         22         26 14155                             0      1
           ACTIVE           35FDEA64         52         26 14155                             0      1
           ACTIVE           35FE4384          1         69 14224                             0      1
           ACTIVE           35FE59CC          1         69 14224                             0      1
           ACTIVE           35FEB2EC          2          2 14248                             0      1
           ACTIVE           35FEC934         11         26 14121                             0      1
SYS        ACTIVE           35FEF5C4          4         16 14117                             0
                            35FE0BD0          1         69 14055                             0
                            35FE865C          1         69 14117                             0
                            35FE7B38          1         69 14117                             0
                            35FE16F4          1         26 14155                             0
                            35FD4E6C          0          0                                   0
                            35FE00AC          2        279 14117                             0
                            35FE2D3C          0          0                                   0
                            35FE7014          2        335 14117                             0
--挑选username和status为null的会话

SQL> select spid,program from v$process where addr in (
  2  '35FE0BD0',
  3  '35FE865C',
  4  '35FE7B38',
  5  '35FE16F4',
  6  '35FD4E6C',
  7  '35FE00AC',
  8  '35FE2D3C',
  9  '35FE7014'
 10  );

SPID                                             PROGRAM
------------------------------------------------ ------------------------------
                                                 PSEUDO
14179                                            oracle@xifenfei (D000)
14183                                            oracle@xifenfei (S000)
15300                                            oracle@xifenfei (TNS V1-V3)
15318                                            oracle@xifenfei (TNS V1-V3)
14252                                            oracle@xifenfei (N000)
14256                                            oracle@xifenfei (L000)
14260                                            oracle@xifenfei (L001)

8 rows selected.
--同样可以发现spid 15300和15318的进程已经在数据库中被kill掉

找出kill掉的spid方法3(11g特有)

SQL> select  spid,program  from v$process where addr in
  2  (select creator_addr from v$session where sid in(133,143));

SPID                                             PROGRAM
------------------------------------------------ ------------------------------
15300                                            oracle@xifenfei (TNS V1-V3)
15318                                            oracle@xifenfei (TNS V1-V3)

找出kill掉的spid方法4(11g特有)

SQL> select * from V$DETACHED_SESSION;

      INDX PG_NAME                                                             SID    SERIAL#        PID
---------- ------------------------------------------------------------ ---------- ---------- ----------
         0 DEFAULT                                                             143         21         21
         1 DEFAULT                                                             133         53         19

SQL> select spid,program from v$process where pid in(21,19);

SPID                                             PROGRAM
------------------------------------------------ ------------------------------
15300                                            oracle@xifenfei (TNS V1-V3)
15318                                            oracle@xifenfei (TNS V1-V3)

ROW CACHE LOCK等待事件

ROW CACHE LOCK基础说明
ROW CACHE LOCK等待事件是一个共享池相关的等待事件。是由于对于字典缓冲的访问造成的。
P1 – Cache Id
P2 – Mode Held
P3 – Mode Requested

mode 和REQUEST的取值:
KQRMNULL 0 null mode – not locked
KQRMS 3 share mode
KQRMX 5 exclusive mode
KQRMFAIL 10 fail to acquire instance lock

如果是RAC/OPS环境,前台进程发出锁请求,LCK0进程发出锁请求。如果是单实例模式,由前台进程直接发出锁请求。
在RAC/OPS环境下,前台进程会循环等待锁的获取,最多会等待60秒钟。在单实例环境,前台进程会循环1000次,等待3秒钟。PMON进程无论在哪种模式,都会等待5秒钟。
要注意的是单实例模式下和多实例模式下申请该锁调用的模块是不同的(kqrget()- 单实例,kqgigt()- 多实例)。
如果发现这个等待十分高,一般来说可能由于2种原因,一是共享池太小了,需要增加共享池,另外一种情况是SQL分析过于频繁,对于共享池的并发访问量过大。对于任何一种情况,绝大多数情况下加大共享池会有助于降低该等待,不过加大共享池的时候也要注意,并不一定所有的情况下增加共享池都会有明显的效果,特别是对于第二种情况,精确的分析十分重要。另外进一步分析,弄清楚哪些ROW CACHE的等待最为严重,有助于解决问题。

SQL查询

--查询row cache lock等待
select *  from v$session_wait where wait_class = 'row cache lock';

--查询rowcache 名称
select * from v$rowcache where cache# = &p1;

ENQUEUE TYPE
DC_TABLESPACES
Probably the most likely cause is the allocation of new extents. If extent sizes are set low then the application may constantly be requesting new extents and causing contention. Do you have objects with small extent sizes that are rapidly growing? (You may be able to spot these by looking for objects with large numbers of extents). Check the trace for insert/update activity, check the objects inserted into for number of extents.

DC_SEQUENCES
Check for appropriate caching of sequences for the application requirements.

DC_USERS
Deadlock and resulting “WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK!” can occur if a session issues a GRANT to a user, and that user is in the process of logging on to the database.

DC_SEGMENTS
This is likely to be down to segment allocation. Identify what the session holding the enqueue is doing and use errorstacks to diagnose.

DB_ROLLBACK_SEGMENTS
This is due to rollback segment allocation. Just like dc_segments,identify what is holding the enqueue and also generate errorstacks. Remember that on a multi-node system (RAC) the holder may be on another node and so multiple systemstates from each node will be required.

DC_AWR_CONTROL
This enqueue is related to control of the Automatic Workload Repository. As such any operation manipulating the repository may hold this so look for processes blocking these.

Process OS id : xxxxx alive after kill

Process OS id : xxxxx alive after kill警告

Mon May 21 04:55:06 2012
Shutting down instance (immediate)
License high water mark = 373
Mon May 21 04:55:06 2012
Stopping Job queue slave processes
Mon May 21 04:55:06 2012
Job queue slave processes stopped
All dispatchers and shared servers shutdown
Mon May 21 04:55:14 2012
Process OS id : 9922 alive after kill
Errors in file 
Mon May 21 04:55:16 2012
Process OS id : 8159 alive after kill
Errors in file /oracle/admin/resultdb/udump/resultdb_ora_14639.trc
Mon May 21 04:55:17 2012
Process OS id : 8285 alive after kill
Errors in file /oracle/admin/resultdb/udump/resultdb_ora_14639.trc
Mon May 21 04:55:33 2012
ALTER DATABASE CLOSE NORMAL

错误原因

On some platforms it takes some time to kill processes--AIX being one of those platforms

There have been previous reports of shutdown taking time on AIX and after all Oracle waits were taken out of
the picture it was determined to be due to the way the kill command is implemented on that platform. 


Bug 4931101 ERRORS IN ALERT LOG DURING SHUTDOWN

处理建议

Ignore the error  as all processes will be closed and shutdown will complete successfully.

补充说明
本次出问题的数据库是运行在 linux 平台上的 10.2.0.3

主键表插入数据不提交,外键表插入数据被阻塞

有客户和我说:他在含主外键的表中实验发现,在主表数据未提交,然后在外键表插入该数据数据时,出现外键表hang住现象.我开始以为是不同的会话,根据oracle数据库的一致性原则,应该新会话在外键表中不能知道这个记录的存在,直接报错.
可是我实验结果证明:外键表会被阻塞.分析原因如下:
模拟环境

SQL> create table t_p(id number primary key,name varchar2(100));

Table created.

SQL> create table t_f(fid number primary key,pid number, foreign key(pid) references  t_p(id));

Table created.

--会话1
SQL> insert into t_p values(1,'xifenfei');

1 row created.

SQL> commit;

Commit complete.

--会话2
SQL> insert into t_f values(1,1);

1 row created.

SQL> commit;

--会话1
SQL> insert into t_p values(2,'XIFENFEI');

1 row created.

--会话2
SQL> insert into t_f values(2,2);
--hang住

通过实验发现,当主键数据没有提交,然后在外键表中插入该数据外键数据时,该条记录会处于hang住状态(等待),那是什么原因导致了这个等待呢?对会话2做一个10046的trace,发现如下

*** 2012-05-17 17:25:41.757
WAIT #3065187488: nam='enq: TX - row lock contention' ela= 27002895 name|mode=1415053316 usn<<16 
| slot=262151 sequence=588 obj#=-1 tim=1337246741756917
EXEC #3065187488:c=4000,e=27004456,p=0,cr=2,cu=14,mis=0,r=0,dep=0,og=1,
plh=0,tim=1337246741757690
ERROR #3065187488:err=1013 tim=1337246741757751
STAT #3065187488 id=1 cnt=0 pid=0 pos=1 obj=0 op='LOAD TABLE CONVENTIONAL  
(cr=0 pr=0 pw=0 time=12 us)'
WAIT #3065187488: nam='SQL*Net break/reset to client' ela= 581 driver 
id=1650815232 break?=0 p3=0 obj#=-1 tim=1337246741782587
WAIT #3065187488: nam='SQL*Net message to client' ela= 2 driver id=1650815232 
#bytes=1 p3=0 obj#=-1 tim=1337246741782668

通过这个trace发现,是因为TX锁导致了外键表上的插入操作被阻塞.出现该问题的原因
有两种可能:1.两次插入(主键表和外键表分别插入)在主键表上有不兼容锁;2.外键表上有不兼容性锁.

使用oradebug跟踪会话

oradebug setmypid
--EVENT 10704跟踪锁的使用情况
oradebug EVENT 10704 trace name context forever,level 10
--插入数据操作
oradebug EVENT 10704 trace name context off
oradebug TRACEFILE_NAME

跟踪主键表插入数据

*** 2012-05-17 19:05:52.410
ksqgtl *** TM-00012892-00000000 mode=3 flags=0x401 timeout=21474836 ***
ksqgtl: xcb=0x343c0e54, ktcdix=2147483647, topxcb=0x343c0e54
        ktcipt(topxcb)=0x0

*** 2012-05-17 19:05:52.411
ksucti: init txn DID from session DID 
ksqgtl:
        ksqlkdid: 0001-0013-0000000F

*** 2012-05-17 19:05:52.429
*** ksudidTrace: ksqgtl
        ktcmydid(): 0001-0013-0000000F
        ksusesdi:   0000-0000-00000000
        ksusetxn:   0001-0013-0000000F
ksqgtl: RETURNS 0

*** 2012-05-17 19:05:52.430
ksqgtl *** TM-00012894-00000000 mode=3 flags=0x401 timeout=21474836 ***
ksqgtl: xcb=0x343c0e54, ktcdix=2147483647, topxcb=0x343c0e54
        ktcipt(topxcb)=0x0

*** 2012-05-17 19:05:52.430
ksucti: init session DID from txn DID: 
ksqgtl:
        ksqlkdid: 0001-0013-0000000F

*** 2012-05-17 19:05:52.430
*** ksudidTrace: ksqgtl
        ktcmydid(): 0001-0013-0000000F
        ksusesdi:   0000-0000-00000000
        ksusetxn:   0001-0013-0000000F
ksqgtl: RETURNS 0

*** 2012-05-17 19:05:52.431
ksqgtl *** TX-00050019-00000307 mode=6 flags=0x401 timeout=0 ***
ksqgtl: xcb=0x343c0e54, ktcdix=2147483647, topxcb=0x343c0e54
        ktcipt(topxcb)=0x0

*** 2012-05-17 19:05:52.431
ksucti: init session DID from txn DID: 
ksqgtl:
        ksqlkdid: 0001-0013-0000000F

*** 2012-05-17 19:05:52.431
*** ksudidTrace: ksqgtl
        ktcmydid(): 0001-0013-0000000F
        ksusesdi:   0000-0000-00000000
        ksusetxn:   0001-0013-0000000F
ksqgtl: RETURNS 0



SQL> SELECT TO_NUMBER(12892,'xxxxxxx') from dual;

TO_NUMBER(12892,'XXXXXXX')
--------------------------
                     75922

SQL> SELECT TO_NUMBER(12894,'xxxxxxx') from dual;

TO_NUMBER(12894,'XXXXXXX')
--------------------------
                     75924

SQL> select object_name from dba_objects where object_id in(75922,75924);

OBJECT_NAM
----------
T_P
T_F

通过锁使用情况跟踪可以知道,在主键表插入一条记录时,先在主键表获得TM锁,然后外键表获得TM锁,最后主键表获得TX MODE=6的锁。

跟踪外键表插入数据

*** 2012-05-17 19:49:24.912
ksqgtl *** TM-00012892-00000000 mode=3 flags=0x401 timeout=21474836 ***
ksqgtl: xcb=0x343a45e8, ktcdix=2147483647, topxcb=0x343a45e8
        ktcipt(topxcb)=0x0

*** 2012-05-17 19:49:24.912
ksucti: init txn DID from session DID 
ksqgtl:
        ksqlkdid: 0001-0015-00000064

*** 2012-05-17 19:49:24.913
*** ksudidTrace: ksqgtl
        ktcmydid(): 0001-0015-00000064
        ksusesdi:   0000-0000-00000000
        ksusetxn:   0001-0015-00000064
ksqgtl: RETURNS 0

*** 2012-05-17 19:49:24.913
ksqgtl *** TM-00012894-00000000 mode=3 flags=0x401 timeout=21474836 ***
ksqgtl: xcb=0x343a45e8, ktcdix=2147483647, topxcb=0x343a45e8
        ktcipt(topxcb)=0x0

*** 2012-05-17 19:49:24.913
ksucti: init session DID from txn DID: 
ksqgtl:
        ksqlkdid: 0001-0015-00000064

*** 2012-05-17 19:49:24.913
*** ksudidTrace: ksqgtl
        ktcmydid(): 0001-0015-00000064
        ksusesdi:   0000-0000-00000000
        ksusetxn:   0001-0015-00000064
ksqgtl: RETURNS 0

*** 2012-05-17 19:49:24.913
ksqgtl *** TX-0002001f-0000034a mode=6 flags=0x401 timeout=0 ***
ksqgtl: xcb=0x343a45e8, ktcdix=2147483647, topxcb=0x343a45e8
        ktcipt(topxcb)=0x0

*** 2012-05-17 19:49:24.913
ksucti: init session DID from txn DID: 
ksqgtl:
        ksqlkdid: 0001-0015-00000064

*** 2012-05-17 19:49:24.914
*** ksudidTrace: ksqgtl
        ktcmydid(): 0001-0015-00000064
        ksusesdi:   0000-0000-00000000
        ksusetxn:   0001-0015-00000064
ksqgtl: RETURNS 0

*** 2012-05-17 19:49:24.914
ksqgtl *** TX-00050019-00000307 mode=4 flags=0x10021 timeout=21474836 ***
ksqgtl: xcb=0x343a45e8, ktcdix=2147483647, topxcb=0x343a45e8
        ktcipt(topxcb)=0x0

*** 2012-05-17 19:49:24.914
ksucti: init session DID from txn DID: 
ksqgtl:
        ksqlkdid: 0001-0015-00000064

*** 2012-05-17 19:49:24.914
*** ksudidTrace: ksqgtl
        ktcmydid(): 0001-0015-00000064
        ksusesdi:   0000-0000-00000000
        ksusetxn:   0001-0015-00000064

*** 2012-05-17 19:49:24.914
ksqcmi: TX,50019,307 mode=4 timeout=21474836

从这里可以发现:先在主键表和外键表上加上TM锁,然后外键表获得TX MODE=6的锁(这边成功,因为该表上未有其他级别不兼容锁),再需要在主键表上获得TX MODE=4(表结构共享锁+所有记录共享锁),但是这个时候,发现该锁上已经在主键表插入数据未提交的时候,已经含有了TX MODE=6的锁,从而使得TX MODE=4无法获得,从而使得外键表插入数据处于阻塞状态.