一分钟查一个案例带你看看Oracle数据库到底有多牛逼性能难题

一分钟查一个案例带你看看Oracle数据库到底有多牛逼

性能难题

问题来了

电话响了，是一位证券客户 DBA 的来电，看来，问题没过两天，又出现了。 接起电话，果不其然。

“小y,前天那个问题又重现了。重启后恢复正常，这次抓到了hangAnalyze,不过领导在身后一直催，所以没来得及抓取 systemstate dump 就重启了。你尽快帮忙分析下吧，hanganalyze 的 trace 文件已经转到你邮箱了。”

就在 2 天前，该客户找到小 y, 他们有一套比较重要的系统出现了数据库无法登陆的情况，导致业务中断，重启后业务恢复，但原因未明，搞的他们压力很大。

可惜的是，他们是事后找过来，由于客户现场保护意识不足，最后也只能是巧妇难为无米之炊了… 总的来说，小 y 还算是比较熟悉证券行业的。

毕竟，小 y 多年来一直在银行、证券、航空等客户提供数据库专家支持服务，这其中就包括了北京排名前 6 的所有证券公司。

简而言之，证券行业的要求就是快速恢复，快速恢复业务大于一切。

原因很简单，股价瞬息万变，作为股民，如果当时无法出售或者购买股票，甚至可能引发官司。所以，证券核心交易系统如果中断时间超过 5 分钟，则可以算得上是严重故障了，一旦被投诉，则可能会被证监会通报，届时业务可能被降级，影响到证券公司的经营和收益。

结合这个特点，小 y 为客户制定了应急预案，看来收集 systemstate dump 是来不及了，只能先收集 hangAnalyze, 时间来得及的话则可以继续收集 systemstate dump。收集 hangAnalyze 的命令很简单，照敲就是了，没什么技术含量。

$sqlplus –prelim “/as sysdba” SQL>oradebug setmypid SQL>oradebug hanganalyze 3 .. 此处等上一会 ..

SQL>oradebug hanganalyze 3 SQL>oradebug tracefile_name

开启分析之旅

1、 hanganalyze 初体验

打开附件，内容如下，中间部分太长了，所以用省略号代替。

朋友们，不妨自己停下来，耐心阅读一下，看看是否可以看的明白。

很快，根据这个 trace, 小 y 在一分钟找到了问题原因。

而这种问题，在其它数据库中属于很难查清的问题。

所以不得不说，Oracle 的 hangAnalyze 是如此的牛逼…

问题原因就在后面，什么时候往下翻，由你决定…

2、 如何开始

先看 trace 的第一部分，如下所示：

上面的信息为出现异常时数据库的整体状态摘要，这些信息表示：

1） 共 76 个会话被 sid=494 的会话阻塞，原因是 sid=494 的会话本身申请 latch: shared pool 资源时被其他会话阻塞。

2） 共 22 个会话被 sid=496 的会话阻塞，原因是 sid=496 的会话本身申请 latch: shared pool 资源时被其他会话阻塞。

3） 共11个会话被sid=598的会话阻塞，”No Wait”表示sid=598的会话本身并未等待任何资源，即该进程在使用 CPU。

4） 共 13 个会话被 sid=518 的会话阻塞，原因是 sid=518 的会话本身申请 latch: shared pool 资源时被其他会话阻塞。

用一张图来表示，如下所示：

3、找到阻塞的源头

会话 494、496、598、518 之间可能相互独立，也可能存在互相阻塞的关系。 小 y 带着大家继续往下梳理。

从抓取到的 hanganalyze 信息摘取上述会话信息的细节，如下所示 :

在该信息中，关注 4 列的内容即可，其中：

第 1 列为 oracle 给 trace 中每一个会话所取的唯一逻辑标识；第 3 列表示会话 sid； 第 6 列表示操作系统进程号；

第 10 列表示阻塞该会话的唯一逻辑标识，为空时表示无阻塞。

因此，从上述信息可知：

