ORA-00494,enqueue [CF]故障诊断

  这次事故还要追述到2个月前,当时客户发现数据库宕机了,从客户发过来到截图可以看到数据库在hang死的时候报ORA-00494:enqueue[CF] held for too long(more than 900 seconds)错误,同时伴随着这个日志还有一个trace,可惜当时空间满了,这个trace被清理掉了.关于这次错误,也前前后后去了几个人去看了,因为没有那个trace文件,所以都无法断定究竟是什么引起的. 我看了看这个问题,也是同样的答案.不过客户还是想听听我的解释和意见,那么我就来分析下这个问题.首先我觉得我们要知道什么是enqueue [CF].那么究竟什么是CF enqueue?

The CF enqueue is a Control File enqueue  and happens during parallel access to the control files.  The CF enqueue can be seen during any action that requires reading the control file, such as redo log archiving, redo log switches and begin backup commands.

  可以看到CF enqueue是控制文件的队列, 发生在并行访问控制文件的时候,它的产生主要是下面几种情况:

1.redo archiveing
2.redo log switches
3.rman backup

  那么在CF的队列锁被持有了900秒后,其他进程无法获取的话,oracle就开始杀进程,如果杀到了关键的后台进程,最终就会引起宕机.那么了解到了这一点后,我们就要关注究竟是什么进程持有了CF enqueue.不过我们单从alter日志中是看不出任何问题的,我们需要trace来辅助帮我们诊断,可惜我们没trace,不过我在MOS上找到了一个案例.这个案例可以供我们学一学.
查询 “‘enq: CF – contention’ ” in the systemstate dump PROCESS

PROCESS 5:
----------------------------------------
SO: 70000064b55a4d8, type: 2, owner: 0, flag: INIT/-/-/0x00
...
OSD pid info: Unix process pid: 27127876, image: oracle@a9pvdb002 (LGWR)
...
waiting for 'enq: CF - contention' blocking sess=0x70000064f750138 seq=50830 wait_time=0 seconds since wait started=0
name|mode=43460005, 0=0, operation=0
...
(enqueue) CF-00000000-00000000    DID: 0001-0005-00000007
lv: 00 aa e7 5c 00 00 00 00 00 00 00 00 00 00 00 00  res_flag: 0x2
res: 0x70000064f8be818, req: SSX, lock_flag: 0x0
...

  这里我们可以发现LGWR进程正在等待CF enqueue,并请求SSX mode的锁定.同时,<<name|mode=43460005, 0=0, operation=0>>这个告诉我们队列的类型,还有ID1和ID2的值.ASCII值4346刚好是CF,而ID1和ID2都是0.后面的enqueue resource就被格式化成了CF-00000000-00000000 . 接下来我们在systemstate dump中搜索关键字”CF-00000000-00000000″,我们会发现持有S模式锁的进程,因为有进程以S模式持有了CF enqueue.所以就导致LGWR一直处于等待状态.LGWR无法获取enqueue resource,要一直等待持有者结束job和释放这个enqueue,

PROCESS 1686:
...
client info: rman channel=FX_ORA_SBT_TAPE3
application name: rman@a9pvdb002 (TNS V1-V3), hash value=0    <== RMAN process holds the CF enqueue
action name: 0002732 STARTED65, hash value=1040409729
waiting for 'control file sequential read' blocking sess=0x0 seq=23783 wait_time=0 seconds since wait started=0
file#=0, block#=8aa, blocks=1
...
SO: 7000006498a3988, type: 5, owner: 7000005fe0ed380, flag: INIT/-/-/0x00
(enqueue) CF-00000000-00000000    DID: 0001-0696-00000109
lv: 00 aa e7 5c 00 00 00 00 00 00 00 00 00 00 00 00  res_flag: 0x2
res: 0x70000064f8be818, mode: S, lock_flag: 0x0   <== CF enqueue is held up in Shared mode
own: 0x70000064f750138, sess: 0x70000064f750138, proc: 0x70000064a5ec7f0, prv: 0x70000064f8be828
...

  在这里我们可以看到阻塞的进程是RMAN,并且上了shared的锁定.此时进程会读取控制文件一段时间,进程将不会释放掉enqueue resource.此时明显的等待事件就是”control file sequential read”.RMAN备份进程将顺序的读取控制文件,操作一段时间.因此,将以S mode的方式持有CF enqueue resource,直到释放.

  上面的例子我们看到阻塞进程是RMAN.类似还有一些可能会是LGWR,CKPT等进程.许多问题,我们会发现阻塞进程是CKPT,引起这种情况可能是日志切换和redolog的问题,此时我们需要对这方面进行调整.

分享到: 更多

Post a Comment

Your email is never published nor shared. Required fields are marked *