通过关联x$kglcursorx$kglcursor_child_sqlid视图;
通过使用Oracle10035Event事件可以找到解析失败的SQL;
通过oraclesystemdump也可以找到解析失败SQL;
以下我们来看看这个精彩的案例分享。
背景介绍客户的一套重要生产系统,出现了性能问题。这个问题涉及的信息如下:
月底时候数据库主机的CPU利用率长期在100%左右。
数据库中出现大量的latch:librarycache竞争
系统概况
该系统为OLAPOLTP混合系统,平时为交易型数据库。每个网点实时数据上传,月底会有统计类报表产生。
以下为数据库负载曲线,可以看到在月底复杂急剧上升,导致业务不能正常操作。
以下为故障时间点部分AWR截图。
从LOADPROFILE看当前数据库每秒有158次的硬解析,总的解析在1082次。
这个时间点的TOP5等待事件中latch:librarycache与kksfbcchildcompletion排在前列,librarycachelatch占到将近有70%。
Latch:Oracle用于控制内存并发的串行锁机制
共享池latch竞争一般导致的原因有以下集中:
literalSQL所谓的literalSQL就是没用使用绑定变量值的SQL比如select*fromenmowhereid=100;
硬解析比如一个新执行的SQL没有在共享池中,那么就要经历一个硬解析的过程,关于过程这里就不在多讲
SQL不能共享,不能共享的原因有很多比如没有在同一个用户下面执行
SQLVERSION大量高版本SQL也会导致共享池的竞争
另外就是主机出现大量换页,比如在AIX环境下大量计算内存使用了SWAP会导致类似的问题
还有就是查询一些底层的视图比如x$ksmsp在某些版本下高并发的系统中直接查询这些视图会出现大量的latch竞争
还有就是SGA大量抖动或者模拟调整的时候也会导致此问题
Oracle各个版本上也存在相关的BUG会导致
根据以上几点我们去分析到底此问题出现在什么地方。
首先数据库等待事件除了librarycachelatch之后就是kksfbc
K[Kernel]K[Kompile]S[Shared]F[Find]B[Best]C[Child]
该函数用以在软解析时找寻合适的子游标,是否该故障是由于大量VERSIONCOUNT引起呢?
从这个时间点AWR来看没有看到大量versioncount的SQL出现。
分析latch的时候AWR有一个非常重要的数据。
从LatchMissSource的数据可以看到,绝大多数都是对于sharedpoollatch的sleeps,
从AWRSleep来看sharedpool排在了第一位。从调用的函数来看都是发生在硬解析这个过程中。
以下为一些常见函数的功能:
Kghfrunp:KGH:Askclienttofreeunpinnedspace
Kghdmp:x$ksmspisafixedtablebasedonkghmetadata.Thenumberoflatchsleepsfor"kghdmp"willincreaseifx$ksmspifaninstallationselectsfromthisfixedtabletoofrequently.
kghupr1:un-pinrecreatable
kghaloKGH:mainallocationentrypoint
kghgexKGH:Getanewextent
kghalfKGH:Non-recoverablyallocateafreeablechunkofmemory
有很多函数这里就不一一列举。
当前现在也可以排除人为查询底层视图导致的latch竞争因为没有看到相关函数出现,插播一个类似的案例。
像这种情况很明显就是有人查询了底层的视图导致的sharedpool竞争。
从主机最早的信息来看也是没有SWAP竞争出现的。
SGA没有大量的resize也可以排除掉由于SGA组件抖动引起的。
从以上信息,我们没有找到想要的结果,那么问题出现在哪里。
把上面几个原因都排除掉了,难道真是遇到OracleBUG了么。
有的时候分析问题会陷入一些误区,比如一个数据库出现大量的latch竞争导致会话飙升然后把process撑满,从timemode里面来看的话可以发现95%都是花费在了连接上面,那么到底是大量不正常的连接(比如连接泄漏)导致了数据库出现竞争呢,还是数据库出现问题导致会话不能等了然后不停的重连导致了问题呢。
从这个库这个时间点的timemode可以发现75%的dbtime都是花费在了解析上面,这也是没有问题的因为这个时间点数据库竞争就出现在解析上面,但是为什么其中有38%的dbtime发生在解析失败上面呢,也就是总共解析的一般时间都是错误的解析。硬解析只有5%左右。
我们来看一张正常时间点的timemode。
从这个趋势图库看到解析失败一直是跟着硬解析的次数而增加,并且每天都在上班之后开始发生。
数据库正常时间点硬解析也只有不到5%左右,也就是硬解析没有大的变化,但是解析失败确认翻了几倍。是什么原因导致这么多的解析失败呢?另外解析失败的SQL是否会导致大量latch竞争?解析失败的SQL是否会在共享池中存储?怎么查询到解析失败的SQL?
很多时候我们会有这样一个误区,既然语法错误或者对象不存在应该在语法语义检查这个步骤就挂了怎么还好存在共享吃里面呢?带着这个几个问题我们做几个简单的测试。
我们先了解下什么是解析失败的SQL。
那么怎么证明就是解析失败的SQL存在共享池中并且在解析的时候持有librarycachelatch呢?
做下面测试之前我们先回顾一个Oracle一些基本概念。
Librarycache是sharedpool中的一块内存区域,主要作用就是缓存执行过的SQL语句所对应的执行计划信息等信息。当同样的SQL再次执行时候可以直接利用已经缓存的相关对象不需要再从头解析。
Librarycache对象句柄是以hashtable的方式存储的,存储方式如下图:
当sql执行时候,首先会对sql文本进行hash运算然后根据hash值去相关hashbucket中遍历,如果找到了就直接用该sql缓存的执行计划等,如果找不到则从头解析,并把解析后执行计划等缓存在hashbucket中。
下面这几张图片展示了一个SQL解析的过程。
SQL的内存结构
我们知道SQL语句必须至少是一个父游标一个子游标存在的,当然生产中很多情况下都是一父多子的情况。
父游标与子游标结构是一样的,区别在于sql文本存储在父游标对应的对象句柄中,而sql的执行计划等信息存储在子游标对应的库缓存对象句柄heap6中。另外父游标的heap0中存储着子游标的句柄地址。如果解析错误的SQL在共享池中存储的话那么必然要产生一个父游标然后父游标里面存储的有SQL文本之类的信息,但是子游标的?既然解析失败那么就没有产生执行计划。
关于heap0中信息可以参考如下图:
父游标句柄对地址可以在x$kglob视图中查询到,KGLHDPAR=KGLHDADR的记录为父游标
X$KGLOB
该视图定义为[K]ernel[G]eneric[L]ibraryCacheManager
KGLHDADRRAW(4|8)Addressofkglhdforthisobject
该地址000007FF11937C90为select*fromenmoSQL的父游标的句柄地址。
可以看到:
KGLOBHD0RAW(4|8)Addressofheap0descriptor
KGLOBHD6RAW(4|8)Addressofheap6descriptor
上面查到的就是该SQL父游标的信息,父游标的kglobhd0的地址为0000000075489AE8
该句柄地址记录的信息很多包含了子游标的信息。
找下该SQL子游标的信息:
子游标heap6的地址为000000007625FBF8句柄中存储的也就是执行计划相关的信息。
通过以上测试我们很容易找到sql的父游标的句柄还有子游标的句柄在内存中的地址。
下面做另外一个简单的测试解析错误的SQL是否有父游标还有子游标生成。
可以看到是可以查询到信息的,也就是有父游标的句柄为00000000754453B8heap0的地址为0000000075485620.
可以看到是有错误的文本信息的内存地址,但是子游标呢?
可以看到是没有子游标产生的,因为该SQL执行错误不会有执行计划相关信息出现。
从x$kglob也可以查到kglobhd0kglobhd6都为空。
在x$kglcursor_child视图也查不到任何信息的,v$sqlv$sqlare类似的视图也就查不到解析错误的SQL了。
关于解析错误的SQL是否需要获取latch其实从上面的测试已经证明了还是要获取sharedpool的latch的因为生成了父游标。
回顾以下SQL硬解析过程中需要获取的latch.
首先持有librarycachelath,在librarycache相关hashbucket中扫描已经缓存的对象句柄,查找是否有匹配的父游标,没有找到释放librarycachelatch.
接着持有librarycachelatch然后不释放情况下持有sharedpoollatch从sharedpool中申请分配内存成功后是否sharedpoollatch再是否librarycachelatch.
还以上面那个错误的SQL为例做一个简单的测试。
首先获取librarycachelatch然后运行sql查询。
这个时候会话已经hang了。
怎么找到解析失败的SQL?
通过关联x$kglcursorx$kglcursor_child_sqlid这两个视图是可以找到解析失败的SQL
通过使用Oracle10035event事件也是可以找到解析失败的SQL
通过oraclesystemdump也可以找到解析失败SQL
当然最后该问题定位到了相关解析失败的SQL,该SQL主要是在月底某一模块批量跑的时候大量的执行,最后修改应用程序代码解决了问题。
通过这个简单的案例可以看到不规范的开发习惯给数据库带了严重的性能影响。像类似这种解析出错的SQL在很多客户核心系统中比比皆是但是由于种种原因不能及时去除类似的SQL最终将带来灾难性的影响。