Enq: RO – fast object reuse问题处理

应用会话在ybtdb2数据库执行Truncate操作无法成功,数据库出现异常等待事件“enq: RO – fast object reuse”。出现异常等待期间数据库主机资源使用正常。为了进一步分析问题,对该进程做了errorstack,errorstack trace文件如下:

SO: 70000050fc93af8, type: 4, owner: 70000050f8d63d8, flag: INIT/-/-/0x00
    (session) sid: 1103 trans: 7000004f99b71a8, creator: 70000050f8d63d8, flag: (100041) USR/- BSY/-/-/-/-/-
              DID: 0002-0227-00001ECA, short-term DID: 0002-0227-00001ECB
              txn branch: 0
              oct: 170, prv: 0, sql: 7000004cd3ff508, psql: 7000004cd3ff508, user: 35/YBT
    service name: ybtdb
    O/S info: user: ybtcenter, term: , ospid: 15266, machine: ybtapp2
              program: loadidsdata@ybtapp2 (TNS V1-V3)
    client info: 10.190.115.2
    application name: loadidsdata@ybtapp2 (TNS V1-V3), hash value=227635376
    waiting for 'enq: RO - fast object reuse' blocking sess=0x0 seq=15114 wait_time=0 seconds since wait started=278032
                name|mode=524f0006, 2=20227, 0=1
    Dumping Session Wait History
     for 'enq: RO - fast object reuse' count=1 wait_time=488301
                name|mode=524f0006, 2=20227, 0=1
     for 'enq: RO - fast object reuse' count=1 wait_time=488295
                name|mode=524f0006, 2=20227, 0=1
     for 'enq: RO - fast object reuse' count=1 wait_time=488299
                name|mode=524f0006, 2=20227, 0=1
     for 'enq: RO - fast object reuse' count=1 wait_time=488293
                name|mode=524f0006, 2=20227, 0=1
     for 'enq: RO - fast object reuse' count=1 wait_time=488292
                name|mode=524f0006, 2=20227, 0=1
     for 'enq: RO - fast object reuse' count=1 wait_time=488290
                name|mode=524f0006, 2=20227, 0=1
     for 'enq: RO - fast object reuse' count=1 wait_time=488291
                name|mode=524f0006, 2=20227, 0=1
     for 'enq: RO - fast object reuse' count=1 wait_time=488292
                name|mode=524f0006, 2=20227, 0=1
     for 'enq: RO - fast object reuse' count=1 wait_time=488296
                name|mode=524f0006, 2=20227, 0=1
     for 'enq: RO - fast object reuse' count=1 wait_time=488299
                name|mode=524f0006, 2=20227, 0=1
    temporary object counter: 0

可以看到该会话一直在等待enq: RO – fast object reuse,且等待时间较长。

----- PL/SQL Call Stack -----
  object      line  object
  handle    number  name
7000004cde152e0       909  package body SYS.DBMS_SYS_SQL
7000004cde15990        39  package body SYS.DBMS_SQL
70000050e323ca8         7  procedure YBT.TRUNCATE_TABLE
----- Call Stack Trace -----
ksliwat+06c0         bl       skgpwwait            FFFFFFFFFFEB1F0 ? 000000000 ?
                                                   103AC4EF8 ? 000000000 ?
                                                   FFFFFFFFFFEB1F0 ?
kslwaitns_timed+002  bl       ksliwat              000000000 ? 000000000 ?
4                                                  000000000 ? 000000000 ?
                                                   000000000 ? 000000000 ?
                                                   000000000 ? 000000000 ?
kskthbwt+022c        bl       kslwaitns_timed      000000004 ? 000000000 ?
                                                   FFFFFFFFFFEBE20 ? 000000000 ?
                                                   3784759F126D58 ? 000000061 ?
                                                   FFFFFFFFFFEB530 ? 000000000 ?
kslwait+00f4         bl       kskthbwt             3200000032 ? 4900000049 ?
                                                   000000000 ? 0524F0006 ?
                                                   000020227 ? 000000001 ?
                                                   E00000000000E ?
                                                   6955278669552786 ?
kjuscv+0ad0          bl       kslwait              FFFFFFFFFFEB704 ? 200000003 ?
                                                   5000001101960E8 ? 700000000 ?
                                                   000000020 ? 000000000 ?
ksipcon+041c         bl       kjuscv               700000509346A00 ?
                                                   50000010564B0D0 ?
                                                   61FFFFFFBF ? 0FFFFFEFF ?
                                                   FFFFFFFFFFEBE20 ? 000000000 ?
                                                   000000000 ? FFFFFFFFFFEBD4C ?
ksqcmi+0e14          bl       ksipcon              10564B8E4 ? 10564B8F0 ?
                                                   10564B928 ? 10564B914 ?
                                                   10564B908 ? 080000004 ?
                                                   10564B940 ? 10564B934 ?
