ORA-00494 enqueue [CF] held for too long故障分析處理

ORA-00494 enqueue [CF] held for too long故障分析處理

今天接應用人員電話反應，一套備份資料庫在加完資料表空間後出現異常，現象是資料庫能查詢，但是update很慢。

故障處理詳細：
1、查看alert日誌如下：
Thread 1 advanced to log sequence 16541 (LGWR switch)
  Current log# 1 seq# 16541 mem# 0: +DATA/racdb/onlinelog/group_1.262.792077131
  Current log# 1 seq# 16541 mem# 1: +DATA/racdb/onlinelog/group_1.263.792077153
 Fri Sep 12 09:52:51 2014
 Archived Log entry 3480 added for thread 1 sequence 16540 ID 0x10fd7185 dest 1:
 Fri Sep 12 09:59:08 2014
 alter tablespace ALARM_DATA_TBS add datafile '+DATA' size 10g autoextend off
 Fri Sep 12 10:01:11 2014
 Completed: alter tablespace ALARM_DATA_TBS add datafile '+DATA' size 10g autoextend off
 Fri Sep 12 10:06:17 2014
 alter tablespace ALARM_DATA_TBS add datafile '+DATA' size 10g autoextend off
 Fri Sep 12 10:13:44 2014
 minact-scn: useg scan erroring out with error e:12751
 Fri Sep 12 10:17:50 2014
 Errors in file /Oracle/app/oracle/diag/rdbms/racdb/racdb/trace/racdb_m001_18487.trc:
 ORA-12751: cpu time or run time policy violation
 Fri Sep 12 10:22:46 2014
 Errors in file /oracle/app/oracle/diag/rdbms/racdb/racdb/trace/racdb_ora_17431.trc  (incident=362566):
 ORA-00494: 持有入隊 [CF] 的時間過長 (超過 900 秒) (由 'inst 1, osid 18462')
 Incident details in: /oracle/app/oracle/diag/rdbms/racdb/racdb/incident/incdir_362566/racdb_ora_17431_i362566.trc
 Fri Sep 12 10:23:16 2014
 Killing enqueue blocker (pid=18462) on resource CF-00000000-00000000 by (pid=17431)
 by killing session 2140.29719
 Attempt to get Control File Enqueue by USER pid=17431 (mode=X, type=0, timeout=900) is being blocked by inst=1, pid=18462
 Please check inst 1's alert log for more information on the blocker including a possible ORA-00494 and related incident logs
 Fri Sep 12 10:23:57 2014
 minact-scn: useg scan erroring out with error e:12751
 Fri Sep 12 10:23:57 2014
 Sweep [inc][362566]: completed
 Sweep [inc2][362566]: completed
 Fri Sep 12 10:25:10 2014
 Errors in file /oracle/app/oracle/diag/rdbms/racdb/racdb/trace/racdb_lgwr_9336.trc  (incident=360259):
 ORA-00494: enqueue [CF] held for too long (more than 900 seconds) by 'inst 1, osid 18462'
 Incident details in: /oracle/app/oracle/diag/rdbms/racdb/racdb/incident/incdir_360259/racdb_lgwr_9336_i360259.trc
 Fri Sep 12 10:25:40 2014
 Killing enqueue blocker (pid=18462) on resource CF-00000000-00000000 by (pid=9336)
 by killing session 2140.29719
 Attempt to get Control File Enqueue by LGWR pid=9336 (mode=X, type=0, timeout=900) is being blocked by inst=1, pid=18462
 Please check inst 1's alert log for more information on the blocker including a possible ORA-00494 and related incident logs
 Fri Sep 12 10:28:16 2014
 Errors in file /oracle/app/oracle/diag/rdbms/racdb/racdb/trace/racdb_ora_17431.trc  (incident=362567):
 ORA-00494: 持有入隊 [CF] 的時間過長 (超過 900 秒) (由 'inst 1, osid 18462')
 Incident details in: /oracle/app/oracle/diag/rdbms/racdb/racdb/incident/incdir_362567/racdb_ora_17431_i362567.trc
 Fri Sep 12 10:28:46 2014
 Killing enqueue blocker (pid=18462) on resource CF-00000000-00000000 by (pid=17431)
 by terminating the process
 Attempt to get Control File Enqueue by USER pid=17431 (mode=X, type=0, timeout=300) is being blocked by inst=1, pid=18462
 Please check inst 1's alert log for more information on the blocker including a possible ORA-00494 and related incident logs
 Fri Sep 12 10:28:46 2014
 Thread 1 advanced to log sequence 16542 (LGWR switch)
  Current log# 2 seq# 16542 mem# 0: +DATA/racdb/onlinelog/group_2.264.792077173
  Current log# 2 seq# 16542 mem# 1: +DATA/racdb/onlinelog/group_2.265.792077193

 

 2、進入資料庫中手動切換日誌(alter system switch logfile)很慢幾近於不動。

