缓解latch: cache buffers chains的案例

这两天我们的一个核心系统U*S，正在做压力测试，虽然压测的服务器配置不如生产，但可以反映出一些问题，初始测试的TPS可以说非常低，据测试同事反映，压测一会，数据库服务器CPU就上来了，业务上有积报现象，找不着原因。

既然数据库服务器CPU飙升上来了，说明数据库服务器上有压力，这就需要看压测期间，数据库有何负载变化。Oracle提供了我们非常丰富的工具，AWR就是其中之一，可以让我们了解特定时间段，数据库相关负载信息，具体使用方法可以参考《一个执行计划异常变更的案例 - 外传之AWR》。

测试数据库服务器配置是8C16G，Oracle 11.2.0.4，

CPU花费了282.66/8*50.97*100%=69%在处理Oracle的操作上(主要指非空闲等待和运算上(例如逻辑读))，这不包含一些后台进程。说明当前数据库负载有些高，(DB TIME说明可参考http://www.eygle.com/digest/2009/02/awr_db_time.html)。

注意：由于采集AWR的问题，其实压测时间要<50分钟，因此数据库实际负载>69%。

看下Load Profile，显示50分钟的逻辑读有17万次，平均每次事务有1300次逻辑读，看起来比较高，硬解析次数低，基本排除绑定变量问题，支持TPS约为134，

看下等待事件，log file sync事件，看了下磁盘性能还可以，可能和测试用例，都是一些小事务有些关系，

排名靠前的出现了latch: cache buffers chains、buffer busy waits这些，参考这篇文章，Troubleshooting 'latch: cache buffers chains' Wait Contention (文档 ID 1342917.1)，

"latch: cache buffers chains" contention is typically encountered because SQL statements read more buffers than they need to and multiple sessions are waiting to read the same block. If you have high contention, you need to look at the statements that perform the most buffer gets and then look at their access paths to determine whether these are performing as efficiently as you would like. Typical solutions are:-

• Look for SQL that accesses the blocks in question and determine if the repeated reads are necessary. This may be within a single session or across multiple sessions.
• Check for suboptimal SQL (this is the most common cause of the events) - look at the execution plan for the SQL being run and try to reduce the gets per executions which will minimize the number of blocks being accessed and therefore reduce the chances of multiple sessions contending for the same block.
• If you can identify a poor SQL and have identified a better plan, you can direct the optimizer to use this plan using the following article: Document 1400903.1 Directing Plans with Baselines/Profiles Using coe_load_sql_baseline.sql / coe_load_sql_profile.sql (shipped with SQLT)

意思就是，latch: cache buffers chains出现，意味着有SQL语句需要读取比他所需要更多的buffer，并且有许多会话等待读取同一个块。

提醒我们是否有SQL占用的逻辑读很高，这就需要我们来看一下SQL ordered by Gets。

果然第一条SQL语句是一条SELECT操作，每次执行的平均逻辑读消耗1522次，一共执行了32万次，总计消耗4亿9千万逻辑读，占用了总逻辑读比例的92%，这里我们想说的是，这条SQL是为了解决逻辑读过高，首要关注的SQL，

MOS中提到了，有可能这个Top SQL就是需要关注的，但有可能需要关注的语句，执行次数低，所以未必出现在Top SQL中，此时就需要看其他语句了。

Note: This is a simple example where there is a high likelihood that the 'biggest' query is the culprit but it is not always the 'Top' SQL that causes the problem. For example, contention may occur on a statement with a smaller total if it is only executed a small number of times so that  it may not appear as the top sql. It may still make millions of buffer gets, but will appear lower in the list because other sqls are performing many times, just not contending. So, if the first SQL is not the culprit then look at the others.

73jjhum06b7pr对应的SQL(屏蔽了其中的业务字段)，

select a, b, c ... z where ID = :1 and RECORD_LOCATOR = :2 and ABO = :3

此时可以打出SQL AWR报告，参考《一个执行计划异常变更的案例 - 外传之SQL AWR》，这一条SQL有两个执行计划，一个是全表扫描，但他的执行次数是0，另一个是索引扫描，用的是ID这个字段的单键值非唯一索引。

从这部分来看，对应的就是这条SQL涉及的表和索引，

现在知道了消耗逻辑读最高SQL，是否可以降低？进一步分析下，这条SQL语句的执行计划，提示使用索引预计返回了1条记录，回表找出了1条记录，这么看效率很高啊？

看一下表的统计信息，显示表的记录数是15万，可实际表的数据量是200万，这是因为测试需要，临时增加的数据，每日定时任务22:00才会开始自动收集统计信息，因此在这之前，统计信息是不准确的，这也是为什么一些大牛建议，当出现批量数据变化的情况下，应该立即手工收集统计信息，顺带插一句，每天22:00自动进行的统计信息收集，也不是所有的表都会进行，只会根据user_tab_modifications中记录的增删改数据量超过10%或者出现过truncate的，才会符合自动收集的条件，这可以参考dbsnake的书。

立即手工收集一下这张表和对应这个索引的统计信息，另外，根据和开发人员的咨询，了解到这条SQL的三个where条件字段关系，其中ID是一个单键值的非唯一索引，但每一个ID值，由于测试数据的问题，会有1万条匹配的记录，而实际中每一个ID值只会有200左右的记录，RECORD_LOCATOR是一个数值类型，ABO是一个字符串类型字段，但其有一个特点，就是每一个ID值，对应只有一个唯一的ABO值。

了解了以上信息，我们看一下执行计划，执行步骤简单，第一步根据ID字段的索引，找出符合条件的记录，第二步根据第一步的结果集，即对应这些记录的rowid，回表找出符合条件的数据记录，同时使用过滤条件RECORD_LOCATOR和ABO，进行过滤处理了，返回结果检索集至前端，完成这条SQL的执行操作。

其中的问题就在于第一步，根据ID检索出的结果集有1万条，但实际只有200条左右，然后需要回表，找出这1万条记录的数据，根据过滤条件，得出检索结果，相当于测试期间需要加载至buffer cache的数据量是真实环境中的50倍，这条SQL执行的次数又是非常高，累积起来对逻辑读消耗的贡献，就会非常显著，进而会成为CBC(latch: cache buffers chains)等待事件的主要诱因之一。

优化这条SQL降低逻辑读的目标，就是要避免读取无用的数据，刚才我们说了，测试环境下，一个ID会对应1万条记录，但根据ABO一个条件，就限制了结果集只有一条，既然如此，若建立一个ID和ABO的复合索引，岂不第一步，根据索引范围扫描的时候，就可以限定只有一条记录，而且和开发人员的交流中，发现业务上一种是根据ID和ABO符合检索的场景，一种是根据ID单条件检索的场景，那么这种ID和ABO的复合索引，两种场景均可以满足，并且可以删除ID这个索引。

删除这一个ID单键值索引，新建这一个ID和ABO复合索引，虽然如下测试时间不同，但可以看出来，逻辑读已经下降了，TPS则提升了，

等待事件中CBC数据，也是有所下降，

这条SQL每次执行消耗逻辑读，从原来1522次下降为3次，说明仅针对此条SQL的优化是起了作用，

截至目前，业务要求的TPS已达到了，当然这有一个问题，就是可能优化了这条SQL，缓解了这个等待事件，立即会有其他问题暴露，此消彼长，优化是一个循序渐进，又可以是一个点到为止的活，底线是可以满足业务要求，毕竟技术是为业务服务的，主要矛盾还是要优先解决。

以下MOS文章和CBC相关，可以了解下，

Understanding and Tuning Buffer Cache and DBWR (文档 ID 62172.1)

WAITEVENT: "latch: cache buffers chains" Reference Note (文档 ID 2098064.1)

How to Identify Hot Blocks Within the Database Buffer Cache that may be Associated with 'latch: cache buffers chains' Wait Contention (文档 ID 163424.1)

总结：

1. 碰见数据库性能问题，AWR、SQL AWR以及ASH，是非常有用的工具，可以帮助我们了解数据库。

2. latch: cache buffers chains这种等待事件，说明可能有SQL语句，消耗了非常高的逻辑读进而导致buffer cache中的缓存latch被并发会话争抢，latch是一种轻量级的锁，主要用于缓存的并发控制，当然系统资源等因素，也可能会导致这个问题，需要结合AWR整体来看问题，不能以一概全，要综合起来。

3. 往往解决了一个问题，其他问题就暴露出来了，这很正常，重要的是要以业务为导向，不能一味的追求技术，点到为止，未尝不是目标。当然就我自己的功力，还谈不上能点到为止，重要的还是从每一次实践中，学习到一些知识，努力提高自己思考和真正解决问题的能力和方法，这才是最有意义、最有价值的事。

如果您觉得此篇文章对您有帮助，欢迎关注微信公众号：bisal的个人杂货铺，您的支持是对我最大的鼓励！共同学习，共同进步:)