伴鱼数据库之慢日志系统

作者： Hacker_ubN7WXjw 原文来源：https://tidb.net/blog/d0ace60d

一、背景

伴鱼少儿英语是目前飞速成长的互联网在线英语教育品牌之一，特别在疫情这段时间内，业务增长近 3-4 倍。伴鱼慢日志系统对于帮助我们及时发现数据库性能问题和预防数据库性能风险，起到了很大的作用。

目前，伴鱼有 10 套 TiDB 数据库，20+ 套 mongodb 数据库，200+ 数据库实例。日常数据库性能问题处理，由于慢日志分散在多台机器，面临日志查询 / 分析 / 统计等各种不便。因此，我们的慢日志系统，需要满足以下几个要求：

1）慢日志集中准实时收集

2）日志查询 / 分析 / 统计可视化

3）慢日志报表功能

4）慢日志及时告警

下面主要介绍下伴鱼慢日志系统以及系统给我们带来的实实在在的效果。

二、慢日志系统详解

我们认为数据库的性能问题，绝大部分原因都是由慢 SQL 导致的，当然像数据库 bug、业务异常流量等情况，在伴鱼还是比较少见的。所以，我们如何准实时收集分布式 TiDB 的慢日志、如何快速的做分析统计以及如何及时的告警，对于快速解决线上问题，甚至将性能风险扼杀在摇篮里至关重要。

1）如何准实时收集慢日志

我们采用了业界比较成熟的开源日志采集、分析、存储和展示架构，很好的解决了我们对慢日志的处理需求。

在上图中，filebeat 负责增量收集 TiDB 产生的慢日志，由于 filebeat 比较轻量，对线上性能基本无影响。采集配置如下，其中 service 用于区分数据来源，在 logstash 解析阶段会用到；ip 在 filebeat 部署阶段自动补上，主要用于分析阶段识别日志来源机器；exclude_lines 排除掉非增删改查语句，便于后续解析。

原始慢日志 (见下图) 经过 filebeat 采集阶段简单处理后，存储到 kafka。存储到 kafka 的慢日志内容格式，如下图所示。

原始日志格式

采集后的日志格式

然后 logstash 负责读取 kafka 中的慢日志并进行解析，转换成我们想要的 kv 键值对，如下图所示。

最后解析后的数据入到 es，供 kibana 查询分析统计。

对于 TiDB 的慢日志，我们重点关注慢日志中的某些特定字段，比如：

index_name: 语句执行过程中是否用到索引

DB：表示执行语句时使用的 database。

query_time：表示执行这个语句花费的时间。

total_keys：表示 Coprocessor 扫过的 key 的数量。

process_keys：表示 Coprocessor 处理的 key 的数量。相比 total_keys，processed_keys 不包含 MVCC 的旧版本。

sql：执行的 sql 语句

2) 如何对慢日志进行分析统计

慢日志通过 logstash 解析后入到 es，通过 kibana，我们可以利用解析的字段作为查询和聚合的条件，很方便的对数据进行分析统计。

比如我们经常有如下操作：

1）30 分钟内，慢请求分别按照 db 和 table 聚合

2）30 分钟内，Process_keys 大于 5000 的慢请求

3）30 分钟内，query_time 大于 500ms 的请求

当然分析统计远不止这些，研发同学还可以在平台上定制所属业务 db 的趋势图和告警等。同时基于慢日志数据，我们还开发了慢日志分析报表平台，从多种维度，比如集群、库、表、操作类型、慢日志数量、执行总时间、平均响应时间以及最大耗时等维度对慢日志进行分析统计，并产生报表定时发送给研发同学。

3）如何对慢日志进行告警

在伴鱼，一个 db 对应一个服务，所以告警都是在特定 db 下设置规则。目前，我们告警粒度是一分钟，主要基于以下三类默认规则告警。

a) 某个 db 下的请求时间达到 100ms 且慢日志达到一定数量则告警

b) 某个 db 下的请求时间达到 500ms 且慢日志达到一定数量则告警

c) 某个 db 下的请求 Process_keys 大于 5000 且慢日志达到一定数量则告警

当然告警规则的设置不是一蹴而就的，需要根据不同的业务场景，dba 和研发不断的调整，最终达到一个比较合理的阀值。

三、慢日志系统给伴鱼带来的收益

目前，我们 10 个 TiDB 集群，有 6 个核心集群请求过万，见下图。慢日志系统运行到现在，主要给我们带来 3 个收益。

1）延时低，6 个请求过万核心集群 999 线基本维持在 16ms 左右，见下图

2）慢日志越来越少，tidb 所有集群的慢日志 (大于 200ms)，30 分钟内，高峰期条数基本维持在 500 以内

3）故障少，除一次 tidb 优化器 bug 导致大表查询故障，影响线上近 10 分钟。近半年没有 tidb 引发的线上故障。

总结，慢日志系统在预防性能风险和发现性能问题确实起到了很重要的作用。