3、分析日誌發現LGWR進程一直在等待CF enqueue，
Dump continued from file: /oracle/app/oracle/diag/rdbms/racdb/racdb/trace/racdb_lgwr_5854.trc
 ORA-00494: enqueue [CF] held for too long (more than 900 seconds) by 'inst 1, osid 7955'

 ========= Dump for incident 380258 (ORA 494) ========
 ----- Beginning of Customized Incident Dump(s) -----
 -------------------------------------------------------------------------------
 ENQUEUE [CF] HELD FOR TOO LONG

 enqueue holder: 'inst 1, osid 7955'
 
 4、進一步分析發現很多次control file sequential read等待，即處於IO等待狀態，
 為什麼出現control file sequential read，可能控制檔案不在了，或者控制檔案或其快照所在目錄掉了。
Current Wait Stack:
  Not in wait; last wait ended 17 min 35 sec ago
 There are 40 sessions blocked by this session.
 Dumping one waiter:
  inst: 1, sid: 1653, ser: 1
  wait event: 'enq: CF - contention'
    p1: 'name|mode'=0x43460005
    p2: '0'=0x0
    p3: 'operation'=0x0
  row_wait_obj#: 4294967295, block#: 0, row#: 0, file# 0
  min_blocked_time: 898 secs, waiter_cache_ver: 407
 Wait State:
  fixed_waits=0 flags=0x21 boundary=0x0/-1
 Session Wait History:
    elapsed time of 17 min 35 sec since last wait
  0: waited for 'control file sequential read'
    file#=0x0, block#=0x12, blocks=0x1
    wait_id=10168 seq_num=10169 snap_id=1
    wait times: snap=0.000352 sec, exc=0.000352 sec, total=0.000352 sec
    wait times: max=infinite
    wait counts: calls=0 os=0
    occurred after 0.000018 sec of elapsed time
  1: waited for 'control file sequential read'
    file#=0x0, block#=0x10, blocks=0x1
    wait_id=10167 seq_num=10168 snap_id=1
    wait times: snap=0.000320 sec, exc=0.000320 sec, total=0.000320 sec
    wait times: max=infinite
    wait counts: calls=0 os=0
    occurred after 0.000018 sec of elapsed time

 

 5、進入RMAN中查看控制檔案備份路徑均為/oradata/racdbdb_rman_bak目錄，詳細如下：
 RMAN> show all;

