TSO 慢排查手册 v2.0——2022.03.11 更新

时过境迁,随着客户量的增加和代码的更新换代,TSO 的一些细节和监控都发生了些许变化,所以在此重新归纳整理,推出 TSO 慢排查手册 v2.0 版本。
image

监控项详解

TiDB 侧监控

PD TSO OPS

image

位置:TiDB - PD Client

每秒的 TSO 请求个数和实际发送到 PD 的 gRPC 请求数量。

  • cmd 代表 TiDB 侧 Wait TSO 个数的数量
  • request 代表 TiDB 侧实际发送给 PD 的 TSO gRPC 请求数量

由于 TiDB 使用的 PD Client 有 batch 攒批策略,所以会一次汇聚多个 TSO 请求,转换成一个实际的 gRPC 请求发送给 PD Leader 期以减轻后者处理压力。反映在监控上应当表现为 request 数量恒小于等于 cmd 数量,cmd/request 即为每秒的平均 batch size。

PD TSO Wait Duration(非 Overview 面板)

image

位置:TiDB - PD Client

TiDB 侧拿到一个 TS 后(TSFuture),调用其 Wait 方法获取 TSO 的等待时长,即“调用 tsFuture.Wait() 到获取到 TSO 结果的时长“。

当 TiDB 请求生成 TSO 时,PD Client 不会 block 调用者,而是直接返回一个 TSFuture,并在后台异步处理 TSO 请求的收发,一旦完成立即返回给 TSFuture,TSFuture 的持有者则需要调用 Wait 来获得最终的 TSO 结果。此时分为两个情况:

  • 如果 TSO 请求已经完成,Wait 会立刻返回一个可用的 TSO 或 error
  • 如果 TSO 请求还未完成,Wait 会 block 住等待一个可用的 TSO 或 error(说明 gRPC 请求在途,网络延迟较高)

而 PD TSO Wait Duration 就代表了从调用 Wait 方法到获得 TSO 的总等待时长(不包括 error 的情况),其可能包括了以下耗时(注意这个“可能”,具体会因调用 Wait 的时机不同而变化):

  • TiDB 侧 Go Runtime 调度耗时(大多数情况)
  • 部分 gRPC 网络时延
  • 部分 PD 侧 TSO 生成处理耗时
  • 部分 PD 侧 Go Runtime 调度耗时

对应统计代码:https://github.com/tikv/pd/blob/02848d2660ee105a7bef9e02f485a588132abc4f/client/client.go#L1236-L1248

PD TSO RPC Duration

image

位置:TiDB - PD Client

PD 侧的 Handle requests duration 中 tso 项监控相同,只不过在 TiDB 面板上单独拉出来写了一个。代表了 PD Client 将 Tso gRPC 请求发送给 PD Server,并从 PD Server 获得 TSO gRPC 返回的时延。所以它包括了:

  • PD 侧 Go Runtime 调度耗时
  • PD 侧 TSO 生成处理耗时
  • gRPC 的网络延迟

根据 TiDB 的流程逻辑,Wait 的调用时机比较后置,所以大多数情况下 PD TSO Wait Duration 都会小于 PD TSO RPC Duration。你可以理解为 TiDB 在调用 Wait 等待 TSO 请求的时候,TSO 的实际处理流程可能处在以下任意一个阶段:

  • RPC 请求还在去往 PD Server 的路上
  • RPC 请求还在回到 PD client 的路上
  • RPC 请求还处在 PD Server 侧的处理过程(TSO 生成中)

对应统计代码:​​https://github.com/tikv/pd/blob/02848d2660ee105a7bef9e02f485a588132abc4f/client/client.go#L1002-L1023

Async TSO Duration(>= v5.4.0)

image

位置:TiDB - PD Client

TiDB 侧拿到一个 TS 后(TSFuture),到调用其 Wait 方法之间经过的时长,即“从获得 tsFuture 开始到调用 tsFuture.Wait() 的时长“。

如前所言,TiDB 拿到 tsFuture 后不会立马进行 Wait 调用来获取 TSO,而是先去进行 Optimize 等一系列操作,等实际需要 TSO 时才取调用 Wait 来获取 TSO 结果。所以 Async TSO Duration 反应了这段时间 TiDB 处理其他工作的耗时情况,一般当 TiDB 压力增加时,该指标会上升。

PD 侧监控

PD server TSO handle time + Client revc time(< v4.0.13)

image

