前言
在另一篇《一个慢查询的基本分析》中仍遗留有一个问题, 即各个tikv主机之间出现交替的cpu波动(下图中), 是什么原因, 这在本篇中加以分析。
一、查看tikv图
tikv-1在08:53左右cpu下降, tikv-2在08:54左右cpu上升
初步判断，可能是有一些热点region，从tikv-1转到了tikv-2上，所以导致cpu消耗的迁移。
二、查找热点迁移的证据
在上一篇中已经定位了异常sql是
select t1.*, t2.*
from t1, t2
where t1.id = t2.id
and t1.cust_id='xxx'
and t2.state='01'
T2表走了全表扫描，而且sql执行频率是每秒一次，所以首先怀疑T2表的region是热点。
2.1 定位热点region的几个办法
这几个办法是：
(1) 手工从top sql和日志中去找相关的证据, 笨方法, 不过在分析历史问题时也可以用；
(2) 使用 pd-ctl 工具的hot read或region topread接口来查看当前的hot-region;
(3) 使用系统视图来查询, 可查7天以内的数据，相关脚本如下:
-- 当前热点 Region 信息
SELECT h.DB_NAME,h.TABLE_NAME,h.INDEX_NAME,h.REGION_ID,
s.ADDRESS LEADER_ADDRESS,h.TYPE,h.MAX_HOT_DEGREE,h.REGION_COUNT,h.FLOW_BYTES
FROM information_schema.TIDB_HOT_REGIONS as h,
information_schema.TIKV_REGION_PEERS as p,
information_schema.TIKV_STORE_STATUS as s
WHERE h.REGION_ID=p.REGION_ID
AND p.STORE_ID = s.STORE_ID
AND p.IS_LEADER = 1
ORDER BY h.FLOW_BYTES DESC limit 10;
--单个 TiKV 的历史热点 Region 信息
select * from information_schema.TIDB_HOT_REGIONS_HISTORY
where update_time between '2023-01-01 00:00:00' and '2023-01-01 00:30:00'
and store_id = 1
order by flow_bytes desc ;
上述脚本使用flow_bytes来排序, 这对有些场景是不适用的, 比如本例中热点region的流量并不大, 在dashboard流量热力图中完全没有表现, 因此要根据具体场景选择合适的字段进行排序。
本篇使用第一个办法来查找热点region, 主要目的是增加对系统原理的了解。
2.2 热点来自T2表?
(1) 查看T2表的region_id
查询 information_schema.tikv_region_status 视图, 查得结果比如是2345。
(2) 在pd.log中查询region-2345的变化情况
在dashboard中搜索pd日志, 看到有2345分区有热点迁移的情况，但不是08:53这个时间点，迁移的源和目标也对不上，因此暂时排除T2表的可能性。
2.3 热点来自T1表?
由于没查到T2表的热点证据，转而怀疑是不是T1表的热点, 因为T2表有23万条记录关联到T1表，而且T1索引也捞到61058条，只是回表过滤时返回0条。
同上面过程一样，查找T1表的热点region证据，还是没找到, 暂时排除T1表的可能性。
如果不是T1/T2表, 难道还有其它可能？
2.4 直接查找热点region
既然从T1/T2的region上查不到相关证据，不如直接从日志中查嫌疑region, 即在08:53时分，热点从tikv-1迁移到tikv-2的相关信息。
pd.log记录的是store-id, 所以需先从information_schema.tikv_store_status查到tikv-1/2对应的store-id。比如查得tikv-1的store编号是17866435, tikv-2的store编号是17866448。
(1) 在pd.log中查找相关热点迁移信息
查找的方向，是在08:53时分，热点region从[17866435] 迁移到 [17866448]的记录。
查得如下 move-hot-read-leader 记录, 仅有一条,其region-id=38418597。
(2) 验证region为热点的可信度
下图来自tidb.log, 看得出38418597 region的访问很慢，且在08:53时从113主机迁移到了91主机。
因为集群tikv之间经历了多次热点迁移，所以如果继续查找，是可以看到它与 38418597分区的迁移是同步的， 这就验证了38418597就是要找的热点region。
(3) 查看region-id属于哪个对象
从 tikv_region_status 视图中查不到 38418597, 有可能此region已经在和其它region合并后销毁。
(4) 查看region 38418597 的转变记录
由于region已经不在, 因此要在pd.log中搜索此region在08:53之后，经历了哪些变化。
在09:25分左右的pd.log中发现一条记录:
["add operator"] [region-id=38406480] [operator="\"merge-region {merge: region 38418597 to 38406480}]
但 38406480 也不是T1/T2的region, 而且随后也被销毁了找不到。继续查找 38406480 的转变。
["region batch split, generate new regions"] [region-id = 38406480] [origin="id:38425214 start_key:\"7480000....\" end_key:\"7480000...00FE\" ......]
这里找到了region的start_key和end_key。 虽然region-id值不断变化，但region所在key中包含的table_id是固定的。
(5) 通过 key定位具体表对象
用下面函数来翻译key
select tidb_decode_key(end_key);
key翻译出来是具体的table_id值，再通过tables视图查出来是T1表, 因此可以判断是T1表的热点region。
补充一下，如果不断地沿着region的split/merge的线索，应该可以最终关联到T1所属的region，只是比较费时。
三、总结
本篇分析过程如下（使用手工方式）:
四、后记
本案例涉及的sql, 占用的绝对资源并不多, T1是6万条, T2是28万条, 才几个region, 每秒调用一次，每执行一次的资源开销是（全表扫描28万条 + 28万次索引访问 + 6.1万次回表)， 有些特别的地方。
4.1 不相关的工具
下面两个工具对本案没帮助:
- dashboard中的热力图, 找不到T1/T2表, 即sql读流量不大;
- grafana中PD与热点调度相关的operator信息, 没有有效的信息;
4.2 表关联中哪个表更危险
T2 (28万全表) IndexJoin T1(6万), 目前看T2全表扫描不是瓶颈, 而是对T1进行28万次的索引访问以及回表查询，引起了热点，也就是说，coprocessor的数量是关键。
4.3 小sql影响整个系统
本案的sql不大, 如果是空闲系统跑一次，差的计划也只要3秒左右，但在持续的执行过程中，不断向tikv中积压请求，最终把一个tikv的cpu耗尽。
一个tikv cpu的耗尽，又影响到此tikv上其它leader的请求, 从而影响个整个库的正常运行。
4.4 热点是否能打散
T1表6万多条数据, 几十MB大不, 只有一两个region, 打散成20M一个也可稍微缓解(小于20M的region会被自动合并)，可以作为临时解决办法，最根本的还是要优化plan，也就是上篇提到的收集统计信息，让优化器选择正确的plan。
