Oracle的一次Cache buffers chains等待事件排查过程

0    87    2

👉 本文共约3630个字,系统预计阅读时间或需14分钟。

题记

这是某移动运营商在SQL线下审核项目中,协助开发商完善数据库性能的过程。以往开发商遇到此问题总是怀疑是数据库的Bug,试图尝试重启Tuxedo、Weblogic,严重时甚至重启实例来缓解问题。经过下面的详细分析,你会发现事实并非如此。

详细诊断过程

这是对于两个节点的RAC环境,数据库版本为11.2.0.4 for HP-UX IA(64-bit)。在2014年11月5日16点至18点间,节点一的CPU使用率从平时的40%增长到60%左右,部分业务办理缓慢甚至超时。经过详细分析,发现是一个低效的、高并发的核心业务的SQL语句引起的。

通过询问业务人员得知,业务系统从17:00至17:30感觉慢得更为明显,因此我们导出了该时间段节点二的AWR报告。

下图显示了实例名为crmdb21的采样时间、数据库版本、CPU个数和内存大小等概要信息,通过简单的换算DB Time和Elapsed可知(2807.24/29.7=94),这台64 Cores的小型机的确很忙。

图片

Load Profile中的Logical read(blocks)973915.2/Per Second表明平均每秒产生的逻辑读blocks数约为97万,每秒的逻辑读约有7.6GB(973915*db_block_size=7.6GB/s),一般来说,逻辑读高CPU的使用率也会随之升高,通常会在Top 10中出现诸如latch: cache buffers chains、db filescattered read等事件。

图片

Top 10Foregrand Events by Total Wait Time的部分,可以看到在该时间段的主要等待事件是latch:cache buffers chains 和 db filesequential read。它们的%DB Time分别占到38.9%和24.3%。后者代表单块读,是一种比较常见的物理IO等待事件,通常在数据块从磁盘读入到相连的内存空间中时发生,也可能是SQL语句使用了selectivity不高的索引,从而导致访问了过多不必要的索引块或者使用了错误的索引,这些等待说明SQL语句的执行计划可能不是最优的。前者是导致数据库逻辑读高的根本原因,由此推断某个或者某些SQL语句出现了性能衰变。图片

在接下来的SQLStatistics部分,分别截取了SQL ordered by Elapsed Time和 SQL orderedby Gets,可以发现SQL Id=g5z291fcmwz08的语句分别占了42.50%的DB Time和35.19%的逻辑读,而其他SQL所占的DB Time和逻辑读分别在0.1%~5%。由此可以确定,就是该SQL语句影响系统性能,但还需要详细了解该SQL的执行计划、绑定变量和当时的逻辑读等信息。

图片
图片

通过分析可以导出该SQLReport。记录了故障时间段SQL Id=g5z291fcmwz08的SQL概要信息。

图片

执行统计信息如下:

图片

可以发现该SQL在30分钟内执行了2281次,单次的逻辑读在267755.03,由此很可能认为这个SQL始终没有走到合适的索引或者是全表扫描。值得关注的是267755.03这个数字,它是一个平均值,很有可能被平均,换句话说,有时单次逻辑读很小、有时可能还会大于这个平均值。

我们再看执行计划:

图片

1、Rows或Cost仅代表一个估算值。

2、谓词条件中用到的索引列都是绑定变量,在遇到绑定变量+窥视关闭(该数据库窥视关闭)时,即使有直方图信息,优化器在估算时总是认为数据分布是平均的。

3、在扫描索引PK_CM_CU_INDIDUAL时,扫描了1到14个分区。

4、CUSTOMER表返回的记录数稍有偏差,将会增加与PK_CM_CU_INDIDUAL索引循环的次数,也会影响整个查询的性能。

本人提供Oracle、MySQL、PG等数据库的培训和考证业务,私聊QQ646634621或微信db_bao,谢谢!

执行计划中,先通过索引IDX_CUSTOMER_CERTID过滤出2条数据,之后回CUSTOMER表得到1条记录,再通过结果集去驱动查询主键PK_CM_CU_INDIVIDUAL,最后通过嵌套循环返回结果集。看上去每一步的Rows和Cost都非常理想,实际上存在4点值得关注的隐患。

