一个热点问题的基本分析

作者： chenbo 原文来源：https://tidb.net/blog/532e9d45

前言

在另一篇《一个慢查询的基本分析》中仍遗留有一个问题, 即各个 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, t2where t1.id = t2.idand 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_BYTESFROM information_schema.TIDB_HOT_REGIONS as h,information_schema.TIKV_REGION_PEERS as p,information_schema.TIKV_STORE_STATUS as sWHERE h.REGION_ID=p.REGION_ID AND p.STORE_ID = s.STORE_ID AND p.IS_LEADER = 1ORDER 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 = 1order 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。