一次大量enq: TX - row lock contention锁等待的问题

原创 2012年09月28日 17:05:02
今天下午接到业务报障,系统出现问题,可能是数据库的问题
1,登录系统,查看等待事件,大量row lock

6:12:58]
[16:12:58]   SID    SERIAL# OSUSER   USERNAME SVRPROC                  SQL_HASH_VALUE EVENT                                             P1         P2         P3
[16:12:58]------ ---------- -------- -------- ------------------------ -------------- ------------------------------ --------------------- ---------- ----------
[16:12:58]   245       4637 app    SOi      41353726                     3961605653 db file sequential read                          226     253846          1
[16:12:58]  3645      58373 app    SOi      61604288                     1523472697 db file sequential read                          178    3443786          1
[16:12:58]  5651      26047 app    PAR    64291328                     2455471834 db file sequential read                          142    2712414          1
[16:12:58] 13207       5781 app    SOi      62915316                     3349830783 db file sequential read                          211    1462130          1
[16:12:58] 10198      64603 app    PAR    45679292                     2510471152 db file sequential read                           91    2141228          1
[16:12:58] 11528       8197 app    PAR    51708698                     2284416154 db file sequential read                          126    1683178          1
[16:12:58]  8863      53455 baoyb    AIM    16319376                     1467486395 db file sequential read                          115    2078933          1
[16:12:58]     1      59191 app    SOi      46072062                     2644787661 enq: TX - row lock contention             1415053318   21889041      50009
[16:12:58]    22      26111 app    SOi      48694114                     3874015681 enq: TX - row lock contention             1415053318   21889041      50009
[16:12:58]    39      38595 AIC    SOi      7210748                       208342339 enq: TX - row lock contention             1415053318   21889041      50009
[16:12:58]    62      56753 AIC    SOi      29426814                     1088173244 enq: TX - row lock contention             1415053318   21889041      50009
[16:12:58]
[16:12:58]   SID    SERIAL# OSUSER   USERNAME SVRPROC                  SQL_HASH_VALUE EVENT                                             P1         P2         P3
[16:12:58]------ ---------- -------- -------- ------------------------ -------------- ------------------------------ --------------------- ---------- ----------
[16:12:58]    66      42397 app    SOi      48366550                     1088173244 enq: TX - row lock contention             1415053318   32047109      25967
[16:12:58]   189      52823 AIC    SOi      38404948                      208342339 enq: TX - row lock contention             1415053318   21889041      50009
[16:12:58]   212        451 app    SOi      42402934                      673329617 enq: TX - row lock contention             1415053318   21889041      50009
[16:12:58]   232      55865 app    SOi      21956094                      673329617 enq: TX - row lock contention             1415053318   21889041      50009
[16:12:58]   240        701 AIC    SOi      42991652                      208342339 enq: TX - row lock contention             1415053318   21889041      50009
[16:12:58]   247       6333 app    SOi      5375522                      3538716681 enq: TX - row lock contention             1415053318   21889041      50009
[16:12:58]   388      17499 app    SOi      42140914                     1763411819 enq: TX - row lock contention             1415053318   21889041      50009
[16:12:58]   389      50591 app    SOi      33292644                      208342339 enq: TX - row lock contention  


2,使用锁等待的脚本查看,holder比较多,难以判断根源的holder

