技术人生系列·我和数据中心的故事（第十二期）-风险预警·如何预防开发问题流到生产

     客户新投业务模块，需要做压力测试，在测试压力并不大的情况下，数据库的性能竟然很差。其中 AWR 报告显示有大量的异常等待事件，客户首先怀疑的是数据库配置不合理导致的，于是第一时间收集了相关信息发了过来。

     首先，我们来看看 AWR 报告能提供的信息：

     图中显示 10 分钟的 AWR 报告中， DBTime 繁忙达到了 385 分钟，那么真的是从应用端上来的压力太大吗？

    继续检查发现系统的CPU时间还是很低的，可以认为数据库平均才使用0.6颗CPU，大多时间还是花费在了等待上；

     接下来查看TOP等待事件：

     主要的等待事件是在 cursor:pin S wait on X 和 library cache lock 上，两项分别占了 DBTime 的 42.8% 和 32.3% ，均与解析相关，此点可以在 AWR 报告的 time model 部分中进一步确认：

     报告中的 Load profile 告诉我们每秒的硬解析次数达到 200 次，这个数据一定会出现问题！！！

     压力测试理论上是不应该出现大量硬解析的，老猫猜想是不是应用设计不合理（比如没有使用绑定变量）导致的呢？

     但是当看到 AWR 报告中的 “ Library Cache Activity“ 部分时，发现 SQL AREA 部分存在大量的 Reloads   和 Invalidations 时，果断的推翻了之前的猜测。

于是我们进一步收集 ASH 报告中问题时刻的 librarycache lock 等待对象的 namespace ；

     从数据中可以看出： P3 值为 5373954 ，将其转换为 16 进制就是 0x520002 ，将 0x52 继续转为 10 进制就是 82 ；

在 ASH 报告中，问题发生在『 SQL AREABUILD 』这个 NAMESPACE 上，这块内存是在构建 Child Cursor 时请求的，如此频繁地出现，基本可以排除收集统计信息， DDL 引致的硬解析，但我们依然要求证！幸运的是，客户 DBA 非常资深，顺便给了 systemstate dump ；

从 中看到 一条关键记录 ：

     这是一个存储过程，硬解析次数 334108 次， cursor 失效次数 334107 次，执行次数 次，明显的 解析失败 。

   再回过头来看之前的 time model ，还是能看到存在的错误解析的情况：     强调一下： 作为一个负责任的第三方运维工程师，必须要要协助客户把问题缩小到最小粒度，才能准确定位硬解析失败的原因。

那么新的问题来了：解析失败，对于一个比较复杂的存储过程来说，我们怎么快速的定位到是什么语句什么原因导致的失败解析呢？

答：   oracle 提供了一系列的跟踪事件来帮助定位各种问题，下面介绍的这个方式一定可以找到一些 event 来进行跟踪：

    搞定，原来 10035 事件可以帮助到我们，那么我们只要在系统级设置上 10035 事件就可以了：

  因为客户也是一位资深的 DBA ，主要的原因已经找到，余下的事情自然就不需要我们帮忙，最后他从 alert log 果然找到了解析错误的 SQL ，并且解决了问题。