AWR 报告深度解读：Redo Nowait指标的算法和诊断

墨墨导读：本文将对Redo Nowait指标的算法和诊断进行深度解析。

为了系统化的梳理 AWR 的知识体系，我们整理了一个系列文章，希望从原理、使用到 AWR 报告的解读，给读者展示全面的 AWR 知识体系，本文是这个系列文章的第四篇。

曾经遇到过一个性能故障，数据库的检查点执行的非常缓慢，直接导致所有日志组都处于活动状态，数据库处于不断停顿的『打嗝』工作状态。

检查V$LOG视图，可以获得日志状态，除了CURRENT日志组，其他日志都处于ACTIVE状态，而且后面的几组日志都是DBA最新添加的：

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

如果日志都处于Active状态，那么显然是DBWR的写出已经无法跟上Log Switch切换触发的检查点。

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

oracle:/oracle >ps -ef|grep ora_dbw	
  oracle  2266     1  0   Mar 31 ?       811:42 ora_dbw0_hysms02	
  oracle 21023 21012  0 18:52:59 pts/65   0:00 grep ora_dbw

这里可以看到DBWR的进程号是2266，接下来使用Top命令观察一下其CPU资源使用情况:

oracle:/oracle >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	
 	
   PID USERNAME THR PRI NICE  SIZE   RES STATE    TIME    CPU COMMAND	
 11855 smspf      1  59    0 1355M 1321M cpu/0   19:32 16.52% oracle	
  2264 oracle     1   0    0 1358M 1316M run    283.3H 16.36% oracle	
 11280 oracle     1  13    0 1356M 1321M sleep   79.8H  0.77% oracle	
21043 oracle     1  43    0 3264K 2056K cpu/9    0:01  0.31% top	
2266 oracle  1  60  0 1357M 1317M sleep  811:42  0.18% oracle	
 26257 smspf     82  59    0  447M  178M sleep  533:04  0.15% java

 注意到2266号进程消耗的CPU不过0.18%,显然并不繁忙,那么瓶颈就很可能在IO上。

使用IOSTAT工具检查IO状况。

gqgai:/home/gqgai>iostat -xn 3	
                    extended device statistics             	
    r/s    w/s   kr/s   kw/s wait actv wsvc_t asvc_t  %w  %b device	
........	
    0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 c0t6d0	
    0.3    8.3    0.3   47.0  0.0  0.1    0.0    9.2   0   8 c0t10d0	
    0.0    8.3    0.0   47.0  0.0  0.1    0.0    8.0   0   7 c0t11d0	
   11.7   65.3  197.2  522.2  0.0  1.6    0.0   20.5   0 100 c1t1d0	
    0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0 hurraysms02:vold(pid238)	
                    ext