OLM·BUG原因引发的性能故障分析与处理案例

导读：东方龙马致力数据库 | 中间件领域20余年，积累很多宝贵的业内经验和专业人才，今天由东方龙马高级工程师阮文强，向大家讲述一次因BUG原因引发的性能故障分析与处理案例。希望对你有所帮助。

一般情况下，对于ORACLE数据库来说，一说到性能问题，我们都是联想到是否SQL执行出现了性能问题？是否配置不合理？是否CPU和IO等操作系统资源使用出现问题？但最近我们遇到了一个由于ORACLE BUG引发的数据库性能问题。

背景：用户反馈有一套系统运行很慢，包括所有的操作如一般的登录、查询、编辑、报表输出都突然变得很慢，开发人员和运维人员都做了相关的检查和一般分析，但都没发现任何可疑的地方，开发人员还对中间件tomcat服务器进行了重启，运维人员也对ORACLE数据库服务重启。重启后，系统仍然很慢，最终用户不断的抱怨。

根据技术人员的反映和之前的操作，我们第一分析就是检查分析当前系统资源使用情况，发现包括Cpu、IO、内存均使用正常，然后开始把焦点放在数据库本身。

首先，从数据库中抓取AWR报告，确认一下整体上的性能问题，整体数据库时间消耗如下：

我们可以看到，一共收集了60分钟的报告，DB TIME即数据库实际运行时间占到了532分钟，即相当于差不多9个线程核的CPU满负载运行。根据我们对这套系统了解，业务量一般不大，数据库压力也不大，我们暂时确认是数据库整体上性能问题，并判断可能是锁（包括lock锁和Latch锁）资源等待问题，然后进一步看等待事件：

参考：row cache lock 解释：

Row Cache Lock：

When DDLs execute, it must acquire a row cache latch to lock the Data Dictionary information. The shared pool contains a cache of rows from the data dictionary that helps reduce physical I/O to the data dictionary tables.  This allows locking of individual data dictionary rows. 

我们根据后台等待事件发现，row cache lock等待事件占了87%以上，占了运行时间27841秒，相当于约450分钟以上，占了所有运行时间的约87%（27841/(532*60)=87.2%）。理论上这个事件是不能出现在TOP 5事件中的，说明当前系统性能差、数据库运行时间消耗时间长都是由row cache lock等待事件引发起。我们再去看整体时间使用模型：

Time Model Statistics

• Total time in database user-calls (DB Time): 31932.9s

• Statistics including the word "background" measure background process time, and so do not contribute to the DB time statistic

• Ordered by % or DB time desc, Statistic name

根据时间模型数据，可以看到60分钟之内，用于SQL或PLSQL解释的时间就占了80%以上，即25552秒，我们可以推测出由于与共享池相关的row cache lock等待事件导致了SQL解释出现问题，并最终大量的SQL运行变成缓慢，从于引发了系统的整体上性问题。

根据上面的分析数据，我们第一步就是先确认数据库配置是否存在问题，对于我们认为不合理的配置，就是调整到相对合理或我们认为合理的配置。对于当前的配置数据，我们主要对SGA和相关的内存组件进行了调整，调整配置如下：

同时，对操作系统内核的一些参数据进行了调整：

通过调整后，根据对数据库的监控，系统性能有一点提升，可没从实质上解决整体上系统慢的性能问题。

我们继续深入分析，通过hanganalyz level 3进行跟踪，得到相关TRACE文件，关键内容如下：

我们发现，当前大量的会话都是在等待nodenum=349(session id=350)的会话，然后再看具体会话TRACE信息，如下：

从上面的信息我们发现，上面row cache lock 的引发主要是由于在执行常规SQL语句等待另一个会话（SID=350）释放相关资源，可我们发现SID=350的会话当前却未执行任何SQL，而且是空闲等待，这是非常不合理的。

这时，我们可以初步确认：当前的性能问题和相关的SQL执行并没有直接联系，很大概率是ORACLE的内部运行机制出现问题，即可能是BUG的问题！

我们通过METALINK发现该问题进一步确认是BUG方面的问题，如下：

注：具体见METALINK DOC ID：1162566.1

从上面的信息我们发现，当前系统问题与BUG 9776608有一定的符合性：

• 当前版本都是11.2.0.0.1

• 出现大量row cache lock，而且都是短的大量的row cache lock等待。

• 通过进一步分析系统底层调用都是ksedsts()+644<- ksdxfstk() +44<- ksdxcb()……等函数开头。

根据文档要求，该问题可升级到11.2.0.2以上版本或安装补丁包patch9776608解决问题。

随后，我们配合运维人员进行系统ORACLE数据库基于PSU补丁升级：

1. 考虑到当前系统最新版本，我们直接把数据库升级到11.2.0.3.4版本。

2. 考虑到系统升级的安全性，我们先对测试环境进行PSU补丁的升级，然后再对正式环境进行升级。

完成升级后，对系统进行监控，确认性能问题得到彻底解决！

附录：问题解决后前后性能对比解释

我们同样收集系统相对压力比较大的时间段1小时的工作日志，DBTIME 只运行 59分钟，为存在性能问题时间段（之前同一时间段DBTIME为532分钟）的10分之一左右。

在TOP 5事件中，不再存在row cache lock等待事件！

Time Model Statistics

• Total time in database user-calls (DB Time): 3545.3s

• Statistics including the word "background" measure background process time, and so do not contribute to the DB time statistic

• Ordered by % or DB time desc, Statistic name

在整个系统时间模型中，解释的时间仅占到数据库运行时间的6.16%，比之前的80%以上下降了75%以上。

生成海报

免责声明：本网站内容主要来自原创、合作伙伴供稿和第三方自媒体作者投稿，凡在本网站出现的信息，均仅供参考。本网站将尽力确保所提供信息的准确性及可靠性，但不保证有关资料的准确性及可靠性，读者在使用前请进一步核实，并对任何自主决定的行为负责。本网站对有关资料所引致的错误、不确或遗漏，概不负任何法律责任。任何单位或个人认为本网站中的网页或链接内容可能涉嫌侵犯其知识产权或存在不实内容时，应及时向本网站提出书面权利通知或不实情况说明，并提供身份证明、权属证明及详细侵权或不实情况证明。本网站在收到上述法律文件后，将会依法尽快联系相关文章源头核实，沟通删除相关内容或断开相关链接。