暂无图片
暂无图片
暂无图片
暂无图片
暂无图片
首页 / 案例分享-什么原因导致了CPU爆机

案例分享-什么原因导致了CPU爆机

白鳝的洞穴 2020-03-30
1050
今天老白分享的案例是数年前的一个邮政业务系统的案例。业务高峰期（18：00—21：00）数据库RAC两个节点CPU使用率急剧上升，直至接近100%：

 总体Load达90%，大批进程使用CPU为100%，等待队列达80-100个，如下所示

PID   USER      PR   NI  VIRT  RES   SHR S %CPU %MEM    TIME+  COMMAND

11636 oracle    25   0  200g 2.2g 2.2g R 100.0  0.4   13:18.11 oracle

12250 oracle    25   0  200g 1.1g 1.1g R 100.0  0.2    6:53.40 oracle

27197 oracle    19   0  200g 723m 712m R 100.0  0.1    3:47.95 oracle

11416 oracle    25   0  200g 2.2g 2.2g R 100.0  0.4    6:30.82 oracle

12470 oracle    25   0  200g 4.0g 4.0g R 100.0   0.8  48:27.03 oracle

......


 因为数据库负载太高，Weblogic在无法正常连接数据库后，反应到最终客户端就成了系统无法连接上，不能正常使用。由于EMSPDA数据采集系统已经连续多日出现性能问题，影响业务运作，以及临近双11快递业务高峰期，因此客户希望尽快能够解决问题。
由于系统存在问题，已经导致AWR SANP都无法正常产生，于是老白先采集了一个ASH报告，希望能够从ASH报告中找到一些蛛丝马迹，实际上，除了不够详细外，ASH报告能够给我们一个较为完整的性能展示：

从ASH报告上看，最主要的问题有两个，一个是CPU+wait for cpu占了48%，另外一个一看就和DRM 有关。后面的gc buffer busy acquire应该和CPU高和DRM有一定的关系。从这里结合大量进程CPU开销很高我们会怀疑两个问题，一个是有大量的高开小的SQL和DRM导致了这个问题。这是一个EMS的巴枪采集系统，按理说不应该有很多大开销SQL的，出现这种情况肯定是不正常的。
因为马上就是双十一了，因此我们决定优化分为两期进行，第一期首先解决一些紧急的问题，确保双十一能够平稳。第二期从双十一后进行，继续进行深度优化。从上面的情况，我们立即制定优化策略，首先对核心业务系统相关的表，索引SQL进行分析，降低SQL的执行开销，减少CPU资源的使用；其次，通过关闭DRM防止类似问题再现。
对系统中采集的TOP SQL进行分析，发现大量占用CPU资源的SQL语句的执行计划是错误的，在并发量大时，所有CPU资源几乎被耗光。为什么会出现执行计划错误呢？我们检查了一下，索引都是存在的，不过没有正确的使用索引。于是我们检查了一下表的统计数据，发现表和分区的统计数据都是存在的，不过统计数据都存在问题，大量的分区的记录数都是0。

分区记录数为0的统计数据让CBO误认为全扫描分区的开销很小，NESTED LOOP的成本极低，从而更倾向于通过NESTED LOOP来进行表连接，从而导致了执行计划错误。在和开发人员交流的时候，我们发现业务核心系统表设计方法：大量关键交易与查询量大的表，均是设计为按每一天为单位的时间范围分区表，分区表提前很长一段时间就已经建立，业务基本都是对当日的分区进行数据插入与查询。于是我们检查了表分析JOB的情况，发现了当日数据没有统计信息错误的原因：该JOB运行为每日晚上10：00以后，当日10：00会对明、后几日的分区进行分析，但分析得出的结果都是“0”行，第二天大量数据插入，到达晚上高峰期时数据量已经很大，但是由于当日没有得到分析统计，所以大量SQL语句均是按表为“0”行来做SQL语句的执行计划
  例如：日期为2013年11月1日时，当日，及附近几日的分区表都是在10月23日统计的，表记录数都被标记为“0”。
既然发现了这个问题，就好多了，只要通过调整分区统计的JOB，就可以解决这个问题。下一步我们再看看索引是否存在问题。
一检查发现问题大了，创建索引的开发人员不了解索引的工作原理，因此在索引设计上存在较大的问题。特别是复合索引的字段顺序是随意的，导致SQL语句使用不合理的索引后，消耗大量CPU资源、产生巨大的GC事件，致使系统整体性能低下，例如：下面索引：


错误的将OPERATION_TIME字段放在了第一位，由于该表是按OPERATION_TIME做时间分区的，MAIL_CODE的选择性很高，使用OPERATION_TIME过滤后还是一整天的数据，作为第一个索引字段效果不好，而MAIL_CODE是一个邮件的编码，字段选择性十分好，大了的SQL的WHERE条件里仅针对MAIL_CODE进行过滤，并没有OPERATION_TIME这个过滤条件。此类问题在数据库中大量存在，是引发性能问题的重要原因之一。


