[Oracle]Redo log日志组故障分析

2024-08-29 13:50:22

字体：大中小

来源：转载

供稿：网友

数据库平台：SunOS 5.8 Generic_108528-23 sun4u sparc SUNW,Ultra-EnterPRise　　数据库版本：8.1.5.0.0　　数据库症状：数据库响应缓慢，应用请求无法返回，业务操作陷于停顿，此时需要DBA介入并进行问题诊断及故障处理。　　1. 登录数据库进行检查　　首先我们登录数据库,检查故障现象。
　　经过检查发现，数据块的所有重做日志组除current外都处于active状态：

Oracle:/oracle/oracle8>sqlplus "/ as sysdba"
SQL*Plus: Release 8.1.5.0.0 - ProdUCtion on Thu Jun 23 18:56:06 2005
(c) Copyright 1999 Oracle Corporation. All rights reserved.<
Connected to:
Oracle8i Enterprise Edition Release 8.1.5.0.0 - Production
With the Partitioning and java options
PL/SQL Release 8.1.5.0.0 - Production
SQL> select * from v$log;
    GROUP#    THREAD# SEQUENCE#      BYTES    MEMBERS ARC STATUS           FIRST_CHANGE# FIRST_TIM
---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- ---------
         1          1     520403   31457280          1 NO ACTIVE              1.3861E+10 23-JUN-05
         2          1     520404   31457280          1 NO ACTIVE              1.3861E+10 23-JUN-05
         3          1     520405   31457280          1 NO ACTIVE              1.3861E+10 23-JUN-05
         4          1     520406   31457280          1 NO CURRENT             1.3861E+10 23-JUN-05
         5          1     520398   31457280          1 NO ACTIVE              1.3860E+10 23-JUN-05
         6          1     520399   31457280          1 NO ACTIVE              1.3860E+10 23-JUN-05
         7          1     520400 104857600          1 NO ACTIVE              1.3860E+10 23-JUN-05
         8          1     520401 104857600          1 NO ACTIVE              1.3860E+10 23-JUN-05
         9          1     520402 104857600          1 NO ACTIVE              1.3861E+10 23-JUN-05
9 rows selected.
SQL> /
    GROUP#    THREAD# SEQUENCE#      BYTES    MEMBERS ARC STATUS           FIRST_CHANGE# FIRST_TIM
---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- ---------
         1          1     520403   31457280          1 NO ACTIVE              1.3861E+10 23-JUN-05
         2          1     520404   31457280          1 NO ACTIVE              1.3861E+10 23-JUN-05
         3          1     520405   31457280          1 NO ACTIVE              1.3861E+10 23-JUN-05
         4          1     520406   31457280          1 NO CURRENT             1.3861E+10 23-JUN-05
         5          1     520398   31457280          1 NO ACTIVE              1.3860E+10 23-JUN-05
         6          1     520399   31457280          1 NO ACTIVE              1.3860E+10 23-JUN-05
         7          1     520400 104857600          1 NO ACTIVE              1.3860E+10 23-JUN-05
         8          1     520401 104857600          1 NO ACTIVE              1.3860E+10 23-JUN-05
         9          1     520402 104857600          1 NO ACTIVE              1.3861E+10 23-JUN-05
9 rows selected.

　　我们知道，当数据库发生日志切换时（Log Switch）,Oracle会触发一个检查点（Checkpoint），检查点进程（Checkpoint Process，CKPT）会通知DBWR（Database?Writer）进程去执行写操作。在日志文件所保护的处于Buffer cache中的脏数据（dirty buffer）未写回磁盘之前，日志文件不能被覆盖或重用。　　假如数据库异常繁忙，或者DBWR的写出过慢，就可能出现检查点未完成，Oracle却已经用完所有日志文件的情况。在这种情况下，数据库的日志无法生成，整个数据库将处于停顿状态，此时日志文件中会记录类似如下信息：

Mon Jan 23 16:11:39 2006Thread 1 cannot allocate new log, sequence 5871Checkpoint not complete Current log# 2 seq# 5870 mem# 0: +ORADG/danaly/onlinelog/group_2.260.600173851 Current log# 2 seq# 5870 mem# 1: +ORADG/danaly/onlinelog/group_2.261.600173853

　检查v$session_wait视图，我们可以从中看到很多session处于log file switch (checkpoint incomplete) 的等待。

　　2. 检查DBWR进程

　　在本案例中，所有日志组都处于active状态，那么显然DBWR的写出存在问题。

　　接下来让我们检查一下DBWR的繁忙程度:

SQL> !
oracle:/oracle/oracle8>ps -efgrep ora_
oracle 2273     1 0   Mar 31 ?       57:40 ora_smon_hysms02
oracle 2266     1 0   Mar 31 ?       811:42 ora_dbw0_hysms02
oracle 2264     1 16   Mar 31 ?       16999:57 ora_pmon_hysms02
oracle 2268     1 0   Mar 31 ?       1649:07 ora_lgwr_hysms02
oracle 2279     1 0   Mar 31 ?        8:09 ora_snp1_hysms02
oracle 2281     1 0   Mar 31 ?        4:22 ora_snp2_hysms02
oracle 2285     1 0   Mar 31 ?        9:40 ora_snp4_hysms02
oracle 2271     1 0   Mar 31 ?       15:57 ora_ckpt_hysms02
oracle 2283     1 0   Mar 31 ?        5:37 ora_snp3_hysms02
oracle 2277     1 0   Mar 31 ?        5:58 ora_snp0_hysms02
oracle 2289     1 0   Mar 31 ?        0:00 ora_d000_hysms02
oracle 2287     1 0   Mar 31 ?        0:00 ora_s000_hysms02
oracle 2275     1 0   Mar 31 ?        0:04 ora_reco_hysms02
oracle 21023 21012 0 18:52:59 pts/65   0:00 grep ora_

　　DBWR的进程号是2266。
　　

　　使用Top命令观察一下该进程的CPU耗用:

oracle:/oracle/oracle8>top

last pid: 21145; load averages: 3.38, 3.45, 3.67 18:53:38
725 processes: 711 sleeping, 1 running, 10 zombie, 3 on cpu
CPU states: 35.2% idle, 40.1% user, 9.4% kernel, 15.4% iowait, 0.0% swap
Memory: 3072M real, 286M free, 3120M swap in use, 1146M swap free

上一篇：[Oracle]用函数格式化EXPLAIN PLAN

下一篇：[Oracle]进程结构和内存结构的实例