性能分析之子锁存器（latch）到 SQL（Oracle）

Posted 2022-01-06 zuozewei

这几天碰到一个事情，有必要记录一下。
在一个项目中，压力测试工具中一个业务响应时间变长，数据库（Oracle）CPU 使用率 99 %以上。

从 AWR 报告上看到如下信息：

在性能项目的沟通中，经常是在这样的时候，我们就去告诉开发说现在的状态是 CPU 使用率高，把 AWR 报告往开发那里一发，性能团队的人员就喝咖啡去了。
但是性能如果只是做到这里，沟通其实没有在同一个界面上。
在这个典型的沟通过程中，上述结果也确实发给开发了。
开发反馈说，是因为在场景执行过程中表的数据量发生了变化，导致了 SQL 的执行计划发生了变化，进而导致了SQL慢，进而导致了latch: cache buffers chains的出现。所以要解决的话，要对数据库进行一次analyze，然后再测试。
​

在上述的背景中，看似没有漏洞，合情合理。
但是，恰好碰到我这偏执的人，我要看到 证据链。
在沟通的来往中，我并没有看到证据链，这是我觉得不好的地方。哪里没有证据呢？就是数据量发生了变化导致了SQL的执行计划发生了变化。
如果有这样的怀疑，就要去证明这个怀疑是对的。
于是我查了 SQL 计划的历史变更记录。
​

根据 SQLID 查看执行计划的变更记录：

selectDISTINCT SQL_ID,PLAN_HASH_VALUE,TO_CHAR(TIMESTAMP,'yyyymmdd hh24:mi:ss') TIMESTAMPfrom dba_hist_sql_plan where sql_id='1wfsd2q8wc5uu'orderbyTIMESTAMP;

                  SQL_ID   PLAN_HASH_VALUE              TIMESTAMP
1                1wfsd2q8wc5uu    4188019746           2018040118:08:09

​

查询更详细的执行记录变更记录（我把结果中的时间戳删掉了，为了格式整齐点）：

select plan_hash_value,id,operation,options,object_name,depth,cost,TO_CHAR(TIMESTAMP,'yyyymmdd hh24:mi:ss') from dba_hist_sql_plan where sql_id='1wfsd2q8wc5uu'and plan_hash_value in (4188019746) orderbyID,TIMESTAMP;

PLAN_HASH_VALUE	ID	OPERATION	OPTIONS	OBJECT_NAME	DEPTH	COST
1	4188019746	0	SELECT STATEMENT			0	2
2	4188019746	1	FILTER			1		
3	4188019746	2	FAST DUAL			2	2	
4	4188019746	3	TABLE ACCESS	BY INDEX ROWID	TABLE1	2	0	
5	4188019746	4	INDEX	RANGE SCAN	TABLE1_IDX1	3	0

这个 SQL 的执行计划，只有 4 月 1 日一条记录，在最近几天的测试中，并没有发生变更。
这就是我要说的证据链，当给出执行计划发生变化这个结论时，就必须给出证明，而实际的数据证明这个结论是错的。
​

下面我们就来分析下怎么才是对的。
既然是 latch: cache buffers chains，首先我们得知道这个值是什么意思。
简单回忆下 latch 的原理（如下部分是在网上抄的）：

当一个数据块读入到SGA中时，该块的块头（BUFFERHEADER）会放置一个HASHBUCKET的链表（HASHCHAIN）中。该内存结构由一系列cachebuffers chains的子latch保护。对BUFFERCACHE中的块，要SELECT/UPDATE/INSERT/DELETER等操作都得先获得cachebuffers chains的子latch，以保证对CHAIN的排他访问。若在过程中发生争用，就会出现latch:cache buffers chains事件。

这个值的出现有两个含义：

1. SQL的执行效率低（因为 SQ L低效，在并发会话时，无法得到相同的数据集，SQ L执行时带有高 BUFFER_GETS 会导致 latch争用）。
2. 数据热块。

​

这是两个完全不同的处理方向。
第一个处理方向，考虑到近期场景执行得比较频繁，数据库变更较多，所以先把数据库做个整体的分析，再来测试下。经过证明之后，发现果然分析了整库之后，时间刷刷的降低了很多，然后就把存储的IO压到80%以上了。
虽然开发说执行计划变更是错的，但是分析整库的处理方法是对的。
套用大话西游里说的：我猜中了结尾，但是没有蒙对过程。
看到这里，是不是觉得问题解决了？可以收工了？很开心的喝咖啡去了？

---

但是，我又偏执了。我考虑了下参数化的逻辑，我觉得数据热块应该是存在的。现在之所以没有暴露出来，是因为 IO 跟不上了。所以我要判断下，如果 IO 够用的话，热块会不会成为下一个瓶颈。于是，接着查。

先看看争用是否严重：

selectround ((misses / gets) * 100) || '%',
 round(
	100 * immediate_misses / (
		immediate_gets + immediate_misses
	)
) || '%'
FROM
	v$latch wherename = 'cache buffers chains';

round((misses / gets) * 100) || '%'的值是 3%。可见还是有一些热度的。
再来查下子锁存器视图，看是否有热块。看看倾斜度。
​

 select * from (select addr,child#,gets,misses,sleepsfrom v$latch_children 
                wherename='cachebuffers chains'orderby sleeps desc) whererownum<=20;

倾斜度是有的。再看下对象的热度：

    select hladdr,
           obj,
           (select object_name
              from dba_objects
             where (data_object_id isnull
               andobject_id = x.obj) or data_object_id = x.obj andrownum = 1) as object_name, dbablk, tch
      from x$bh x
     where hladdr in ('00000005FCE6EAC0')
     orderby tch desc;

TCH 是 touch count，此值越高，则热度越高。
查找引起热块的 SQL。

     select *
       from (selectcount(*),
                    sql_id,
                    nvl(o.object_name, ash.current_obj#) objn,
                    substr(o.object_type, 0, 10) otype,
                    CURRENT_FILE# fn,
                    CURRENT_BLOCK# blockn
               from v$active_session_history ash, all_objects o
              where event like'latch: cache buffers chains'
                ando.object_id(+) = ash.CURRENT_OBJ#
              GROUPBY SQL_ID,
                       current_obj#,
                       current_file#,
                       current_block#,
                       o.object_name,
                       o.object_type
              orderbycount(*) desc)
      whererownum <= 10;

根据 SQLID 查一下 SQL 的文本，果然就是我们用到的那个查询业务 QL。

在性能分析中，我们太容易给自己定个范围或圈套了。有时觉得这个事情不该是自己做的。
如果单从职场的角度说，这样想并无不妥。
但是如果从技术角度说，这样想就必然会导致自己的能力受限。
所以不用给技术下个定义，在个人能力能达到的地方，都尽量去做，学无止境。

而从现象到瓶颈的性能分析是最需要一个人有足够的知识宽度的，因为你不知道在寻找瓶颈的过程中会遇到什么样的知识弱点。
今天碰到的是 Oracle，明天碰到 mysql、HBase怎么办？啥也别想，二话不说，办它就对了。