在继续往下分析之前,开发人员抛出一个疑问,为什么同一个SQL在其他两个库都正常,而在这个库却出现了问题?

通过以下查询不难发现,这个SQL在每一个库的单次平均逻辑读都相似。

图片

执行统计如下:

图片

从执行次数上看,其他两个库基本维持在几十或上百次,而在故障库中峰值高达2281次,这同样是故障点的执行次数。这表明该SQL的性能是低效的,对数据库造成的性能冲击也是随着执行次数的增加而愈演愈烈的。

谓词条件中用到了绑定变量,需要找到当时的绑定变量值来看真实的执行计划。

图片

在上述分析中提到,“如果CUSTOMER表返回的记录数稍有偏差,将会增加与PK_CM_CU_INDIDUAL索引循环的次数,从而影响整个查询的性能”。在回表之前先通过索引字段CERTID过滤数据,该字段的数据分布非常重要。即该字段的值是否存在数据倾斜至关重要,下面对其进行统计。

图片

结果很明显,该字段使用过的值出现了严重的数据倾斜。我们把3xxxxxx00402045代入WHERE条件,通过/*+gather_plan_statistics*/查看优化器的估计值与真实值之间的差异。在扫描IDX_CUSTOMER_CERTID索引时,估算值是1,而实际值是59106,回表之后的记录数依然是59106,这表明至少要和下面的索引关联59106次,被驱动表恰巧共有14个分区,循环的次数就变成了59106×14 次,这也是单次逻辑高达2503731的原因,如图9-10所示。

说明:/*+gather_plan_statistics*/这个提示会记录每一步操作中真实返回的行数(A-Rows)、逻辑读(Buffers)和耗费的时间(A-Time)。

图片

同时也测试了一个不倾斜的值进行对比(3xxxxxx00402044),发现逻辑读只有760,这说明了该SQL被执行的次数越多,逻辑读就会被平均得更小图片

经过以上分析可知,数据倾斜、全分区扫描、执行次数三者相加之和的增加使得该SQL的性能影响了整个系统。接下来从两个方面对其进行优化。

1、从SQL方面。

编写一个新SQL专门针对倾斜值,用HASH JOIN替代默认的NEST LOOP。

2、从业务方面。

1)检查倾斜数据的合理性。

2)在访问PERSON_CUSTOMER表时,可以增加分区字段加以限制,从而避免扫描多余的分区。

3)梳理业务场景。

通过和开发人员、业务人员反复沟通确认,该条SQL在业务场景和数据倾斜上都是可以修正和清理的。在完全满足业务场景的前提下,开发人员对SQL做了调整,通过改写union all和rownum <2,有效合理地控制了返回的记录数,逻辑读也从26万降低到了1303,性能提升了近200倍,如图9-12所示。这个案例的优化过程也是围绕技术和业务反复优化的过程。

图片

图片

总结

在移动运营商SQL审核项目的交付过程中,和大家分享以下几点。

1、在AWR、SQL Report中Per所对应的往往是平均值,需要结合执行计划和数据分布来分析该平均值是否真实可靠。

2、当全分区扫描出现在执行计划中时,需要结合业务判断其合理性。

3、绑定变量的历史值和其数据分布能够提高分析问题的精确性。

4、提高SQL的性能存在着多种优化方法,随着系统本身和系统架构的推进,SQL优化需要结合技术、数据特点、业务场景等要素综合分析,从而才能给客户提出一套完整、全面、可执行的优化方案。

参考

【谁影响了性能】全面诊断Cache buffers chains

标签:

头像

小麦苗

学习或考证,均可联系麦老师,请加微信db_bao或QQ646634621

您可能还喜欢...

发表回复

您的电子邮箱地址不会被公开。 必填项已用*标注

20 − 8 =

 

嘿,我是小麦,需要帮助随时找我哦
  • 18509239930
  • 个人微信

  • 麦老师QQ聊天
  • 个人邮箱
  • 点击加入QQ群
  • 个人微店

  • 回到顶部
返回顶部