前幾天有位朋友在留言板上提了這樣一個(gè)問(wèn)題：

Fri May 25 20:46:06 2007　　//自動(dòng)備份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　　 //發(fā)生日志切換

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　　 //同時(shí)啟動(dòng)歸檔

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　　 //一秒后另一進(jìn)程啟動(dòng)，失敗

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

以上日志是備份過(guò)程中產(chǎn)生的，備份腳本如下：

$ORACLE_HOME/bin/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;

}

!!

這位朋友提出的問(wèn)題是，為什么會(huì)有：

Log actively being archived by another process

如果一個(gè)歸檔進(jìn)程已經(jīng)開(kāi)始?xì)w檔日志，為什么另外一個(gè)進(jìn)程又來(lái)歸檔日志？

研究了一下，有了一點(diǎn)新的發(fā)現(xiàn)。

首先，歸檔進(jìn)程的數(shù)量是受初始化參數(shù)log_archive_max_processes控制，初始的，這個(gè)參數(shù)設(shè)置為2，Oracle啟動(dòng)兩個(gè)歸檔進(jìn)程：

[oracle@jumper bdump]$ ps -ef|grep ora_arc

oracle 11938 1 0 18:24 ? 00:00:00 ora_arc0_eygle

oracle 11940 1 0 18:24 ? 00:00:00 ora_arc1_eygle

oracle 16260 11894 0 20:21 pts/5 00:00:00 grep ora_arc

其中主歸檔進(jìn)程會(huì)持續(xù)訪問(wèn)控制文件：

*** 2007-06-06 20:23:50.510

WAIT #0: nam='rdbms ipc message' ela= 59999293 p1=6000 p2=0 p3=0

WAIT #0: nam='control file sequential read' ela= 76 p1=0 p2=1 p3=1

WAIT #0: nam='control file sequential read' ela= 36 p1=0 p2=370 p3=1

WAIT #0: nam='control file sequential read' ela= 36 p1=0 p2=8 p3=1

WAIT #0: nam='control file sequential read' ela= 30 p1=0 p2=9 p3=1

*** 2007-06-06 20:24:51.950

WAIT #0: nam='rdbms ipc message' ela= 59999344 p1=6000 p2=0 p3=0

WAIT #0: nam='control file sequential read' ela= 72 p1=0 p2=1 p3=1

WAIT #0: nam='control file sequential read' ela= 35 p1=0 p2=370 p3=1

WAIT #0: nam='control file sequential read' ela= 35 p1=0 p2=8 p3=1

WAIT #0: nam='control file sequential read' ela= 29 p1=0 p2=9 p3=1

另外一個(gè)歸檔進(jìn)程以'rdbms ipc message' 事件處于等待：

*** 2007-06-06 20:01:15.830

WAIT #0: nam='rdbms ipc message' ela= 148300048 p1=14831 p2=0 p3=0

a*** 2007-06-06 20:06:23.030

WAIT #0: nam='rdbms ipc message' ela= 299999745 p1=30000 p2=0 p3=0

a*** 2007-06-06 20:11:30.230

WAIT #0: nam='rdbms ipc message' ela= 299999735 p1=30000 p2=0 p3=0

a*** 2007-06-06 20:16:37.430

WAIT #0: nam='rdbms ipc message' ela= 299999779 p1=30000 p2=0 p3=0

a*** 2007-06-06 20:21:44.630

當(dāng)我們執(zhí)行alter system archive log current命令時(shí)，Oracle Post歸檔進(jìn)程時(shí)，主歸檔進(jìn)程首先執(zhí)行歸檔，而次歸檔進(jìn)程則需要去讀取控制文件，以獲得當(dāng)前及下一歸檔日志信息：

*** 2007-06-06 19:58:43.970

WAIT #0: nam='rdbms ipc message' ela= 148134746 p1=30000 p2=0 p3=0

WAIT #0: nam='control file sequential read' ela= 36 p1=0 p2=1 p3=1

WAIT #0: nam='control file sequential read' ela= 29 p1=0 p2=369 p3=1

WAIT #0: nam='control file sequential read' ela= 32 p1=0 p2=8 p3=1

WAIT #0: nam='control file sequential read' ela= 29 p1=0 p2=10 p3=1

這就導(dǎo)致次歸檔進(jìn)程始終會(huì)落后于主歸檔進(jìn)程，會(huì)在警告日志中看到如下信息:

Wed Jun 6 19:58:43 2007

ARCH: Evaluating archive log 4 thread 1 sequence 305

ARCH: Beginning to archive log 4 thread 1 sequence 305

Creating archive destination LOG_ARCHIVE_DEST_1: '/opt/oracle/product/9.2.0/dbs/arch1_305.dbf'

Wed Jun 6 19:58:43 2007

ARC1: Evaluating archive log 4 thread 1 sequence 305

ARC1: Unable to archive log 4 thread 1 sequence 305

Log actively being archived by another process

這在正常情況下是不會(huì)出現(xiàn)的，如果一個(gè)歸檔進(jìn)程能夠滿足系統(tǒng)需要，第二個(gè)進(jìn)程就無(wú)需啟動(dòng)，而手動(dòng)switch log則會(huì)Post所有歸檔進(jìn)程。

在Oracle10g中，情況同樣如此:

Wed Jun 6 20:32:57 2007

ARCH: Evaluating archive log 4 thread 1 sequence 75268

Wed Jun 6 20:32:57 2007

ARC0: Evaluating archive log 4 thread 1 sequence 75268

ARC0: Unable to archive log 4 thread 1 sequence 75268

Log actively being archived by another process

Wed Jun 6 20:32:57 2007

ARCH: Beginning to archive log 4 thread 1 sequence 75268 (2074.-1351690850:2074.-1351608674) (mmsdb)

-The End-

創(chuàng)作挑戰(zhàn)賽新人創(chuàng)作獎(jiǎng)勵(lì)來(lái)咯，堅(jiān)持創(chuàng)作打卡瓜分現(xiàn)金大獎(jiǎng)

總結(jié)

以上是生活随笔為你收集整理的Oracle 应用归档 卡死,关于Oracle归档进程的运行机制的全部?jī)?nèi)容，希望文章能夠幫你解決所遇到的問(wèn)題。

如果覺(jué)得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。