[16:16:03]SESS                                                     ID1        ID2      LMODE    REQUEST TY
[16:16:03]------------------------------------------------- ---------- ---------- ---------- ---------- --
[16:16:03]Holder:  7205                                       21037088      51133          6          0 TX
[16:16:03]Waiter: 14692                                       21037088      51133          0          6 TX
[16:16:03]Waiter: 6246                                        21037088      51133          0          6 TX
[16:16:03]Waiter: 1190                                        21037088      51133          0          6 TX
[16:16:03]Holder:  12643                                      21299226      52395          6          0 TX
[16:16:03]Waiter: 3820                                        21299226      52395          0          6 TX
[16:16:03]Waiter: 10197                                       21299226      52395          0          6 TX
[16:16:03]Waiter: 1926                                        21299226      52395          0          6 TX
[16:16:03]Holder:  7169                                       21561365      54540          6          0 TX
[16:16:03]Waiter: 13929                                       21561365      54540          0          6 TX
[16:16:03]Waiter: 1562                                        21561365      54540          0          6 TX
[16:16:03]
[16:16:03]SESS                                                     ID1        ID2      LMODE    REQUEST TY
[16:16:03]------------------------------------------------- ---------- ---------- ---------- ---------- --
[16:16:03]Waiter: 9080                                        21561365      54540          0          6 TX
[16:16:03]Holder:  8863                                       21889041      50009          6          0 TX
[16:16:03]Waiter: 14914                                       21889041      50009          0          6 TX
[16:16:03]Waiter: 14911                                       21889041      50009          0          6 TX
[16:16:03]Waiter: 14902                                       21889041      50009          0          6 TX
[16:16:03]Waiter: 14882                                       21889041      50009          0          6 TX
[16:16:03]Waiter: 14872                                       21889041      50009          0          6 TX
[16:16:03]Waiter: 14865                                       21889041      50009          0          6 TX
[16:16:03]Waiter: 14721                                       21889041      50009          0          6 TX


3,由于是rac,做一个全局的HANGANALYZE
[16:16:57]SQL> ORADEBUG setmypid
[16:16:57]Statement processed.
[16:17:02]SQL>  ORADEBUG setinst all
[16:17:03]Statement processed.
[16:17:07]SQL> ORADEBUG -g def hanganalyze 3
[16:17:26]Hang Analysis in /oracle/diag/rdbms/yydb/yydb1/trace/yydb1_diag_4260840.trc
4,此时被阻塞的语句是大量update
16:17:35]SQL_ID        PCTLOAD  CPU OTHER   IO SQL_TEXT
[16:17:35]------------- ------- ---- ----- ---- ----------------------------------------------------------------------------------------------------
[16:17:35]9bxujnufu8hfd      17    0   100    0 update INS__100 set STATE = :1 ,DONE_DATE = :2  where   ROWID = :3
[16:17:35]8vcrwd10dsd5w      15    0   100    0 update INS__101 set STATE = :1 ,DONE_DATE = :2  where   ROWID = :3
[16:17:35]777xsjn66q3a3      10    0   100    0 update INS__102 set STATE = :1 ,DONE_DATE = :2  where   ROWID = :3
[16:17:35]3xng1922jhqdx      10    0   100    0 update INS__103 set STATE = :1 ,DONE_DATE = :2  where   ROWID = :3
[16:17:35]5g2gyxwn24cfj       8    0   100    0 update INS__100 set OP_ID = :1 ,STATE = :2 ,DONE_DATE = :3  where   ROWID = :4
[16:17:35]ac17casyksfka       5    0   100    0 update INS__100 set EXPIRE_DATE = :1 ,EFFECTIVE_DATE = :2 ,STATE = :3 ,COUNTY_CODE = :4 ,DONE_DA
[16:17:35]7pdp5zfbc7bh5       4    0   100    0 update INS__104 set STATE = :1 ,DONE_DATE = :2  where   ROWID = :3
[16:17:35]024cfqtnjr1vb       3    0   100    0 update INS__103 set EXPIRE_DATE = :1 ,EFFECTIVE_DATE = :2 ,OP_ID = :3 ,STATE = :4 ,COUNTY_CODE =
[16:17:35]24m4b9jfqn2zm       2    0   100    0 update INS__101 set EXPIRE_DATE = :1 ,EFFECTIVE_DATE = :2 ,OP_ID = :3 ,STATE = :4 ,COUNTY_CODE =
[16:17:35]8vm3vv2t6ymv6       2    0   100    0 update INS__102 set STATE = :1 ,OP_ID = :2 ,DONE_DATE = :3  where   ROWID = :4
[16:17:35]cnq4y75v772af       2    0   100    0 update INS__103 set EXPIRE_DATE = :1 ,EFFECTIVE_DATE = :2 ,STATE = :3 ,COUNTY_CODE = :4 ,DONE_DA

