Only ARCH Bgprocess may create archivelog?

我们在学习Oracle入门知识时都会介绍到ARCH归档进程，归档进程ARCH负责将在线重做日志归档，注意ARCH只会将日志文件中存在的重做内容复制到归档日志文件中，举例来说重做日志文件的大小是512MB，但当前写入的redo entry只占用10MB空间，此时由某些条件触发了日志切换，那么产生的归档文件的大小仍是10MB。

一直以来存在着这样一种误解：归档操作只会由ARCH进程负责完成。

实际上归档操作可能由多种进程完成，举例来说前台进程Fore ground process就可以完成归档操作，当在前台进程中执行alter system archive log current命令时实际执行归档操作的是前台进程(server process)，而非ARCH，这可能是大多数人料想之外的，口说无凭，我们具体验证一下:

[oracle@rh2 ~]$ ps -ef|grep LOCAL=YES|grep G10R2
oracle   20790 20789  0 19:17 ?        00:00:00 oracleG10R2 (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))

SQL> set linesize 200 pagesize 1400;
SQL> select le.leseq "Current log sequence No",
  2         100 * cp.cpodr_bno / le.lesiz "Percent Full",
  3         (cpodr_bno - 1) * 512  "bytes used exclude header",
  4         le.lesiz * 512 - cpodr_bno * 512 "Left space",
  5         le.lesiz  *512       "logfile size"
  6    from x$kcccp cp, x$kccle le
  7   where LE.leseq = CP.cpodr_seq
  8     and bitand(le.leflg, 24) = 8;

Current log sequence No Percent Full bytes used exclude header Left space logfile size
----------------------- ------------ ------------------------- ---------- ------------
                    720   62.0244141                  32518144   19910144     52428800

/* 通过以上脚本可以了解当前日志文件(current logfile)的使用情况，
    这里可以看到日志文件大小为50MB，已使用32MB                    */

[oracle@rh2 ~]$ strace -p 20972 -o archive.log
Process 20972 attached - interrupt to quit

SQL> alter system archive log current;
System altered.