DRM的问题也很容易定位，从下面日志中看出，数据库两个节点间不断的在发生REMASTER，此时，数据库基本处于冰冻状态，并且带来节点间网络流量传输巨大，使得性能瓶颈效应放大：

Thu  Aug 29 21:42:20 2013

Reconfiguration  started (old  inc 190, new inc 192)

List of  instances:

 1 2 (myinst: 1)

 Global Resource Directory frozen

 Communication channels reestablished

 Master  broadcasted resource hash value bitmaps

 Non-local Process blocks cleaned out

Thu Aug 29  21:42:20 2013

 LMS 4: 0 GCS shadows cancelled, 0 closed, 0  Xw survived

Thu Aug 29  21:42:20 2013

 LMS 3: 0 GCS shadows cancelled, 0 closed, 0  Xw survived

Thu Aug 29  21:42:20 2013

 LMS 1: 0 GCS shadows cancelled, 0 closed, 0  Xw survived

Thu Aug 29  21:42:20 2013

 LMS 5: 0 GCS shadows cancelled, 0 closed, 0  Xw survived

Thu Aug 29  21:42:20 2013

 LMS 0: 1 GCS shadows cancelled, 0 closed, 0  Xw survived

Thu Aug 29  21:42:20 2013

 LMS 2: 0 GCS shadows cancelled, 0 closed, 0  Xw survived

 Set master node info

 Submitted all remote-enqueue requests

 Dwn-cvts replayed, VALBLKs dubious

 All grantable enqueues granted

Thu Aug 29  21:42:40 2013

 Submitted all GCS remote-cache requests

 Fix write in gcs resources

Thu  Aug 29 21:42:50 2013

Reconfiguration  complete

Thu  Aug 29 21:45:07 2013

Reconfiguration  started (old inc 192, new inc 194)

List of  instances:

 1 2 (myinst: 1)

 Global Resource Directory frozen

 Communication channels reestablished

 Master broadcasted resource hash value  bitmaps

 Non-local Process blocks cleaned out

Thu Aug 29  21:45:07 2013

 LMS 4: 0 GCS shadows cancelled, 0 closed, 0  Xw survived

Thu Aug 29  21:45:07 2013

 LMS 3: 0 GCS shadows cancelled, 0 closed, 0  Xw survived

Thu Aug 29  21:45:07 2013

 LMS 2: 0 GCS shadows cancelled, 0 closed, 0  Xw survived

Thu Aug 29  21:45:07 2013

 LMS 0: 0 GCS shadows cancelled, 0 closed, 0  Xw survived

Thu Aug 29  21:45:07 2013

 LMS 5: 0 GCS shadows cancelled, 0 closed, 0  Xw survived

Thu Aug 29  21:45:07 2013

 LMS 1: 0 GCS shadows cancelled, 0 closed, 0  Xw survived

 Set master node info

 Submitted all remote-enqueue requests

 Dwn-cvts replayed, VALBLKs dubious

 All grantable enqueues granted

Thu Aug 29  21:45:29 2013

 Submitted all GCS remote-cache requests

 Fix write in gcs resources

Thu  Aug 29 21:45:40 2013

Reconfiguration  complete


针对上述问题进行优化后，系统性能得到了极大的提升，资源开销也有明显的下降：

11月1日优化前的CPU使用情况

11月4日优化后的情况

由于双十一临近，在客户的要求下，优化项目组暂停工作，暂时进入现场护航阶段。11月15日进入快递投递高峰期，业务量比平时高出三、四倍，系统负载随着业务量的上升而同样上升，受问题放大效应的影响，CPU再次接近100%，形成系统高负载。部分业务模块的响应速度下降数倍，业务部门投诉大幅增加：

于是客户要求优化小组再次对除了核心表外的其他存在类似问题的表进行同样的优化操作，经过第二轮的分析与优化处理，CPU在业务量上升三、四倍的情况下，负载再次下降三倍：

系统终于顶住了本次双十一的冲击。经过双11前的一次大优化，以及正当双11高峰业务量翻几翻之时的两轮大优化，以业务量回归正常后，系统负载显著下降，以下为2013年11月22日（周五）系统负载情况图：

在CPU负载从接近100%下降到15%左右后，系统的事务处理能力还得到了3.18倍的提升

指标名称

优化前

优化后

提升倍数

2013/10/31 19:00-20:00

2013/11/22 19:00-20:00

Transactions S

13.1

41.4

3.18倍


最后修改时间：2020-03-31 07:59:49
文章转载自 白鳝的洞穴，如果涉嫌侵权，请发送邮件至：contact@modb.pro进行举报，并提供相关证据，一经查实，墨天轮将立刻删除相关内容。

评论