ORA-00494 enqueue [CF] held for too long troubleshooting

ORA-00494 enqueue [CF] held for too long troubleshooting

Today, the application staff responded by phone that an exception occurred after a backup database was added to the tablespace. This problem occurs when the database can be queried, but the update process is slow.

Detailed troubleshooting:
1. view the alert Log as follows:
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/trace/racdb_m0020.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/trace/racdb_ora_17431.trc (incident = 362566 ):
ORA-00494: Long (more than 900 seconds) held into the queue [CF] (by 'inst 1, osid 100 ')
Incident details in:/oracle/app/oracle/diag/rdbms/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/trace/racdb_lgwr_9336.trc (incident = 360259 ):
ORA-00494: enqueue [CF] held for too long (more than 900 seconds) by 'inst 1, osid 100'
Incident details in:/oracle/app/oracle/diag/rdbms/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/trace/racdb_ora_17431.trc (incident = 362567 ):
ORA-00494: Long (more than 900 seconds) held into the queue [CF] (by 'inst 1, osid 100 ')
Incident details in:/oracle/app/oracle/diag/rdbms/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. The manual log switch (alter system switch logfile) in the database is very slow and almost implicate.

3. Analysis logs show that the LGWR process has been waiting for CF enqueue,
Dump continued from file:/oracle/app/oracle/diag/rdbms/racdb/trace/racdb_lgwr_5854.trc
ORA-00494: enqueue [CF] held for too long (more than 900 seconds) by 'inst 1, osid 100'

========= 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. Further analysis found that many control file sequential read waits, that is, they are in the IO wait status,
The control file sequential read may be out of the control file, or the control file or its snapshot directory may be out.
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: cballs = 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: cballs = 0 OS = 0
Occurred after 0.000018 sec of elapsed time

 

5. Go to RMAN and check that the backup path of the control file is/oradata/racdbdb_rman_bak. The details are as follows:
RMAN> show all;

Use the target database control file to replace the recovery directory
Db_unique_name is the RMAN Configuration Parameter of the database of racdb:
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/racdb_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. Check the Directory and find that the/oradata directory is out.
Bash-3.00 $ df-h
Filesystem size used avail capacity Mounted on
/Dev/dsk/c0t0d0s0 96G 47G 48G 50%/
/Devices 0 K 0 K 0 K 0%/devices
Ctfs 0 K 0 K 0 K 0%/system/contract
Proc 0 K 0 K 0 K 0%/proc
Mnttab 0 K 0 K 0 K 0%/etc/mnttab
Swap 87G 1.9 M 87G 1%/etc/svc/volatile
Objfs 0 K 0 K 0 K 0%/system/object
Sharefs 0 K 0 K 0 K 0%/etc/dfs/sharetab
Fd 0 K 0 K 0 K 0%/dev/fd
Swap 87G 120 K 87G 1%/tmp
Swap, 87G, 80 K, 87G, 1%/var/run
/Dev/dsk/c0t0d0s4 38G 27G 11G 72%/export/home
/Dev/dsk/c0t1d0s3 77G 41G 35G 54%/oracle

7. Modify the backup path of the control file to restore the database to normal.
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 is the RMAN Configuration Parameter of the database of racdb:
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 ';