Oracle数据库日志中一条“异常”信息所包含的细节
Oracle数据库日志中一条“异常”信息所包含的细节
今天在梳理服务器的信息的时候，发现有一台服务器没有设置crontab作业,一般的服务器中可能会需要一些定时的任务来触发一些备份，清理等等工作。
因为这是一台备库机器，上面有11gR2的备库,所以首要工作就是查看是否在正常应用日志。
从日志来看，归档已经正常应用。不过似乎有一些相对陌生的操作在日志里面。
Archived Log entry 68735 added for thread 1 sequence 95373 ID 0x70141a28 dest 1:
Tue Aug 04 16:00:29 2015
Media Recovery Waiting for thread 1 sequence 95374 (in transit)
Recovery of Online Redo Log: Thread 1 Group 4 Seq 95374 Reading mem 0
Mem# 0: /U01/app/Oracle/oradata/xxxxxx/std_redo04.log
Tue Aug 04 16:22:32 2015
RFS[6]: Selected log 5 for thread 1 sequence 95375 dbid 1880348712 branch 828552874
Tue Aug 04 16:22:32 2015
Deleted Oracle managed file /U01/app/oracle/fast_recovery_area/xxxxxx/archivelog/2015_07_15/o1_mf_1_92947_btbdqpm3_.arc
Tue Aug 04 16:22:32 2015
Media Recovery Waiting for thread 1 sequence 95375 (in transit)
Recovery of Online Redo Log: Thread 1 Group 5 Seq 95375 Reading mem 0
Mem# 0: /U01/app/oracle/oradata/xxxxxx/std_redo05.log
Archived Log entry 68736 added for thread 1 sequence 95374 ID 0x70141a28 dest 1:
Tue Aug 04 16:45:30 2015
RFS[6]: Selected log 4 for thread 1 sequence 95376 dbid 1880348712 branch 828552874
Tue Aug 04 16:45:30 2015
Deleted Oracle managed file /U01/app/oracle/fast_recovery_area/xxxxxx/archivelog/2015_07_15/o1_mf_1_92948_btbdqwmt_.arc
Tue Aug 04 16:45:30 2015
Media Recovery Waiting for thread 1 sequence 95376 (in transit)
Recovery of Online Redo Log: Thread 1 Group 4 Seq 95376 Reading mem 0
Mem# 0: /U01/app/oracle/oradata/xxxxxx/std_redo04.log
Archived Log entry 68737 added for thread 1 sequence 95375 ID 0x70141a28 dest 1:
按照这个频率，似乎每次接受一次归档，都会触发一次自动的删除就归档的操作。
这个操作很明显不是在crontab中触发的，因为crontab没有启用，就算启用，这些操作也不会同步的如此紧密，数据库日志中不会有这些信息。
带着疑问，查看了一些相关的帖子，其中有一篇文章是老熊写的，http://www.laoxiong.net/oracle-11g-data-guard-archived-log-managemen.html
在文章中还提供了一个metalink的链接解释。
Files being deleted in the flash recovery area, messages in the alert log Deleted Oracle managed file <filename> (文档 ID 1369341.1)
对于这个问题，其实在11gR2开始，Oracle会根据闪回恢复区的大小，设定一个阀值，默认是80%,即如果归档空间的使用率超过80%,则会自动触发删除归档。
可以在当前的环境简单验证。
SQL> SQL> show parameter recover
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
db_recovery_file_dest string /U01/app/oracle/fast_recovery_area
db_recovery_file_dest_size big integer 120G
查看闪回区域的使用情况如下：
[fast_recovery_area]$ du -sh ./*
18M ./hxxxx
96G ./SHxxxxx
如果细细查看，会发现在近期确实生成了大量的归档文件。
...
3.9G ./2015_07_23
3.8G ./2015_07_24
3.9G ./2015_07_25
3.9G ./2015_07_26
8.7G ./2015_07_27
3.9G ./2015_07_28
4.1G ./2015_07_29
4.0G ./2015_07_30
4.3G ./2015_07_31
4.1G ./2015_08_01
4.1G ./2015_08_02
8.9G ./2015_08_03
3.2G ./2015_08_04
当然系统级查看似乎还是不够清晰，我们可以用个试图来看看，一目了然。
SQL> select * from V$RECOVERY_AREA_USAGE;
FILE_TYPE PERCENT_SPACE_USED PERCENT_SPACE_RECLAIMABLE NUMBER_OF_FILES
-------------------- ------------------ ------------------------- ---------------
CONTROL FILE 0 0 0
REDO LOG 0 0 0
ARCHIVED LOG 79.98 79.92 2427
BACKUP PIECE 0 0 0
IMAGE COPY 0 0 0
FLASHBACK LOG 0 0 0
FOREIGN ARCHIVED LOG 0 0 0
可以看到现在的使用情况已经达到了79.98%,已经处于触发的临界点了。
对于这个问题，明白了原因，解决起来就容易多了，自己也暗自庆幸这个库是一个11gR2的库，要不然没准我在近期就会收到报警短信了。
删除归档，还是直接用rman来做，可以使用下面的脚本来简单处理，把一天前的归档删除。
rman target / <<EOF
CONFIGURE ARCHIVELOG DELETION POLICY TO applied on all standby ;
crosscheck archivelog all;
delete noprompt expired archivelog all;
delete noprompt archivelog until time "sysdate-1";
exit
EOF
删除后再次查看，空间就释放了不少。
[archivelog]$ du -sh .
4.1G
如果对于80%这个阀值存在异议，还是可以通过事件19823来触发，比如我们希望把阀值调整为90%
就可以这么设置。
alter system set event='19823 trace name context forever,level 90‘ scope=spfile; 然后需要重启数据库生效。
所以通过这个问题我们看到日志中的一个细小的差别，其实在数据库层面在触发一些工作，这个特性相对来说还是比较合理的一个处理。
评论暂时关闭