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

今天下午接到业务报障,系统出现问题,可能是数据库的问题
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,系统恢复。问题出在了开发人员在业务高峰期批量更新数据,高峰时间段批量更新数据是大忌!!!!
  • 1
    点赞
  • 0
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值