使用目標資料庫控制檔案替代恢複目錄
db_unique_name 為 racdb 的資料庫的 RMAN 配置參數為:
CONFIGURE RETENTION POLICY TO REDUNDANCY 1;
 CONFIGURE BACKUP OPTIMIZATION OFF; # default
 CONFIGURE DEFAULT DEVICE TYPE TO DISK; # default
 CONFIGURE CONTROLFILE AUTOBACKUP OFF;
 CONFIGURE CONTROLFILE AUTOBACKUP FORMAT FOR DEVICE TYPE DISK TO '/oradata/racdbdb_rman_bak/conf_%T_%F';
 CONFIGURE DEVICE TYPE DISK PARALLELISM 1 BACKUP TYPE TO BACKUPSET; # default
 CONFIGURE DATAFILE BACKUP COPIES FOR DEVICE TYPE DISK TO 1; # default
 CONFIGURE ARCHIVELOG BACKUP COPIES FOR DEVICE TYPE DISK TO 1; # default
 CONFIGURE MAXSETSIZE TO UNLIMITED; # default
 CONFIGURE ENCRYPTION FOR DATABASE OFF; # default
 CONFIGURE ENCRYPTION ALGORITHM 'AES128'; # default
 CONFIGURE COMPRESSION ALGORITHM 'BASIC' AS OF RELEASE 'DEFAULT' OPTIMIZE FOR LOAD TRUE ; # default
 CONFIGURE ARCHIVELOG DELETION POLICY TO NONE; # default
 CONFIGURE SNAPSHOT CONTROLFILE NAME TO '/oradata/racdbdb_rman_bak/snap_racdb.ctl';

 6、查看目錄發現/oradata目錄掉了
 bash-3.00$ df -h
 Filesystem            size  used  avail capacity  Mounted on
 /dev/dsk/c0t0d0s0      96G    47G    48G    50%    /
 /devices                0K    0K    0K    0%    /devices
 ctfs                    0K    0K    0K    0%    /system/contract
 proc                    0K    0K    0K    0%    /proc
 mnttab                  0K    0K    0K    0%    /etc/mnttab
 swap                    87G  1.9M    87G    1%    /etc/svc/volatile
 objfs                    0K    0K    0K    0%    /system/object
 sharefs                  0K    0K    0K    0%    /etc/dfs/sharetab
 fd                      0K    0K    0K    0%    /dev/fd
 swap                    87G  120K    87G    1%    /tmp
 swap                    87G    80K    87G    1%    /var/run
 /dev/dsk/c0t0d0s4      38G    27G    11G    72%    /export/home
 /dev/dsk/c0t1d0s3      77G    41G    35G    54%    /oracle

 7、通過修改控制檔案備份路徑，資料庫恢複正常。
  RMAN> CONFIGURE SNAPSHOT CONTROLFILE NAME TO '/oracle/app/oracle/product/11.2.0/db_1/dbs/snap_racdb.ctl';
  RMAN> show all;

 db_unique_name 為 racdb 的資料庫的 RMAN 配置參數為:
CONFIGURE RETENTION POLICY TO REDUNDANCY 1;
 CONFIGURE BACKUP OPTIMIZATION OFF; # default
 CONFIGURE DEFAULT DEVICE TYPE TO DISK; # default
 CONFIGURE CONTROLFILE AUTOBACKUP ON;
 CONFIGURE CONTROLFILE AUTOBACKUP FORMAT FOR DEVICE TYPE DISK TO '/oracle/app/oracle/product/11.2.0/db_1/dbs/conf_%T_%F';
 CONFIGURE DEVICE TYPE DISK PARALLELISM 1 BACKUP TYPE TO BACKUPSET; # default
 CONFIGURE DATAFILE BACKUP COPIES FOR DEVICE TYPE DISK TO 1; # default
 CONFIGURE ARCHIVELOG BACKUP COPIES FOR DEVICE TYPE DISK TO 1; # default
 CONFIGURE MAXSETSIZE TO UNLIMITED; # default
 CONFIGURE ENCRYPTION FOR DATABASE OFF; # default
 CONFIGURE ENCRYPTION ALGORITHM 'AES128'; # default
 CONFIGURE COMPRESSION ALGORITHM 'BASIC' AS OF RELEASE 'DEFAULT' OPTIMIZE FOR LOAD TRUE ; # default
 CONFIGURE ARCHIVELOG DELETION POLICY TO NONE; # default
 CONFIGURE SNAPSHOT CONTROLFILE NAME TO '/oracle/app/oracle/product/11.2.0/db_1/dbs/snap_racdb.ctl';