当前位置: 首页 >> 技术文章 >> AWR 报告深度解读:Redo Nowait指标的算法和诊断
AWR 报告深度解读:Redo Nowait指标的算法和诊断
发布时间:2019-09-05 发布人:eygle 162

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

AWR知识体系:https://www.modb.pro/topic/6165


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

检查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)
                    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   13.7    2.7   68.2  0.0  0.2    0.0   10.9   0  12 c0t10d0
    0.0   13.7    0.0   68.2  0.0  0.1    0.0    9.6   0  11 c0t11d0
   11.3   65.3   90.7  522.7  0.0  1.5    0.0   19.5   0  99 c1t1d0
0.0    0.0    0.0    0.0  0.0  0.0    0.0    0.0   0   0

以上监控显示存放数据库的主要卷c1t1d0的繁忙程度始终处于99~100,而写速度却只有500K/s左右,这个速度是极为缓慢的。进一步的检查确认是硬盘发生了损坏,Raid5的磁盘组中损坏了一块硬盘,导致了磁盘I/O性能下降,经过更换以后系统逐渐恢复正常。

以下是另外一则类似的问题。最初有朋友提出的问题是,实例效率里面的Redo Nowait指标代表的是什么,为什么会出现负数:

 图示

从数据库的计算公式中可以找到这些比例的计算方法,虽然很多情况下,这些比例的参考意义不大:

--
--  Instance Efficiency Percentages
 
column ldscr  format a50
column nl format a60 newline;
select 'Instance Efficiency Percentages (Target 100%)' ldscr
      ,'~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~' ldscr
      ,'            Buffer Nowait %:'                  dscr
      , round(100*(1-:bfwt/:gets),2)                   pctval
      ,'      Redo NoWait %:'    
      , decode(:rent,0,to_number(null), round(100*(1-:rlsr/:rent),2))  pctval
      ,'            Buffer  Hit   %:'                  dscr
      , round(100*(1-(:phyr-:phyrd-:phyrdl)/:gets),2) pctval
      ,'   In-memory Sort %:'    
      , decode((:srtm+:srtd),0,to_number(null),
                               round(100*:srtm/(:srtd+:srtm),2))       pctval
      ,'            Library Hit   %:'                  dscr
      , round(100*:lhtr,2)                             pctval
      ,'       Soft Parse %:'    
      , round(100*(1-:hprs/:prse),2)                   pctval
      ,'         Execute to Parse %:'                  dscr
      , round(100*(1-:prse/:exe),2)                    pctval
      ,'        Latch Hit %:'    
      , round(100*(1-:lhr),2)                          pctval
      ,'Parse CPU to Parse Elapsd %:'                  dscr
      , decode(:prsela, 0, to_number(null)
                      , round(100*:prscpu/:prsela,2))  pctval
      ,'    % Non-Parse CPU:'
      , decode(:tcpu, 0, to_number(null)
                    , round(100*1-(:prscpu/:tcpu),2))  pctval
  from sys.dual;

从以上计算公式中可以找到:

Redo Nowait % = decode(:rent,0,to_number(null), round(100*(1-:rlsr/:rent),2))
 =  (1 – rlsr/rent) 100%

这里的 rlsr = Redo Log space requests ,rent = Redo Entries 。从AWR报告中可以找到这两个统计值,计算一下这个比率,和报告中的计算值完全吻合:

 Redo Nowait % = (1 – 133,566/44,038)*100% = -203.30 %

图示

可是这个比率说明什么?

重做日志空间请求表明活动日志文件已满,Oracle正在等待为重做日志条目分配磁盘空间。这个比值越高说明在写出Redo条目时等待越多,当比率为负数,说明已经处于严重的写出等待之中。

那么到底是什么原因导致写出不畅呢?是因为Redo量太大,还是因为磁盘效率过低呢?通过数据库的其他统计数据可以进行进一步的分析。

这是一个 11.2.0.4的RAC集群环境,从数据库的概要信息来看,平均每秒仅仅有 7K左右的Redo日志,数据库的物理写也非常低,但是数据库的每秒DB Time却高达259.7 。

 图示

进一步的,从 Top Events数据信息中可以看出,整体的 I/O 非常缓慢,User/IO的平均等待时间高达 410毫秒,db file sequential read的平均等待时间也高达 1779毫秒,这说明I/O上出现了明显的瓶颈。

 图示

在整个数据库写出量并不大的情况下,整体I/O延时却非常高,在日志组同样处于高ACTIVE的情况下,出现大量的Log file Switch(checkpoint incomplete)等待。配合I/O层面的检查发现这个案例同样是存储损坏硬盘导致的I/O能力下降。

数据库的性能,是一个综合因素,在遇到异常分析时,也需要综合多方面的因素,才能够快速而准确的定位根因,解决问题。