有位朋友提了这样一个问题：
Fri May 25 20:46:06 2007 //自动备份controlfile Starting control autobackup Control autobackup written to DISK device handle '/ora_rman_backup/crtl_backup/c-4205638757-20070525-00' Fri May 25 20:46:11 2007 //发生日志切换 Thread 1 advanced to log sequence 535 Current log# 1 seq# 535 mem# 0: /dev/udpay/lv_redo11_256m Current log# 1 seq# 535 mem# 1: /dev/udpay/lv_redo12_256m Fri May 25 20:46:11 2007 //同时启动归档 ARCH: Evaluating archive log 6 thread 1 sequence 534 ARCH: Beginning to archive log 6 thread 1 sequence 534 Creating archive destination LOG_ARCHIVE_DEST_1: '/archivelog/arch/1_534.dbf' Fri May 25 20:46:12 2007 //一秒后另一进程启动，失败 ARC0: Evaluating archive log 6 thread 1 sequence 534 ARC0: Unable to archive log 6 thread 1 sequence 534 Log actively being archived by another process Fri May 25 20:46:15 2007 //3秒后成功归档 ARCH: Completed archiving log 6 thread 1 sequence 534 Fri May 25 20:46:18 2007 //3秒后日志切换 Thread 1 advanced to log sequence 536 Current log# 2 seq# 536 mem# 0: /dev/udpay/lv_redo21_256m
以上日志是备份过程中产生的，备份脚本如下：
$ORACLE_HOME/bin/rman < connect catalog rman/rman ; connect target sys/sys@udpay; CONFIGURE CONTROLFILE AUTOBACKUP FORMAT FOR DEVICE TYPE DISK TO '/ora_rman_backup/crtl_backup/%F'; CONFIGURE CONTROLFILE AUTOBACKUP ON; CROSSCHECK ARCHIVELOG ALL; run{ ALLOCATE CHANNEL ch1 DEVICE TYPE DISK; backup full database format 'D:/%T_%d' include current controlfile; sql 'alter system archive log current'; backup filesperset 3 format 'D:/arch%u_%s_%p' archivelog all; DELETE NOPROMPT ARCHIVELOG UNTIL TIME 'SYSDATE-2'; release channel ch1; } !!
这位朋友提出的问题是，为什么会有：
Log actively being archived by another process如果一个归档进程已经开始归档日志，为什么另外一个进程又来归档日志？
研究了一下，有了一点新的发现。
首先，归档进程的数量是受初始化参数log_archive_max_processes控制，初始的，这个参数设置为2，Oracle启动两个归档进程：
[oracle@jumper bdump]$ ps -ef|grep ora_arcoracle 11938 1 0 18:24 ? 00:00:00 ora_arc0_eygleoracle 11940 1 0 18:24 ? 00:00:00 ora_arc1_eygleoracle 16260 11894 0 20:21 pts/5 00:00:00 grep ora_arc
其中主归档进程会持续访问控制文件：
*** 2007-06-06 20:23:50.510WAIT #0: nam='rdbms ipc message' ela= 59999293 p1=6000 p2=0 p3=0WAIT #0: nam='control file sequential read' ela= 76 p1=0 p2=1 p3=1WAIT #0: nam='control file sequential read' ela= 36 p1=0 p2=370 p3=1WAIT #0: nam='control file sequential read' ela= 36 p1=0 p2=8 p3=1WAIT #0: nam='control file sequential read' ela= 30 p1=0 p2=9 p3=1*** 2007-06-06 20:24:51.950WAIT #0: nam='rdbms ipc message' ela= 59999344 p1=6000 p2=0 p3=0WAIT #0: nam='control file sequential read' ela= 72 p1=0 p2=1 p3=1WAIT #0: nam='control file sequential read' ela= 35 p1=0 p2=370 p3=1WAIT #0: nam='control file sequential read' ela= 35 p1=0 p2=8 p3=1WAIT #0: nam='control file sequential read' ela= 29 p1=0 p2=9 p3=1
另外一个归档进程以'rdbms ipc message' 事件处于等待：
*** 2007-06-06 20:01:15.830WAIT #0: nam='rdbms ipc message' ela= 148300048 p1=14831 p2=0 p3=0a*** 2007-06-06 20:06:23.030WAIT #0: nam='rdbms ipc message' ela= 299999745 p1=30000 p2=0 p3=0a*** 2007-06-06 20:11:30.230WAIT #0: nam='rdbms ipc message' ela= 299999735 p1=30000 p2=0 p3=0a*** 2007-06-06 20:16:37.430WAIT #0: nam='rdbms ipc message' ela= 299999779 p1=30000 p2=0 p3=0a*** 2007-06-06 20:21:44.630
当我们执行alter system archive log current命令时，Oracle Post归档进程时，主归档进程首先执行归档，而次归档进程则需要去读取控制文件，以获得当前及下一归档日志信息：
*** 2007-06-06 19:58:43.970WAIT #0: nam='rdbms ipc message' ela= 148134746 p1=30000 p2=0 p3=0WAIT #0: nam='control file sequential read' ela= 36 p1=0 p2=1 p3=1WAIT #0: nam='control file sequential read' ela= 29 p1=0 p2=369 p3=1WAIT #0: nam='control file sequential read' ela= 32 p1=0 p2=8 p3=1WAIT #0: nam='control file sequential read' ela= 29 p1=0 p2=10 p3=1
这就导致次归档进程始终会落后于主归档进程，会在警告日志中看到如下信息:
Wed Jun 6 19:58:43 2007ARCH: Evaluating archive log 4 thread 1 sequence 305ARCH: Beginning to archive log 4 thread 1 sequence 305Creating archive destination LOG_ARCHIVE_DEST_1: '/opt/oracle/product/9.2.0/dbs/arch1_305.dbf'Wed Jun 6 19:58:43 2007ARC1: Evaluating archive log 4 thread 1 sequence 305ARC1: Unable to archive log 4 thread 1 sequence 305Log actively being archived by another process
这在正常情况下是不会出现的，如果一个归档进程能够满足系统需要，第二个进程就无需启动，而手动switch log则会Post所有归档进程。
在Oracle10g中，情况同样如此:
Wed Jun 6 20:32:57 2007ARCH: Evaluating archive log 4 thread 1 sequence 75268Wed Jun 6 20:32:57 2007ARC0: Evaluating archive log 4 thread 1 sequence 75268ARC0: Unable to archive log 4 thread 1 sequence 75268Log actively being archived by another processWed Jun 6 20:32:57 2007ARCH: Beginning to archive log 4 thread 1 sequence 75268 (2074.-1351690850:2074.-1351608674) (mmsdb)