一次MOSTLY LATCH-FREE SCN LATCH 问题分析

今天接到告警中间件侧反馈堵塞,通过查询相关日志,发现数据库上一条SQL出现了latch free的等待,该SQL执行时间大概持续了180秒。导致应用服务出现堵塞。

1) 通过收集SQLHC信息,发现该SQL在问题时间点存在很严重性能问题。问题时间点平均执行时长170秒,平均逻辑读1200万。

 
2)通过中间件日志,我们找到了当时调用的绑定变量。通过手动执行该SQL,发现在绑定变量和执行计划没发生改变的时候,SQL执行时快时慢。有时候能够迅速执行出来,有时候就会等待很久。通过观察,在异常执行时间段产生的等待事件是latch free。

而通过历史视图查询在出问题期间的event name是空的。但是可以看到等待事件p1和p2值。这里主要是看p2,p2的值是166。

 
通过查询v$latchname,可以发现166是一种叫mostly latch-free scn的等待事件。

 
而正常的时候是秒出的,基本看不到任何等待事件。

3)从历史的情况来看。这个问题主要出现过2次,一次是在8月27日,而另外一次是今天9月27日。而其他时间该SQL一直运行良好没出现任何问题。

 

问题解决:
1).根据当前的情况,目前怀疑是特殊场景下:(因为该等待事件和scn有关,怀疑可能是分布式事务问题,正好出问题期间也产生了一些tx锁和无效的分布式事务)导致触发了Oracle Bug,下午和Oracle工程师一起复现了这个问题,目前Oracle方面倾向于命中了Bug 9951190导致的。临时的workground是将参数_ktb_debug_flags从8改成0,但是因为该参数设置为8是为了阻止另外一个ora-00600问题。修改参数为0则很容易触发这个ora-00600问题,所以不建议修改参数。

2).通过在bcv上执行同样的sql语句,发现一个更好的执行计划。建议考虑执行sql profile先绑定。目前汇在16点40左右得到授权执行了绑定,绑定后已经执行了13次。sql性能运行良好。

SELECTsql_id,MODULE,cpu_time,elapsed_time,buffer_gets,sql_profile,last_load_time,executions FROM v$sql where sql_id='0jg8uq3w2d4v8';


 
目前暂时不清楚绑定该SQL之后, 是否仍然触发上述问题,需要再进行一段时间的观察。

3)最终解决问题的方法是安装补丁9951190

分享到: 更多

Comments 1

  1. justguo wrote:

    我们生产库也遇到了这个bug,但是,打补丁太麻烦了,看帮助是要先ADG库打,是吧。

    Posted 15 7月 2020 at 08:51

Post a Comment

Your email is never published nor shared. Required fields are marked *