5,查看HANGANALYZE log的内容,339 sessions被sid=8863的进程阻塞
.......
Chains most likely to have caused the hang:
 [a] Chain 1 Signature: 'db file scattered read'<='enq: TX - row lock contention'
     Chain 1 Signature Hash: 0x13c8fc65
 [b] Chain 2 Signature: 'db file scattered read'<='enq: TX - row lock contention'
     Chain 2 Signature Hash: 0x13c8fc65
 [c] Chain 3 Signature: 'db file scattered read'<='enq: TX - row lock contention'
     Chain 3 Signature Hash: 0x13c8fc65

===============================================================================
Non-intersecting chains:

-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
    Oracle session identified by:
    {
                instance: 1 (yydb.yydb1)
                   os id: 46072062
              process id: 320, oracle@scyydb1
              session id: 1
        session serial #: 59191
    }
    is waiting for 'enq: TX - row lock contention' with wait info:
    {
                      p1: 'name|mode'=0x54580006
                      p2: 'usn<<16 | slot'=0x14e0011
                      p3: 'sequence'=0xc359
            time in wait: 73 min 18 sec
           timeout after: never
                 wait id: 5488
                blocking: 0 sessions
             current sql: update INS_ set STATE = :1 ,DONE_DATE = :2  where   ROWID = :3
             short stack: ksedsts()+644<-ksdxfstk()+44<-ksdxcb()+3384<-sspuser()+116<-47dc<-sskgpwwait()+32<-skgpwwait()+180<-ksliwat()+11032<-kslwaitctx()+1
80<-kjusuc()+3652<-ksipgetctxi()+1892<-ksqcmi()+21888<-ksqgtlctx()+2904<-ksqgelctx()+660<-ktuGetTxForXid()+184<-ktcwit1()+456<-IPRA.$kdddgb()+6860<-kdddgb()+
96<-kdusru()+8516<-updrowFastPath()+1192<-qerupFetch()+2596<-updaul()+1100<-updThreePhaseExe()+336<-updexe()+344<-opiexe()+14476<-kpoal8()+4616<-opiodr()+720
<-ttcpip()+1028<-opitsk()+1508<-opiino()+940<-opiodr()+720<-opidrv()+1132<
            wait history:
              * time between current wait and wait #1: 0.000401 sec
              1.       event: 'SQL*Net message from client'
                 time waited: 0.000596 sec
                     wait id: 5487            p1: 'driver id'=0x28444553
                                              p2: '#bytes'=0x1
              * time between wait #1 and #2: 0.000008 sec
              2.       event: 'SQL*Net message to client'
                 time waited: 0.000002 sec
                     wait id: 5486            p1: 'driver id'=0x28444553
                                              p2: '#bytes'=0x1
              * time between wait #2 and #3: 0.000117 sec
              3.       event: 'db file sequential read'
                 time waited: 0.007607 sec
                     wait id: 5485            p1: 'file#'=0xa2
                                              p2: 'block#'=0x112360
                                              p3: 'blocks'=0x1
    }
    and is blocked by
 => Oracle session identified by:
    {
                instance: 1 (yydb.yydb1)
                   os id: 16319376
              process id: 1567, oracle@scyydb1
              session id: 8863
        session serial #: 53455
    }
    which is waiting for 'db file scattered read' with wait info:
    {
                      p1: 'file#'=0xc4
                      p2: 'block#'=0x26d37c
                      p3: 'blocks'=0x10
            time in wait: 0.000000 sec
           timeout after: never
                 wait id: 6304859
                blocking: 339 sessions
             current sql: update so1.INS__ins t set t.expire_date=to_date('20121231 23:59:59','yyyymmdd hh24:mi:ss') where (t.offer_inst_id,t.use
r_id) in
(select a.offer_inst_id,a.user_id from wlanCPss2 a )
             short stack: ksedsts()+644<-ksdxfstk()+44<-ksdxcb()+3384<-sspuser()+116<-47dc<-poll()+12<-sntpoltsts()+884<-snttmoredata()+52<-nsmore2recv()+246
0<-nioqts()+6588<-ksuttctest()+128<-updrow()+16292<-qerupFetch()+856<-updaul()+1100<-updThreePhaseExe()+336<-updexe()+344<-opiexe()+14476<-kpoal8()+4616<-opi
odr()+720<-ttcpip()+1028<-opitsk()+1508<-opiino()+940<-opiodr()+720<-opidrv()+1132<-sou2o()+136<-opimai_real()+608<-ssthrdmain()+268<-main()+204<-__start()+1
12

6,通过sid定位用户信息,确定为有人用plsql在运行上述sql

SESSION_ID SAMPLE_TIME                                                                 PROGRAM                                          MACHINE
---------- --------------------------------------------------------------------------- ------------------------------------------------ ---------------

      8863 28-SEP-12 03.49.13.605 PM                                                   plsqldev.exe                                     XX-VM-RDS1


                                                                                                                                       
7,杀掉了问题sid,系统恢复。问题出在了开发人员在业务高峰期批量更新数据,高峰时间段批量更新数据是大忌!!!!

一次数据库相关操作卡住的排查--enq: TX - row lock contention

问题描述:某日客户来电某HR系统排值班表的操作一直HANG住,一直无法完成。 这种问题,主要思路是围绕查看此操作因何HANG住。 常见的严重的HANG住有DB方面的AUDIT无空间、归档空间满以及...
  • q947817003
  • q947817003
  • 2015年08月24日 16:45
  • 3682

enq: TX - row lock contention 参数P1,P2,P3的讲解

enq: TX - row lock contention等待事件的三个参数如下,其中P2和P3可以定位XID
  • robo23
  • robo23
  • 2015年03月18日 21:11
  • 1505

enq: TX - row lock contention 等待事件

OS环境:windows server 2008 64位数据库版本:11.2.0今天在使用rman备份的时候随意的查看了一下等待事件,除了了我们现在系统遇到的IO瓶颈外,还额外的发了enq: TX -...
  • SongYang_Oracle
  • SongYang_Oracle
  • 2011年05月20日 09:55
  • 25992

[Oracle] enq: TX - row lock contention 优化案例

根据开发反馈,最近每天早上7:30应用会报警,应用的日志显示数据库连接池满了,新的连接被拒绝。 首先,我做了ASH报告(报告区间:7:25 ~ 7:35),从ASH的等待事件发现enq: TX - r...
  • u010415792
  • u010415792
  • 2014年06月04日 09:28
  • 2581

enq: TX - row lock contention故障处理一则

一个很简单的问题,之所以让我对这个问题进行总结,一是因为没我想象的简单,在处理的过程中遇到了一些磕磕碰碰,甚至绕了一些弯路,二是引发了我对故障处理时的一些思考。...
  • oradh
  • oradh
  • 2014年06月20日 14:18
  • 2348

enq: TX - row lock contention等待事件

http://www.oracleonlinux.cn/2012/11/resolve-row-lock-contention/ enq: TX - row lock contention 等待事件...
  • zhengwei125
  • zhengwei125
  • 2016年06月12日 12:00
  • 865

等待事件enq TX row lock contention分析

在Oracle数据库性能报告AWRRPT分析时,发现top 5等待事件第一位的是enq: TX - row lock contention。这个等待事件消耗了绝大多数的CPU资源,导致系统整理性能下降...
  • cunxiyuan108
  • cunxiyuan108
  • 2015年01月20日 11:03
  • 1656

AWR报表-enq: TX - row lock contention事件解决方法

enq: TX - row lock contention事件是锁等待事件,今天我要做一个例子来模拟这类事件的出现。      测试环境如下:            现在我们进行测试,用1个会话ses...
  • suyishuai
  • suyishuai
  • 2014年03月03日 15:05
  • 1026

如何找出引起enq:TX - row lock contention的记录

V$SESSION中有如下4个列,用来记录当发生enq:TX-row lock contention的时候, 导致挂起的行。  ROW_WAIT_OBJ#           ...
  • cunxiyuan108
  • cunxiyuan108
  • 2015年01月20日 11:04
  • 928

Oracle enq: TX contention 和 enq: TM contention 等待事件说明【转自dave偶像大神】

原文链接: http://blog.csdn.net/tianlesoftware/article/details/6526238 和Oracle性能优化密切相关的一些知识参考如下Blog...
  • lovedieya
  • lovedieya
  • 2014年02月27日 01:53
  • 870
内容举报
返回顶部
收藏助手
不良信息举报
您举报文章:一次大量enq: TX - row lock contention锁等待的问题
举报原因:
原因补充:

(最多只允许输入30个字)