ksqcnv+030c          bl       ksqcmi               70000050B0D3DF8 ? 600000000 ?
                                                   FFFF0011BD18 ?
                                                   147AE140B4A3EC8 ?
                                                   FFFFFFFFFFED260 ?
                                                   FFFFFFFFFFED4B0 ? 000000004 ?
                                                   110001248 ?
ksqcov+0034          bl       ksqcnv               FFFFFFFFFFED84C ? 000000000 ?
                                                   FFFFFFFFFFED844 ? 000000001 ?
                                                   000000001 ? 000020227 ?
                                                   00147AE14 ?
kcbo_reuse_obj+0880  bl       01F94504             
kcbrbo+00bc          bl       01F93AE0             
ktsstrn_segment+0f6  bl       kcbrbo               FFFFFFFFFFEE0C0 ? 000000000 ?
c                                                  7000004BD28E470 ?
kkbtts_trunc_tbl_se  bl       ktsstrn_segment      FFFFFFFFFFEE0C0 ? 02CC03F1D ?
g+04b8                                             000000000 ? 0FFFEE268 ?
                                                   064232020 ? 064232020 ?
kkbtrn+13f8          bl       kkbtts_trunc_tbl_se  047548A48 ? 7000004BD28E318 ?
                              g                    000000000 ? 1FFFEE7A0 ?
                                                   7000004D42A5D88 ?
                                                   700000443A513F0 ?
                                                   3000000000003 ?
opiexe+317c          bl       kkbtrn

通过观察堆栈发现是在执行Truncate语句,执行过程中采取了下列调用。

kslwaitns_timed -> kskthbwt -> kslwait -> kjuscv -> ksipcon -> ksqcmi -> ksipcon -> ksqcnv -> ksqcov -> kcbo_reuse_obj -> kcbrbo -> ktsstrn_segment -> kkbtts_trunc_tbl_se

通过metalink note进行搜索,找到了文档Process waits too long for ‘enq: RO – fast object reuse’. Cause: CKPT Process Bug 7385253 (文档 ID 785232.1)里面的文档中的Call Stack和我们的类似。文档中指出的Call Stack如下所示:

kslwaitns_timed kskthbwt kslwait ksqcmi ksqcnv ksqcov kcbo_reuse_obj kcbrbo ..etc

同时可以观察队列资源的情况。

----------resource 0x7000004c3fb9410----------------------
resname       : [0x20227][0x1],[RO]
GRANTED_Q :
lp 70000050bce5f40 gl KJUSERCR rp 7000004c3fb9410 [0x20227][0x1],[RO]
  master 1 gl owner 70000050cd9d4d0 possible pid 2064446 xid 2001-0013-00000005 bast 0 rseq 15 mseq 0 history 0x95514955
  open opt KJUSERDEADLOCK  KJUSERIDLK 
CONVERT_Q: 
lp 700000509346a00 gl KJUSERPW rl KJUSEREX rp 7000004c3fb9410 [0x20227][0x1],[RO]
  master 1 gl owner 70000050fc93af8 possible pid 1159360 xid 2022-0227-00001ECA bast 0 rseq 15 mseq 0 history 0x5514955a
  convert opt KJUSERGETVALUE KJUSERNODEADLOCKWAIT KJUSERNODEADLOCKBLOCK

可以看到该队列和pid 2064446和pid 1159360有关。

SO: 70000050b0d3dd8, type: 5, owner: 700000481adb5a0, flag: INIT/-/-/0x00
        (enqueue) RO-00020227-00000001  DID: 0002-0227-00001ECA
        lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  res_flag: 0x3
        res: 0x70000050a15e320, mode: SSX, req: X, lock_flag: 0x0
        own: 0x70000050fc93af8, sess: 0x70000050fc93af8, proc: 0x70000050f8d63d8, prv: 0x70000050a15e350
        slk: 0x700000509346a00

possible owner[19.2064446] on resource RO-00020227-00000001

继续分析可以发现pid 1159360以X模式在请求持有队列RO-00020227-00000001。pid 1159360正是发起truncate的会话进程。而队列RO-00020227-00000001是被pid 2064446所持有的。而通过查询2064446发现是ckpt进程。

[jtdba@sxybtdb2 ~]$ps -ef | grep ckpt
   jtdba 1581064 2146438   0 14:30:52  pts/0  0:00 grep ckpt 
  oracle 2064446       1   0   Dec 21      - 28:02 ora_ckpt_ybtdb2

问题解决
建议安装单独的patch 7385253来规避这个问题.
建议将数据库升级到11.2来规避此问题.11.2以上的版本才修复了该问题.

分享到: 更多