ITPub博客

首页 > 数据库 > Oracle > Oracle数据库到底有多牛逼--技术人生系列第三十期-我和数据中心的故事

Oracle数据库到底有多牛逼--技术人生系列第三十期-我和数据中心的故事

Oracle 作者:记录每一次错误 时间:2018-12-03 14:30:36 0 删除 编辑

问题来了


电话响了 ,是一位证券客户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 语句长时间在执行, SQL AREA pin 住, MMAN 进程持有了 latch:shared pool 又不得不等,就容易导致其他进程无法获得 latch:shared pool 而引发问题。



当然,还有包括 ORACLE 内部实现动态机制的机制不够合理和高效等缺陷,也可能导致 SGA 动态调整引发问题。

实际上,小 y 的经验是,但凡涉及到内存动态调整的,不管是数据库,还是操作系统,都可能出现问题,例如操作系统的透明大页内存转换,就可能导致 kernel hang  

如果想要查 BUG, 从上文的分析中可以知道,大概搜索的关键字是 MMAN   进程、 latch Child shared pool   shrink CPU, 以此为关键字在 ORACLE METALINK BUG 库中查找相关 BUG ,与“   Bug 8211733- Shared pool latch contention when shared pool is shrinking [ID 8211733.8] ”中的描述吻合,但缺少 systemstate dump, 无法核对 call stack, 因此无法完全确认。

但具体到该 CASE ,核对 SGA 动态调整的具体 BUG 号的意义不大,因为 SGA 在各个版本中还是存在或多或少的问题,个别补丁不能完全预防隐患,最有效的解决办法时关闭 SGA 动态调整,使用手工管理的方式进行 ,同时为了避免关闭动态调整后的副作用,需要对应用进行对应的优化和调整。


7

头脑风暴之是否可以不关闭SGA动态调整来解决问题呢

各位看官不妨也想一想这个问题?

…………

…………

…………

…………

…………

…………

…………

…………

…………

…………

答案是当然可以,但是不知道能持续多长时间,因为应用可能在变, SQL 可能在变。

说可以,是因为,可以看到,该系统物理读高的 SQL 有不少,并且很多 SQL 单次执行时间超过 100 秒!如果 SQL 语句优化后, buffercache 就几乎不需要动态调大了,同时 SQL 优化后执行时间短了,需要 pin 的时间也短了,几个因素变好了,问题遇到的概率就小很多很多。

如果 SQL 语句短期无法优化和解决呢?

如下图所示,物理读主要集中在两张表,并且表不大,

因此可以通过 keep 到内存也可以解决物理读高导致动态调整的问题。

8

头脑风暴之如何避免关闭内存动态调整后的副作用

单纯的关闭 SGA 动态调整,意味着 shared pool 没有自动增大的机会,可能因为内存碎片化导致 ORA-4031 的几率增大,特别是对于硬解析较高的系统。因此,我们查看了该系统的硬解析情况。如下图所示:

可以看到,每秒硬解析达到了 22 次!说明 SQL 语句的共享性做的不好。

检查发现,如下图所示,该系统大量地用了 HINT HINT 中加入了一个随机生成的数据,这样就导致 SQL 语句无法被共享和重用。长远看,需要和开发沟通解决这类问题。

但是由于证券行业短周期内定期重启的特点,这个问题可以忽略。




问题原因与经验总结

在关闭 SGA 动态调整后(同时加大 shared pool ),长时间观察,

问题没有再出现,问题得到解决。


故障原因总结 :

1)         SID=598 MMAN 进程,在进行 SGA 动态调整,从 sharedpool 中挪动部分内存到 buffercache, 期间长时间持有 latch:sharedpool, 但由于长时间无法完成 sharedpool shrink, 导致其他进程无法获得 latch:shared pool, 从而出现问题

2)    导致内存需要动态调整的原因在于 SQL 语句的物理读很高, buffer cache 需要动态扩大, shared pool 需要收缩, SQL 语句执行又很长,需要长时间 pin 住,是触发问题的导火索。


经验总结:

1)         学会阅读 hangAnalyze trace, 将帮助你快速找到问题原因

2)         如果不想关闭 SGA 动态调整,则需要对于系统中出现物理读高的 SQL 进行优化或者 keep 物理读高的表到内存中

3)    对于每个调整,需要掌握其副作用,并根据情况作出关联调整

本文转载于中亦安图

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/31547066/viewspace-2222490/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论
性格开朗,有较强的学习能力,对oracle数据库的体系结构,搭建RAC,timesten,goldengate,分布式数据库,dataguard,系统调优有较深入的了解, 尤其是oracle优化,深入学习的主机命令,对数据库的优化,SQL语句的优化有深入的认识,目前正在shell脚本,mysql,以后会有计划学习大数据和python。

注册时间:2018-07-23

  • 博文量
    170
  • 访问量
    201309