1)sid=494 的会话被唯一逻辑标识为 597 的会话阻塞 2)sid=496 的会话被唯一逻辑标识为 597 的会话阻塞 3)sid=518 的会话被唯一逻辑标识为 597 的会话阻塞而唯一逻辑标识为 597 的会话信息为 :

即唯一逻辑标识为 597 的会话的 sid=598, 操作系统进程号 553382，该行的第 10 列为空，即再也没有其他会话阻塞 sid=598 的会话。

也就是说，sid=598 的会话就是数据库异常时的会话获取资源时阻塞的源头。如下图所示：

4、 陷入僵局？（阻塞的源头只是一个数字！）

前面的分析，已经找到了源头是 SID=598 的会话。

那么 sid=598 的会话是什么用户什么程序什么机器发起，在执行什么 SQL，进程的 callstack 是什么呢？所有这些信息，我们都可以在 systemstate dump 中可以找到，但可惜的是，客户虽然由于时间关系没有来得及抓取 systemstate dump，因此无法进一步获取该进程的信息。

悲剧了！难道要再一次陷入巧妇难为无米之炊的尴尬境地么？如果是你，你会怎么办，此处不妨思考几分钟…

5、 找到打开天堂大门的钥匙

打开天堂之门的钥匙有很多把，但上帝总是会眷恋把握细节和用心的人。难道因为缺少 systemstatedump 就放弃了么？那客户怎么办？

这里介绍其中一把钥匙，当然还有其他钥匙，如果你也找到了其他钥匙，不妨留言告诉小 y。继续看阻塞源头的相关信息。

SID=598 的会话，在操作系统上的进程号是 553382。 一个进程要么是前台进程（服务进程），要么是后台进程。

如果是后台进程，则我们可以在 alert 日志中，找到操作系统上进程号是 553382 对应的后台进程到底是什么！

打开 alert 日志，果然不出所料，凶手真的是他 如下所示 :

因此，造成数据库异常的源头就是数据库后台进程 mman 进程 !

即负责 ORACLE 内存动态调整的后台进程！

该 进 程 在 数 据 库 中

负责 SGA 内存在各个组件比如 buffer cache 和 shared pool 之间的动态调整。通俗的来说，我们在配置数据库所使用的相关内存参数时，在 10g 版本之前，需要手工设置 buffer cache 和 shared pool 的大小，但是 10g 版本后，为了简化管理，可以只设置 buffer cache 和 shared pool 加起来的总内存大小，不需要关注单独为 buffer

cache和shared pool设置多大的内存，数据库后台进程mman进程可以在两者之间根据需要动态调整。

很多客户都默认地选择了这样一种智能但并不完美的内存管理方式。 那么整个系统中，是否有出现 SGA 内存动态调整的情况呢 ?

摘取问题当天其他时段，例如 15 点到 16 点之间的 AWR 报告，观察该系统的情况。 （数据库重启后无法观察到问题时段 v$sga_resize_ops 了）

从 中 可 以 看 到，shared pool 在 15 点时的大小为 3584M，到了 16 点就已经被动态调整到了 1760M, 这些就是由

后台 mman 进程来完成的。如此大幅度的下降，说明期间经历过多次的调整，不断的对 shared pool 进程 shrink 操作。

那么到底是 sharedpool 中的哪部分内存被挪到了 buffercache 呢？从 AWR 报告的 SGA breakdown difference 可以看到： SQL AREA 从 2088M 降至 370M，被刷出了 82% ！

SQLAREA 大量的内存被挪走，SQL 语句 ( 含登陆的递归 SQL) 必然被大量刷出，后续需要硬解 析（hanganalyze 可 以 看 到 有 latch:shared pool）。

6、进一步分析原因

根据上述分析，有一个问题仍然需要确认 : 那就是为什么 SGA 动态调整导致如此严重的问题？

这明显与 ORACLE 的 BUG 相关。

当发现整个系统 buffer cache 命中率低、物理读高的时候，buffer cache 需要从 shared pool 中借走部分内存（由 MMAN 进程来负责完成动态调整）。

当需要借走的 granula 属于 shared pool 的 SQL AREA, 但是由于 SQL 语句长时间在执行，