PD server TSO handle time(>= v4.0.13)

image

位置:PD - TiDB

事实上,这个监控的名字从 v4.0.13 版本起就是错误的,其只包含了 PD Server 端收到请求之后处理 TSO 所花费的时间,并不包括 Client 接收 TSO 的耗时。所以在不同的版本,这个监控的意义有所区分:

Handle requests duration

image

位置:PD - TiDB

代表了 PD Client 将 Tso gRPC 请求发送给 PD Server,并从 PD Server 获得 TSO gPRC 返回的时延。所以它包括了:

  • PD 侧 Go Runtime 调度耗时
  • PD 侧 TSO 生成处理耗时
  • gRPC 的网络延迟

对应统计代码:​​https://github.com/tikv/pd/blob/02848d2660ee105a7bef9e02f485a588132abc4f/client/client.go#L1002-L1023

Handle requests count

image

位置:PD - TiDB

同 PD TSO OPS 中的 request,代表发送给 PD 的实际 Tso gRPC 数量。

TSO 慢的排查手段

一般而言,当我们发现慢的时候,”慢”的这个现象往往会出现在 SQL 的执行耗时增加上,秉持着“先问是不是,再问为什么的原则”,我们首先需要判断 SQL 慢是否真的是因为 TSO 慢了——例如 auto-commit 下的点查 SQL,是不需要获取 TSO 的,它慢不应该在 TSO 监控里找原因。

在排除其他嫌疑,真的下决定要查一查 TSO 慢的问题时,由于对 TiDB 来说,实际感受到“慢”的体感只会来自于 Wait 的调用耗时大,即 PD TSO Wait Duration 的监控表现出整体时延升高或尾延升高。这个时候回顾 PD TSO Wait Duration 的监控意义,我们知道它可能包括:

  • TiDB 侧 Go Runtime 调度耗时
  • 部分 PD 侧 Go Runtime 调度耗时
  • 部分 PD 侧 TSO 生成处理耗时
  • 部分 gRPC 网络时延

去除一些偏底层的细节,我们可以将其简单粗暴地归纳为:

  • 网络慢了
  • PD 卡了
  • TiDB 卡了

所以从这三个方向出发,依次排除。

网络慢了

首先立马查看 PD TSO RPC Duration,其正常数值范围 80% 差不多在 1ms 以内,99% 在 4ms 内,如果数值比较高,则说明网络和 PD 的处理时间长(包括 Go Runtime 调度和实际 TSO 处理逻辑),此时继续看 PD server TSO handle time + Client revc time 是否慢,如果不慢则说明 PD TSO 处理(和发送)不慢,大概率是网络问题,需要往网络问题方向排查。

PD 卡了

如果 PD server TSO handle time + Client revc time 慢:

  • 如果是 v4.0.13 版本及以后,由于这个监控其实只包括了 PD leader 处理 TSO 时间,所以它慢说明 PD TSO 处理的慢,此时应该考察 PD Leader 的 CPU 占用情况是否较高?以及是否存在混布(混合部署)的情况,即同一台机器上有其他的进程或操作扰乱了 PD 的计算,影响了 TSO 的处理速度。
  • 如果是 v4.0.13 版本之前(不包括),那么说明 PD leader 处理 TSO 时间慢或回传给客户端的发送时间慢或两者都比较慢,需要同时考虑上述 PD CPU 问题以及 PD 到 TiDB 之间的网络问题。

还有一个情况也会影响到 PD 的 TSO 分配——PD 出现了 leader 切换,不过一般出现 leader 切换,直接会导致 TSO 不可用,并不能是让 TSO 变慢的原因,只在此一提,仅供参考。

TiDB 卡了

如果顺利排除了网络问题和 PD 问题,那么疑点又回到了 TiDB 这边。由于 TSO 的后台处理流程和 TiDB 的 Parser 以及 Complie 生成 Plan 是同时进行的,遇到高强度的 Workload 和一些较为复杂的查询时,可能会消耗大量的资源,影响到 Wait 操作(里面使用了 select 语句以及 channel,涉及到 Go 的调度),此时可以来到 TiDB 的 Execution 监控面板,看看 Parse,Complie 和 Execute 的耗时。

image

还可以观察一下 TiDB 的 Server 面板,看看 CPU 负载如何。条件允许的情况,可以再 profile 以下,排查一下 goroutine 的数量和运行耗时,看看瓶颈出现在何处。

10赞