[oracle@rh2 ~]$ cat archive.log |egrep "open|read|write"
read(8, "\1\2\0\0\6\0\0\0\0\0\3^\10!\200\0\0\0\0\0\0\30\352\341\0\0\0\0\0`\0\0"..., 2064) = 258
open("/s01/admin/G10R2/bdump/alert_G10R2.log", O_WRONLY|O_CREAT|O_APPEND, 0660) = 6
writev(6, [{"Mon May 30 19:31:23 2011\n", 25}, {"ALTER SYSTEM ARCHIVE LOG", 24}, {"\n", 1}], 3) = 50
open("/flashcard/oradata/G10R2/controlfile/1.ctl", O_RDWR|O_SYNC|O_DIRECT) = 12
pread(12, "\25\302\0\0\1\0\0\0\0\0\0\0\0\0\1\4\361\374\0\0\0\0\0\0\0\3 \n\22\235\205\254"..., 16384, 16384) = 16384
pread(12, "\25\302\0\0\17\0\0\0\2324\0\0\377\377\1\4?^\0\0\0\6\0\0\0\0\0\0\0\0\0\2"..., 16384, 245760) = 16384
pread(12, "\25\302\0\0\21\0\0\0\2324\0\0\377\377\1\4\377\37\0\0\0\0\0\0\0\0\0\0Q\350\255,"..., 16384, 278528) = 16384
pread(12, "\25\302\0\0\26\0\0\0\2234\0\0\377\377\1\4\327\312\0\0\0\220\1\0\316\2\0\0\2\0\0\0"..., 16384, 360448) = 16384
pread(12, "\25\302\0\0\23\0\0\0\2174\0\0\377\377\1\4\372\202\0\0\17\0\0\0\265!\315\0\0\0/\234"..., 16384, 311296) = 16384
pwrite(12, "\25\302\0\0\22\0\0\0\2334\0\0\377\377\1\4B\35\0\0\0\0\0\0\0\0\0\0Q\350\255,"..., 16384, 294912) = 16384
pwrite(12, "\25\302\0\0\20\0\0\0\2334\0\0\377\377\1\4\240^\0\0\200\6\0\0\0\0\0\0\0\0\0\2"..., 16384, 262144) = 16384
pwrite(12, "\25\302\0\0\1\0\0\0\0\0\0\0\0\0\1\4\t\377\0\0\0\0\0\0\0\3 \n\22\235\205\254"..., 16384, 16384) = 16384
pread(12, "\25\302\0\0\1\0\0\0\0\0\0\0\0\0\1\4\t\377\0\0\0\0\0\0\0\3 \n\22\235\205\254"..., 16384, 16384) = 16384
pread(12, "\25\302\0\0\1\0\0\0\0\0\0\0\0\0\1\4\r\377\0\0\0\0\0\0\0\3 \n\22\235\205\254"..., 16384, 16384) = 16384
pread(12, "\25\302\0\0\20\0\0\0\2354\0\0\377\377\1\4\241\177\0\0\200'\0\0\0\0\0\0\0\0\0\2"..., 16384, 262144) = 16384
pread(12, "\25\302\0\0\22\0\0\0\2354\0\0\377\377\1\4X\35\0\0\0\0\0\0\0\0\0\0Q\350\255,"..., 16384, 294912) = 16384
pread(12, "\25\302\0\0\26\0\0\0\2354\0\0\377\377\1\4\236W\0\0\0\220\1\0\321\2\0\0\1\0\0\0"..., 16384, 360448) = 16384
pread(12, "\25\302\0\0\36\0\0\0\2354\0\0\377\377\1\4\367\5\0\0\3\0\3\0\2\0\0\0\0\0/f"..., 16384, 491520) = 16384
open("/flashcard/oradata/G10R2/onlinelog/o1_mf_3_6v34jpmp_.log", O_RDONLY|O_DIRECT) = 13
open("/flashcard/oradata/G10R2/onlinelog/o1_mf_3_6v34jpmp_.log", O_RDWR|O_SYNC|O_DIRECT) = 13
open("/s01/flash_recovery_area/G10R2/onlinelog/o1_mf_3_6v34jpyn_.log", O_RDONLY|O_DIRECT) = 14
open("/s01/flash_recovery_area/G10R2/onlinelog/o1_mf_3_6v34jpyn_.log", O_RDWR|O_SYNC|O_DIRECT) = 14
pread(13, "\1\"\0\0\1\0\0\0\320\2\0\0\0\200Um\0\0\0\0\0\3 \n\22\235\205\254G10R"..., 512, 512) = 512
pread(14, "\1\"\0\0\1\0\0\0\320\2\0\0\0\200Um\0\0\0\0\0\3 \n\22\235\205\254G10R"..., 512, 512) = 512
open("/flashcard/oradata/G10R2/onlinelog/o1_mf_3_6v34jpmp_.log", O_RDONLY|O_DIRECT) = 13
open("/flashcard/oradata/G10R2/onlinelog/o1_mf_3_6v34jpmp_.log", O_RDWR|O_SYNC|O_DIRECT) = 13
open("/s01/flash_recovery_area/G10R2/onlinelog/o1_mf_3_6v34jpyn_.log", O_RDONLY|O_DIRECT) = 14
open("/s01/flash_recovery_area/G10R2/onlinelog/o1_mf_3_6v34jpyn_.log", O_RDWR|O_SYNC|O_DIRECT) = 14
pread(13, "\1\"\0\0\1\0\0\0\320\2\0\0\0\200Um\0\0\0\0\0\3 \n\22\235\205\254G10R"..., 512, 512) = 512
pread(14, "\1\"\0\0\1\0\0\0\320\2\0\0\0\200Um\0\0\0\0\0\3 \n\22\235\205\254G10R"..., 512, 512) = 512
pread(12, "\25\302\0\0\24\0\0\0\2354\0\0\377\377\1\4\341\202\0\0\17\0\0\0\265!\315\0\0\0/\234"..., 16384, 327680) = 16384
pread(12, "\25\302\0\0\1\0\0\0\0\0\0\0\0\0\1\4\r\377\0\0\0\0\0\0\0\3 \n\22\235\205\254"..., 16384, 16384) = 16384
pread(12, "\25\302\0\0\20\0\0\0\2354\0\0\377\377\1\4\241\177\0\0\200'\0\0\0\0\0\0\0\0\0\2"..., 16384, 262144) = 16384
pread(12, "\25\302\0\0\22\0\0\0\2354\0\0\377\377\1\4X\35\0\0\0\0\0\0\0\0\0\0Q\350\255,"..., 16384, 294912) = 16384
pread(12, "\25\302\0\0D\1\0\0\2234\0\0\377\377\1\4L\250\0\0\0\0\0\0\0\0\0\0008\251\332,"..., 16384, 5308416) = 16384
pread(12, "\25\302\0\0A\1\0\0\2234\0\0\377\377\1\4\3715\0\0\0\236<\216\5\0\0\0\0\300[\310"..., 16384, 5259264) = 16384
pwrite(12, "\25\302\0\0C\1\0\0\2364\0\0\377\377\1\4\210\232\0\0\0000\360\1\0\0\0\0\v\252\332,"..., 16384, 5292032) = 16384
pwrite(12, "\25\302\0\0\21\0\0\0\2364\0\0\377\377\1\4[\35\0\0\0\0\0\0\0\0\0\0Q\350\255,"..., 16384, 278528) = 16384
pwrite(12, "\25\302\0\0\17\0\0\0\2364\0\0\377\377\1\4?\177\0\0\0'\0\0\0\0\0\0\0\0\0\2"..., 16384, 245760) = 16384
pwrite(12, "\25\302\0\0\1\0\0\0\0\0\0\0\0\0\1\4\r\377\0\0\0\0\0\0\0\3 \n\22\235\205\254"..., 16384, 16384) = 16384
pread(12, "\25\302\0\0\1\0\0\0\0\0\0\0\0\0\1\4\r\377\0\0\0\0\0\0\0\3 \n\22\235\205\254"..., 16384, 16384) = 16384
open("/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_720_6y700ch9_.arc", O_RDWR|O_CREAT|O_EXCL|O_SYNC, 0660) = 15
open("/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_720_6y700ch9_.arc", O_RDWR|O_SYNC|O_DIRECT) = 15
write(15, "\0\"\0\0\0\0\300\377\0\0\0\0\0\0\0\0~\240\0\0\0\2\0\0\30\370\0\0}|{z"..., 512) = 512
open("/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_720_6y700ch9_.arc", O_RDONLY|O_DIRECT) = 15
open("/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_720_6y700ch9_.arc", O_RDWR|O_DIRECT) = 15
pread(13, "\1\"\0\0\1\0\0\0\320\2\0\0\0\200Um\0\0\0\0\0\3 \n\22\235\205\254G10R"..., 1048576, 512) = 1048576
pwrite(15, "\1\"\0\0\1\0\0\0\320\2\0\0\0\200tm\0\0\0\0\0\3 \n\22\235\205\254G10R"..., 1048576, 512) = 1048576
pread(13, "\1\"\0\0\1\10\0\0\320\2\0\0\0\200\271\242:22:48:01\5VALID\1"..., 1048576, 1049088) = 1048576
pwrite(15, "\1\"\0\0\1\10\0\0\320\2\0\0\0\200\271\242:22:48:01\5VALID\1"..., 1048576, 1049088) = 1048576
pread(13, "\1\"\0\0\1\20\0\0\320\2\0\0\0\200\220\271\n\0232011-05-12:22:"..., 1048576, 2097664) = 1048576
pwrite(15, "\1\"\0\0\1\20\0\0\320\2\0\0\0\200\220\271\n\0232011-05-12:22:"..., 1048576, 2097664) = 1048576
pread(13, "\1\"\0\0\1\30\0\0\320\2\0\0\364\201\261/\21\0232011-05-12:22:"..., 1048576, 3146240) = 1048576
pwrite(15, "\1\"\0\0\1\30\0\0\320\2\0\0\364\201\261/\21\0232011-05-12:22:"..., 1048576, 3146240) = 1048576
pread(13, "\1\"\0\0\1 \0\0\320\2\0\0\0\200\31~:22:54:21\5VALID\1"..., 1048576, 4194816) = 1048576
pwrite(15, "\1\"\0\0\1 \0\0\320\2\0\0\0\200\31~:22:54:21\5VALID\1"..., 1048576, 4194816) = 1048576
pread(13, "\1\"\0\0\1(\0\0\320\2\0\0\0\200\320\210\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1048576, 5243392) = 1048576
pwrite(15, "\1\"\0\0\1(\0\0\320\2\0\0\0\200\320\210\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1048576, 5243392) = 1048576
pread(13, "\1\"\0\0\0010\0\0\320\2\0\0\374\200\265$\5\f\27<\10\7xo\5\f\27<\10\02320"..., 1048576, 6291968) = 1048576
pwrite(15, "\1\"\0\0\0010\0\0\320\2\0\0\374\200\265$\5\f\27<\10\7xo\5\f\27<\10\02320"..., 1048576, 6291968) = 1048576
pread(13, "\1\"\0\0\0018\0\0\320\2\0\0\0\200W&796508\377\5\304\2\6\2\t\377\tP"..., 1048576, 7340544) = 1048576
pwrite(15, "\1\"\0\0\0018\0\0\320\2\0\0\0\200W&796508\377\5\304\2\6\2\t\377\tP"..., 1048576, 7340544) = 1048576
pread(13, "\1\"\0\0\1@\0\0\320\2\0\0\0\200*2SYS\7D807355\377\5\304\2\7"..., 1048576, 8389120) = 1048576
pwrite(15, "\1\"\0\0\1@\0\0\320\2\0\0\0\200*2SYS\7D807355\377\5\304\2\7"..., 1048576, 8389120) = 1048576
pread(13, "\1\"\0\0\1H\0\0\320\2\0\0\0\200~\5\tPROCEDURE\7xo\5\f\30"..., 1048576, 9437696) = 1048576
pwrite(15, "\1\"\0\0\1H\0\0\320\2\0\0\0\200~\5\tPROCEDURE\7xo\5\f\30"..., 1048576, 9437696) = 1048576
pread(13, "\1\"\0\0\1P\0\0\320\2\0\0\0\200ll\5\f\30\10'\0232011-05-12"..., 1048576, 10486272) = 1048576
pwrite(15, "\1\"\0\0\1P\0\0\320\2\0\0\0\200ll\5\f\30\10'\0232011-05-12"..., 1048576, 10486272) = 1048576
pread(13, "\1\"\0\0\1X\0\0\320\2\0\0\0\200\320\370\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1048576, 11534848) = 1048576
pwrite(15, "\1\"\0\0\1X\0\0\320\2\0\0\0\200\320\370\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1048576, 11534848) = 1048576
pread(13, "\1\"\0\0\1`\0\0\320\2\0\0\0\200\27\216 \377\tPROCEDURE\7xo\5"..., 1048576, 12583424) = 1048576
pwrite(15, "\1\"\0\0\1`\0\0\320\2\0\0\0\200\27\216 \377\tPROCEDURE\7xo\5"..., 1048576, 12583424) = 1048576
pread(13, "\1\"\0\0\1h\0\0\320\2\0\0008\201fj\1N\1N,\0\r\3SYS\7D860"..., 1048576, 13632000) = 1048576
pwrite(15, "\1\"\0\0\1h\0\0\320\2\0\0008\201fj\1N\1N,\0\r\3SYS\7D860"..., 1048576, 13632000) = 1048576
pread(13, "\1\"\0\0\1p\0\0\320\2\0\0\0\200\25%\7xo\5\f\30\20:\0232011-05"..., 1048576, 14680576) = 1048576
pwrite(15, "\1\"\0\0\1p\0\0\320\2\0\0\0\200\25%\7xo\5\f\30\20:\0232011-05"..., 1048576, 14680576) = 1048576
pread(13, "\1\"\0\0\1x\0\0\320\2\0\0\0\200G\36\7xo\5\f\30\23\6\7xo\5\f\30\23\6"..., 1048576, 15729152) = 1048576
pwrite(15, "\1\"\0\0\1x\0\0\320\2\0\0\0\200G\36\7xo\5\f\30\23\6\7xo\5\f\30\23\6"..., 1048576, 15729152) = 1048576
pread(13, "\1\"\0\0\1\200\0\0\320\2\0\0004\200\"\34311-05-12:23:20:1"..., 1048576, 16777728) = 1048576
pwrite(15, "\1\"\0\0\1\200\0\0\320\2\0\0004\200\"\34311-05-12:23:20:1"..., 1048576, 16777728) = 1048576
pread(13, "\1\"\0\0\1\210\0\0\320\2\0\0\0\200\320(\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1048576, 17826304) = 1048576
pwrite(15, "\1\"\0\0\1\210\0\0\320\2\0\0\0\200\320(\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1048576, 17826304) = 1048576
pread(13, "\1\"\0\0\1\220\0\0\320\2\0\0\0\200\343\367\377\tPROCEDURE\7xo\5\f"..., 1048576, 18874880) = 1048576
pwrite(15, "\1\"\0\0\1\220\0\0\320\2\0\0\0\200\343\367\377\tPROCEDURE\7xo\5\f"..., 1048576, 18874880) = 1048576
pread(13, "\1\"\0\0\1\230\0\0\320\2\0\0\350\201\200\263\33\32\0232011-05-12:23"..., 1048576, 19923456) = 1048576
pwrite(15, "\1\"\0\0\1\230\0\0\320\2\0\0\350\201\200\263\33\32\0232011-05-12:23"..., 1048576, 19923456) = 1048576
pread(13, "\1\"\0\0\1\240\0\0\320\2\0\0\34\201\36\326-12:23:28:30\5VAL"..., 1048576, 20972032) = 1048576
pwrite(15, "\1\"\0\0\1\240\0\0\320\2\0\0\34\201\36\326-12:23:28:30\5VAL"..., 1048576, 20972032) = 1048576
pread(13, "\1\"\0\0\1\250\0\0\320\2\0\0\0\200P\331VALID\1N\1N\1N,\0\r\3S"..., 1048576, 22020608) = 1048576
pwrite(15, "\1\"\0\0\1\250\0\0\320\2\0\0\0\200P\331VALID\1N\1N\1N,\0\r\3S"..., 1048576, 22020608) = 1048576
pread(13, "\1\"\0\0\1\260\0\0\320\2\0\0\0\200\342X\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1048576, 23069184) = 1048576
pwrite(15, "\1\"\0\0\1\260\0\0\320\2\0\0\0\200\342X\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1048576, 23069184) = 1048576
pread(13, "\1\"\0\0\1\270\0\0\320\2\0\0\0\200k\251,\0\r\3SYS\7D968280\377"..., 1048576, 24117760) = 1048576
pwrite(15, "\1\"\0\0\1\270\0\0\320\2\0\0\0\200k\251,\0\r\3SYS\7D968280\377"..., 1048576, 24117760) = 1048576
pread(13, "\1\"\0\0\1\300\0\0\320\2\0\0\310\200Ix:37:19\5VALID\1N\1N"..., 1048576, 25166336) = 1048576
pwrite(15, "\1\"\0\0\1\300\0\0\320\2\0\0\310\200Ix:37:19\5VALID\1N\1N"..., 1048576, 25166336) = 1048576
pread(13, "\1\"\0\0\1\310\0\0\320\2\0\0\0\200\34*#\7\377\tPROCEDURE\7xo"..., 1048576, 26214912) = 1048576
pwrite(15, "\1\"\0\0\1\310\0\0\320\2\0\0\0\200\34*#\7\377\tPROCEDURE\7xo"..., 1048576, 26214912) = 1048576
pread(13, "\1\"\0\0\1\320\0\0\320\2\0\0\0\200\343\336A\377\tPROCEDURE\7xo\5"..., 1048576, 27263488) = 1048576
pwrite(15, "\1\"\0\0\1\320\0\0\320\2\0\0\0\200\343\336A\377\tPROCEDURE\7xo\5"..., 1048576, 27263488) = 1048576
pread(13, "\1\"\0\0\1\330\0\0\320\2\0\0P\200\367{/\377\tPROCEDURE\7xo\5"..., 1048576, 28312064) = 1048576
pwrite(15, "\1\"\0\0\1\330\0\0\320\2\0\0P\200\367{/\377\tPROCEDURE\7xo\5"..., 1048576, 28312064) = 1048576
pread(13, "\1\"\0\0\1\340\0\0\320\2\0\0\0\200\315_-05-12:23:46:08\5"..., 1048576, 29360640) = 1048576
pwrite(15, "\1\"\0\0\1\340\0\0\320\2\0\0\0\200\315_-05-12:23:46:08\5"..., 1048576, 29360640) = 1048576
pread(13, "\1\"\0\0\1\350\0\0\320\2\0\0\0\200\263Xo\5\f\0302\31\7xo\5\f\0302\31\0232"..., 1048576, 30409216) = 1048576
pwrite(15, "\1\"\0\0\1\350\0\0\320\2\0\0\0\200\263Xo\5\f\0302\31\7xo\5\f\0302\31\0232"..., 1048576, 30409216) = 1048576
pread(13, "\1\"\0\0\1\360\0\0\320\2\0\0\0\200\213K\5VALID\1N\1N\1N,\0\r\3"..., 1048576, 31457792) = 1048576
pwrite(15, "\1\"\0\0\1\360\0\0\320\2\0\0\0\200\213K\5VALID\1N\1N\1N,\0\r\3"..., 1048576, 31457792) = 1048576
pread(13, "\1\"\0\0\1\370\0\0\320\2\0\0\300\200\333N\24\0\t\0T\0\210\22\"\0\0\0\t\0\t\0"..., 12288, 32506368) = 12288
pwrite(15, "\1\"\0\0\1\370\0\0\320\2\0\0\300\200\333N\24\0\t\0T\0\210\22\"\0\0\0\t\0\t\0"..., 12288, 32506368) = 12288
open("/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_720_6y700ch9_.arc", O_RDWR|O_DIRECT) = 16
write(16, "\0\"\0\0\0\0\300\377\0\0\0\0\0\0\0\0~\240\0\0\0\2\0\0\30\370\0\0}|{z"..., 512) = 512
open("/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_720_6y700ch9_.arc", O_RDWR|O_DIRECT) = 16
write(16, "\0\"\0\0\0\0\300\377\0\0\0\0\0\0\0\0~\240\0\0\0\2\0\0\30\370\0\0}|{z"..., 512) = 512
pread(12, "\25\302\0\0\1\0\0\0\0\0\0\0\0\0\1\4\r\377\0\0\0\0\0\0\0\3 \n\22\235\205\254"..., 16384, 16384) = 16384
pread(12, "\25\302\0\0\17\0\0\0\2364\0\0\377\377\1\4?\177\0\0\0'\0\0\0\0\0\0\0\0\0\2"..., 16384, 245760) = 16384
pread(12, "\25\302\0\0\21\0\0\0\2364\0\0\377\377\1\4[\35\0\0\0\0\0\0\0\0\0\0Q\350\255,"..., 16384, 278528) = 16384
pread(12, "\25\302\0\0\26\0\0\0\2354\0\0\377\377\1\4\236W\0\0\0\220\1\0\321\2\0\0\1\0\0\0"..., 16384, 360448) = 16384
pread(12, "\25\302\0\0\313\0\0\0\2234\0\0\377\377\1\4\2\245\0\0005\251\332,D\"\315\0\0\0\0\0"..., 16384, 3325952) = 16384
pread(12, "\25\302\0\0(\1\0\0d4\0\0\377\377\1\4\6*\0\0\33\0\4\0\333\7\0\0\0\0\0\0"..., 16384, 4849664) = 16384
pread(12, "\25\302\0\0A\1\0\0\2234\0\0\377\377\1\4\3715\0\0\0\236<\216\5\0\0\0\0\300[\310"..., 16384, 5259264) = 16384
pread(12, "\25\302\0\0\313\0\0\0\2234\0\0\377\377\1\4\2\245\0\0005\251\332,D\"\315\0\0\0\0\0"..., 16384, 3325952) = 16384
pwrite(12, "\25\302\0\0B\1\0\0\2374\0\0\377\377\1\4\3725\0\0\0\236<\216\5\0\0\0\0\300[\310"..., 16384, 5275648) = 16384
pread(12, "\25\302\0\0C\1\0\0\2364\0\0\377\377\1\4\210\232\0\0\0000\360\1\0\0\0\0\v\252\332,"..., 16384, 5292032) = 16384
pread(12, "\25\302\0\0B\1\0\0\2374\0\0\377\377\1\4\3725\0\0\0\236<\216\5\0\0\0\0\300[\310"..., 16384, 5275648) = 16384
pwrite(12, "\25\302\0\0D\1\0\0\2374\0\0\377\377\1\4\177\253\0\0\0\0\0\0\0\0\0\0\v\252\332,"..., 16384, 5308416) = 16384
pread(12, "\25\302\0\0\313\0\0\0\2234\0\0\377\377\1\4\2\245\0\0005\251\332,D\"\315\0\0\0\0\0"..., 16384, 3325952) = 16384
pwrite(12, "\25\302\0\0B\1\0\0\2374\0\0\377\377\1\4\353{\0\0\0\316,\220\5\0\0\0\0\300[\310"..., 16384, 5275648) = 16384
pread(12, "\25\302\0\0\26\0\0\0\2354\0\0\377\377\1\4\236W\0\0\0\220\1\0\321\2\0\0\1\0\0\0"..., 16384, 360448) = 16384
pwrite(12, "\25\302\0\0\25\0\0\0\2374\0\0\377\377\1\4\236W\0\0\0\220\1\0\321\2\0\0\1\0\0\0"..., 16384, 344064) = 16384
pwrite(12, "\25\302\0\0\314\0\0\0\2374\0\0\377\377\1\4\231@\0\0005\251\332,D\"\315\0\0\0\0\0"..., 16384, 3342336) = 16384
pwrite(12, "\25\302\0\0\22\0\0\0\2374\0\0\377\377\1\4\323\35\0\0\0\0\0\0\0\0\0\0Q\350\255,"..., 16384, 294912) = 16384
pwrite(12, "\25\302\0\0\20\0\0\0\2374\0\0\377\377\1\4\261\375\0\0\200%\0\0\0\0\0\0\0\0\0\2"..., 16384, 262144) = 16384
pwrite(12, "\25\302\0\0\1\0\0\0\0\0\0\0\0\0\1\0043\377\0\0\0\0\0\0\0\3 \n\22\235\205\254"..., 16384, 16384) = 16384
pread(12, "\25\302\0\0\1\0\0\0\0\0\0\0\0\0\1\0043\377\0\0\0\0\0\0\0\3 \n\22\235\205\254"..., 16384, 16384) = 16384
write(11, "\0\313\0\0\6\0\0\0\0\0\10\6\0\315\"\315\0\0\0\0\0\1\0\0\0\0\0\0\0\0\0\0"..., 203) = 203

在以上system call trace中可以看到前台进程首先读取并更新了控制文件(controlfile/1.ctl)，之后读取了在线日志文件的头部(read o1_mf_3_6v34jpmp_.log=512bytes),接着以相关属性创建了归档日志文件(o1_mf_1_720_6y700ch9_.arc，注意这里使用了O_CREAT、O_EXCL、O_SYNC、0660属性)并得到该打开文件描述符15，接着以每次buffer为1048576字节来读取在线日志并写入归档日志pread(onlinelog)->pwrite(archivelog)，直到在线日志中的redo记录被写完。这里的buffer大小1048576实际上受到隐藏参数_log_archive_buffer_size(Size of each archival buffer in log file blocks)的影响，该参数指定了归档缓冲的大小，其单位为日志文件块(log file block)，日志文件块大小在不同平台上各有差异，具体可以参考这里。目前主流的UNIX平台上日志文件标准块大小为512 bytes，而_log_archive_buffer_size的默认值一般为2048，所以得出了这里的(2048*512)=1048576=1MB buffer大小。需要注意的是与”alter system archive log current”命令不同，”switch logfile”不会引起前台进程去执行归档操作，归档操作仍将由ARCH进程完成。

我们可以很方便的通过查询v$archived_log视图来了解具体完成某个日志文件归档操作的是何种进程，这得益于其creator列:


SQL> select distinct creator  from v$archived_log;

CREATOR
-------
RMAN
FGRD
ARCH


CREATOR 	VARCHAR2(7) 	Creator of the archivelog:

    ARCH - Archiver process
    FGRD - Foreground process
    RMAN - Recovery Manager
    SRMN - RMAN at standby
    LGWR - Logwriter process

以上可以看到可能创建归档日志的进程不仅仅局限于FGRD与ARCH，RMAN(注意实际上并非直接由rman进程完成)在执行热备操作时也可能掺合进来归档一把，此外在DataGuard环境中LGWR也会参与归档操作。

V$archived_log视图中另外一个有趣的字段是REGISTRAR，一般来说在非DataGuard环境中CREATOR总是等于REGISTRAR，而在DataGuard环境中REGISTRAR常是RFS(remote file server process (RFS) on the standby system where the RFS process writes the redo data to either archived redo log files or standby redo log files)后台进程，而实际的CREATOR则往往仍是ARCH或LGWR。

REGISTRAR 	VARCHAR2(7) 	Registrar of the entry:

    RFS - Remote File Server process
    ARCH - Archiver process
    FGRD - Foreground process
    RMAN - Recovery manager
    SRMN - RMAN at standby
    LGWR - Logwriter process

Posted

May 30, 2011

mac

Tags:

Comments

2 responses to “Only ARCH Bgprocess may create archivelog?”

Kamus

June 17, 2011

观察到你的在线日志组有两个member，在归档的时候，也open了/s01/flash_recovery_area/G10R2/onlinelog/o1_mf_3_6v34jpyn_.log这个文件，描述符为14，但是在写入归档的时候却并没有read这个redo，也就是多个member并没有在redo->arch的时候发挥并行写入的功能。多个member有此功能吗？特定场合下才会发生？

maclean

June 17, 2011

我的观点:猜测在arch到多个destinations的时候可能会发挥并行读取的功能，官方文档的描述：
Creating multiple ARCH processes is especially useful when you:
Use more than two online redo logs
Archive to more than one destination
Each ARCn process works on only one inactive log at a time, but must archive to each specified destination.

另外11g中出现了一个新的参数_arch_sim_mode:Change behavior of local archiving，默认为0。对这个参数的的实际作用，Google不到任何有用的信息。

做了一点简单的测试，但仍不足以说明问题，研究这个太耗时间了:

SQL> select group#,members,archived from v$log;

    GROUP#    MEMBERS ARC
---------- ---------- ---
         1          2 YES
         2          2 NO
         3          2 NO
         4          2 NO

SQL> show parameter log_archive_trace

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
log_archive_trace                    integer     124

SQL> alter system switch logfile;
System altered.

======================arch trace content=========================


*** 2011-06-17 20:05:11.766
*** 2011-06-17 20:05:11.766 4212 krsv.c
krsv_hung_process_check: Executing hung process detection check
*** 2011-06-17 20:05:11.766 4512 krsv.c
krsv_hung_process_check: Completed hung process detection check
krsv_proc_lock: Getting process latch [krsv.c:4790]
krso_proc_start_arch: Releasing process latch [krsv.c:1972]
krss_proc_role: Checking for 'no FAL', 'no SRL', and 'HB' ARCH process
krss_proc_role: Getting process latch [krss.c:469]
#  HB  NoF NoS CRL Name
29 NO  NO  NO  NO  ARC0
28 NO  YES YES NO  ARC1
27 YES NO  NO  NO  ARC2
26 NO  NO  NO  NO  ARC3
krss_proc_crl: Checking if ARC1 should be the CRL ARCH
krss_proc_crl: No CRL ARCH needed
krss_proc_role: Releasing process latch [krss.c:654]
*** 2011-06-17 20:05:11.769 1381 krsa.c
Requesting CFTXN 0x7fff5047c540 read-only (last PID:16897) [kcrr.c:3525] IX0
*** 2011-06-17 20:05:11.772 1526 krsa.c
Started    CFTXN 0x7fff5047c540 read-only (PID:16895) [kcrr.c:3525] IX+
Retrieving log 1
Retrieving log 2
Retrieving log 1
krse_arc_driver_core: Clearing FARC_FINAL/FARC_EOR 
Using 16 buffers 1048576 blocks 2048 bytes
*** 2011-06-17 20:05:11.773 8532 krse.c
VALIDATE
*** 2011-06-17 20:05:11.773 8603 krse.c
PREPARE
krsk_rlh_get_info: Log 1 thread:1 seq:267 dbid:0x97935b6 acid:0x9790ab2 branch:747100216
krsk_rlh_get_info: Database dbid:0x97935b6 acid:0x9790ab2 branch:747100216
krsa_make_bts_eqids: dbid:158938550 rls:0:972274 rlc:747100216 thr:1 seq:267 cia:0 tcia:0
ID1: Neither CIA nor TRUE CIA - no special number used in ID1 computation
*** 2011-06-17 20:05:11.793 629 krsa.c
krsa_bts_acq_mode: krsaeqp:0x7f48ff11c138 parent:0xdcbb49f8 mode:5
  Acquiring global enqueue on thread 1 sequence 267 instance 1
*** 2011-06-17 20:05:11.794 690 krsa.c
Acquired global enqueue on thread 1 sequence 267 (id1:0x97835b6 id2:0x2c87d933)
Retrieving log 1
Scan al entries up to entry 313 and update boundary to: 317 
Reusing kcrfx read buffers
*** 2011-06-17 20:05:11.800 1568 krsa.c
Ending     CFTXN 0x7fff5047c540 (last PID:16895) [krse.c:8260] IX0
*** 2011-06-17 20:05:11.800 1662 krsa.c
Completed  CFTXN 0x7fff5047c540 (last PID:16895) [krse.c:8260] IX-
*** 2011-06-17 20:05:11.800 8355 krse.c
INITIALIZE
Clearing global error code [krse.c:5791]
Destination LOG_ARCHIVE_DEST_31 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_30 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_29 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_28 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_27 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_26 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_25 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_24 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_23 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_22 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_21 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_20 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_19 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_18 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_17 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_16 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_15 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_14 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_13 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_12 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_11 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_10 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_9 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_8 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_7 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_6 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_5 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_4 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_3 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_2 is neither enabled nor valid
Destination LOG_ARCHIVE_DEST_1 is being evaluated
VALIDFOR_STANDBY_LOGFILE:1
VALIDFOR_ONLINE_LOGFILE: 1
VALIDFOR_STANDBY_ROLE:   1
VALIDFOR_PRIMARY_ROLE:   1
SLF:0x0 PSB:0x0 LSB:0x0 SSB:0x0 STRM:0x0 ADS:0
Destination LOG_ARCHIVE_DEST_1 accepted for ONLINE_LOGFILE archival
Destination LOG_ARCHIVE_DEST_1 is eligible for archival 
krse_arc_dest_init: number of destinations to service now 1.
*** 2011-06-17 20:05:11.801 7104 krse.c
SPOOL
*** 2011-06-17 20:05:11.801 3864 krse.c
LOCAL_ARCH_STATS: IO context created: Time spent: 0 msec => 0.00 sec Total: 0 msec => 0.00 sec
*** 2011-06-17 20:05:11.801 4265 krsh.c
ARC1: Creating local archive destination LOG_ARCHIVE_DEST_1: '/s01/arch/1_267_747100216.dbf' (thread 1 sequence 267)
*** 2011-06-17 20:05:11.806 4070 krse.c
LOCAL_ARCH_STATS: Archive log created: Time spent: 10 msec => 0.01 sec Total: 10 msec => 0.01 sec
Archiving block 1 count 442 block(s) to '/s01/arch/1_267_747100216.dbf'
*** 2011-06-17 20:05:11.813 5102 krse.c
LOCAL_ARCH_STATS: Reads and Writes completed: Time spent: 0 msec => 0.00 sec Total: 10 msec => 0.01 sec
*** 2011-06-17 20:05:11.813 4265 krsh.c
ARC1: Closing local archive destination LOG_ARCHIVE_DEST_1: '/s01/arch/1_267_747100216.dbf'
*** 2011-06-17 20:05:11.816 5328 krse.c
LOCAL_ARCH_STATS: Archive log closed: Time spent: 10 msec => 0.01 sec Total: 20 msec => 0.02 sec
*** 2011-06-17 20:05:11.816 5458 krse.c
FINISH
-----------------------------------------------------------
SUMMARY of Archival Time for thread 1 seq 267
IO context creation         0 msec => 0.00 sec
Archive log creation        10 msec => 0.01 sec
Archive log read and write  0 msec => 0.00 sec
Archive log close           10 msec => 0.01 sec
Archive log total           20 msec => 0.02 sec
-----------------------------------------------------------
Ignoring destination LOG_ARCHIVE_DEST_31: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_30: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_29: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_28: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_27: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_26: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_25: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_24: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_23: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_22: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_21: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_20: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_19: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_18: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_17: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_16: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_15: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_14: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_13: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_12: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_11: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_10: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_9: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_8: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_7: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_6: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_5: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_4: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_3: skipped during krse_arc_dest_init
Ignoring destination LOG_ARCHIVE_DEST_2: skipped during krse_arc_dest_init
*** 2011-06-17 20:05:11.817 3383 krse.c
COMPLETE, all destinations archived
Closing krrx context without deallocating buffers
*** 2011-06-17 20:05:11.820 1381 krsa.c
Requesting CFTXN 0x7fff5047c540 read-write (last PID:16895) [krse.c:1797] IX0
*** 2011-06-17 20:05:11.823 1526 krsa.c
Started    CFTXN 0x7fff5047c540 read-write (PID:16895) [krse.c:1797] IX+
Retrieving log 1
*** 2011-06-17 20:05:11.826 2311 krse.c
Archived Log entry 318 added for thread 1 sequence 267 ID 0x9790ab2 dest 1: /s01/arch/1_267_747100216.dbf
*** 2011-06-17 20:05:11.826 8935 krsf.c
Acquiring FAL Queue latch from [krsf.c:8935] IX0
*** 2011-06-17 20:05:11.826 8935 krsf.c
Successfully acquired FAL Queue latch IX+
*** 2011-06-17 20:05:11.826 8990 krsf.c
Freeing FAL Queue latch from [krsf.c:8990] IX0
*** 2011-06-17 20:05:11.826 8990 krsf.c
Successfully freed FAL Queue latch IX-
pre-dal: lno:1 arf:2 arb:4 arh:3 art:2
Retrieving log 4
Updating log 4 thread 2 sequence 60
Previous log 4 thread 2 sequence 60
Retrieving log 2
Updating log 2 thread 1 sequence 268
Previous log 2 thread 1 sequence 268
post-dal: lno:1 arf:0 arb:0 arh:3 art:2
Updating log 1 thread 1 sequence 267
Previous log 1 thread 1 sequence 267
krsa_bts_rel: krsaeqp:0x7f48ff11c138 parent:0xdcbb49f8 mode:5
         dbid:158938550 rls:0:972274 rlc:747100216 thr:1 seq:267 cia:0
*** 2011-06-17 20:05:11.827 755 krsa.c
Releasing global enqueue for thread 1 sequence 267
*** 2011-06-17 20:05:11.827 778 krsa.c
Released global enqueue for thread 0 sequence 0
ARCHIVED
Retrieving log 3
Retrieving log 4
Retrieving log 2
*** 2011-06-17 20:05:11.832 1568 krsa.c
Ending     CFTXN 0x7fff5047c540 (last PID:16895) [kcrr.c:5328] IX0
*** 2011-06-17 20:05:11.832 1662 krsa.c
Completed  CFTXN 0x7fff5047c540 (last PID:16895) [kcrr.c:5328] IX-
*** 2011-06-17 20:05:11.833 2116 krsa.c
Requesting CFTXN 0x7fff50479b28 noenqueue (last PID:16895) [krss.c:845] IX0
*** 2011-06-17 20:05:11.835 2133 krsa.c
Started    CFTXN 0x7fff50479b28 noenqueue (PID:16895) [krss.c:845] IX+
Retrieving log 1
Retrieving log 2
Retrieving log 3
Retrieving log 4
*** 2011-06-17 20:05:11.837 1568 krsa.c
Ending     CFTXN 0x7fff50479b28 (last PID:16895) [krss.c:1187] IX0
*** 2011-06-17 20:05:11.837 1662 krsa.c
Completed  CFTXN 0x7fff50479b28 (last PID:16895) [krss.c:1187] IX-
*** 2011-06-17 20:05:11.837 3280 krsf.c
Acquiring FAL Queue latch from [krsf.c:3280] IX0
*** 2011-06-17 20:05:11.837 3280 krsf.c
Successfully acquired FAL Queue latch IX+
*** 2011-06-17 20:05:11.837 3706 krsf.c
Freeing FAL Queue latch from [krsf.c:3706] IX0
*** 2011-06-17 20:05:11.837 3706 krsf.c
Successfully freed FAL Queue latch IX-
kcrrwkx: nothing to do (end)

Only ARCH Bgprocess may create archivelog?

Comments

2 responses to “Only ARCH Bgprocess may create archivelog?”

Leave a Reply Cancel reply