0

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

数据和云 2019-09-09
127

墨墨导读:本文将对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)
          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能力下降。
             
            数据库的性能,是一个综合因素,在遇到异常分析时,也需要综合多方面的因素,才能够快速而准确的定位根因,解决问题。


            出处:墨天轮(https://www.modb.pro/db/6196,复制到网页中打开或者点击“阅读原文”)


            DBASK,DBA的即时问答平台


            扩展阅读



            1. AWR 报告深度解读:Redo Nowait指标的算法和诊断泄露二十多万名用户数据

            2. 国外数据库十大风云人物,你认识几个?

            3. 墨天轮“我的DBA之路”有奖征文开始啦

            4. 数据安全警示录:XKCD论坛在56万会员数据泄露后关闭,密码安全应提升

            5. 2019年9月数据库流行度排行:MySQL 强劲增长完成深 V 反转

            6. 这个火热的社区都升级到2.0了,你还不知道它?

            7. 一文告诉你全世界最顶级的开发者都在使用什么数据库

            8. 前沿 | VLDB 2019论文解读:阿里巴巴大规模数据库智能参数优化的创新与实践

            9. Oracle 12c因bug导致ORA-04031问题处理过程 | 云和恩墨技术通讯精选

            10. 数据安全:英国公司泄露超过100万人的指纹和面部识别数据



            数据和云

            ID:OraNews

            如有收获,请划至底部,点击“在看”,谢谢!



            公司简介  | 招聘 | DTCC | 数据技术嘉年华 | 免费课程 | 入驻华为严选商城

              

            zCloud | SQM | Bethune Pro2 zData一体机 | MyData一体机 | ZDBM 备份一体机

            Oracle技术架构 | 免费课程 | 数据库排行榜 | DBASK问题集萃 | 技术通讯 

            升级迁移 | 性能优化 | 智能整合 安全保障 |  架构设计 | SQL审核 | 分布式架构 | 高可用容灾 | 运维代维

            云和恩墨大讲堂 | 一个分享交流的地方

            长按,识别二维码,加入万人交流社群


            请备注:云和恩墨大讲堂


            最后修改时间:2020-05-07 23:38:09
            「喜欢文章,快来给作者赞赏墨值吧」
            文章转载自数据和云,如果涉嫌侵权,请发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

            评论

            数据库资讯
            最新 热门 更多
            本月热门
            近期活动
            全部
            暂无活动,敬请期待...
            相关课程
            全部