使用慢日志排查超时问题

功能简介

实例的慢日志会记录执行时间超过指定阈值的请求，慢日志分为数据节点慢日志和代理慢日志。

慢日志查看方式

操作步骤

服务超时的原因通常比较复杂，很多情况下与慢请求相关。您可以按照下述步骤来排查超时问题。

1. 当服务出现超时问题，首先查看代理慢日志，详情请参见查询慢日志。

   说明

   • 如果实例为标准架构，请跳转至步骤3分析数据节点慢日志。

   • 如果代理慢日志内容为空，您可以排查客户端与实例间的网络状况。如果确认通过外网（公网）连接实例，请参见本文的「排查外网（公网）连接延迟」章节。

2. 定位最早的代理慢日志由哪条命令引发。

   说明

   代理慢日志通常是因为数据节点中出现慢请求，引起命令堆积而导致的。

   本案例中，最早出现的慢日志是由一条KEYS命令生成的。慢日志记录中的IP地址即为使用这些命令的客户端IP地址。

   在慢日志页面单击代理节点页签，可查看代理慢日志记录。本案例中，代理慢日志表格显示了 5 条记录，包含 1 条 KEYS 命令和 4 条 SET 命令，执行时长在 64048～88861 微秒之间。

3. 查看数据节点慢日志以确认代理慢日志中的哪些日志引起了超时问题。

   说明

   通常情况下，在代理慢日志中最先产生慢日志的命令，也会在数据节点生成慢日志。数据节点的慢日志一般比代理节点慢日志少，这与二者对执行时间的定义以及慢日志阈值不同有关。

   本案例中，查看代理慢日志后，再对比数据节点慢日志，发现也存在KEYS命令产生的慢日志，且没有出现代理慢日志中的其它慢日志，说明真正引起超时即为KEYS命令产生的慢日志。

   在慢日志页面单击数据节点页签，可查看数据节点慢日志记录。本案例中，数据节点慢日志中仅出现 KEYS 命令的慢日志记录，其执行时长较长，确认该命令为导致超时的根因。

4. 在代理慢日志中，根据上一步骤定位到的命令精确搜索，可找到使用这些命令的客户端IP，随后进行优化。

利用慢日志排查热Key问题

当怀疑实例存在热Key问题时，可以通过调整慢日志阈值参数辅助排查读请求侧的热Key。数据节点慢日志的记录阈值由参数 slowlog-log-slower-than 控制，默认值为 20000 微秒（20 毫秒），只有执行时长超过该阈值的命令才会被记录到慢日志中。即使某个 Key 被高频访问，只要单次命令的执行时长没有超过默认阈值，这些读请求也不会产生慢日志记录，因此默认阈值下无法通过慢日志定位热Key。

排查热Key时，建议适当调低 slowlog-log-slower-than 的取值，以捕获更多访问记录，再根据慢日志中反复出现的高频命令定位热Key的来源客户端IP。

需要注意的是，审计日志开通后仅记录写操作的访问信息，不记录读操作，因此无法通过审计日志查看热Key的读访问IP；如需定位读请求侧的热Key来源，需依赖调低阈值后的慢日志。若需要排查基于写请求的热Key，可参考查询历史热点Key。

排查外网（公网）连接延迟

当确认实例服务端无性能瓶颈，但客户端仍出现连接超时报错时，需排查客户端与实例之间是否存在外网（公网）连接延迟问题。

其他排查方向

完成慢日志和公网连接排查后仍未定位问题时，可继续通过实例巡检、性能监控以及 VPC、ECS 和应用侧信息缩小排查范围。