TiDB 慢日志在伴鱼的实践

2021年09月15日 阅读数:1
这篇文章主要向大家介绍TiDB 慢日志在伴鱼的实践,主要内容包括基础应用、实用技巧、原理机制等方面,希望对大家有所帮助。

TiDB 慢日志在伴鱼的实践

做者简介:刘江,伴鱼英语数据库负责人,TUG 2020 年度 MOA。负责伴鱼数据库运维、大数据运维以及数据库平台化建设。数据库

本文来自于伴鱼英语 DBA 组负责人刘江在「能量钛」第二期活动的分享,刘江为你们分享了 TiDB 慢日志在伴鱼的实践。本文将从如下三个方面展开:数据结构

  • 第一部分是背景与需求,首先介绍伴鱼作 TiDB 慢日志系统的背景,以及基于这个背景,要把慢日志系统作成什么样子;
  • 第二部分介绍下慢日志系统具体是怎么作的;
  • 第三部分经过几个线上案例,看看慢日志系统是如何定位线上问题的。

背景与需求

今年上半年,阿里云发布了新一代 DAS(数据库自治服务)服务,里面谈到数据库的问题,90% 以上的问题都是来源于数据库的异常请求。其实在咱们平常的数据库问题场景,大部分的问题也都是异常 SQL 请求,像数据库的 bug 或者是机器致使的故障问题,平时遇到仍是相对较少的。对于异常 SQL 的定位,数据库的慢日志分析,是一种特别有效的手段。架构

那么咱们在平时利用慢日志分析问题的时候,会有哪些痛点?在作慢日志系统以前,集群的慢日志是分布在多台机器上面的,若是数据库出现了问题,就须要登陆到多台机器一台台的去分析,问题处理的效率很低。特别是当集群规模特别大的时候,基本上没办法去快速定位问题。运维

固然,TiDB 在 4.0 版本支持了 Dashboard,咱们能够经过 Dashboard 查看整个集群的慢日志信息,好比最近 15 分钟的或者最近半个小时的慢日志。但当系统真正出现问题的时候,慢日志会特别多,Dashboard 会面临计算加载等性能问题,同时 Dashboard 不支持检索和分析统计,这不利于咱们快速定位到异常 SQL。性能

TiDB 系统库自带了一张表(INFORMATION_SCHEMA.SLOW_QUERY)来实时存储慢日志,咱们也能够经过它来定位异常 SQL,但这张表是一个关系型的表,自己是没有索引的,当日志量特别大的时候,多维检索和分析是特别慢的。同时,对于关系型表的多维检索和分析统计,也不是它所擅长的。测试

基于以上的痛点,伴鱼的慢日志系统须要知足如下几个需求:大数据

首先,就是慢日志集中式收集,可以把线上多个集群甚至几十个集群的慢日志所有收拢在一块儿,便于集中分析,这样作入口统一了。搜索引擎

其次,要保证收集的慢日志是准实时的。由于若是收集的慢日志延迟太大的话,对于处理线上问题和分析问题是没有帮助的。阿里云

而后,慢日志能够检索和统计分析。由于当出现问题的时候慢日志是特别多的,这个时候若是可以检索和统计分析的话,就能够快速定位到异常 SQL。spa

最后,慢日志系统须要支持监控和告警

系统详解

基于以上的背景和需求,咱们来看一下伴鱼的慢日志系统是怎么作的。

系统架构

伴鱼慢日志系统总体架构,以下图所示。咱们在 TiDB Server 机器初始化时部署了 Filebeat 组件,经过它把采集的慢日志,写入到 Kafka,同时打上机器 IP 信息。而后经过 logstash 解析出咱们关注的字段,存储到 ES。ES 自己是一个搜索引擎,作数据的分析和统计,速度是特别快的。同时咱们经过 Kibana 查看 ES 里的慢日志数据,作可视化的统计和检索。

固然,慢日志系统还有一种架构,以下图所示。Clickhouse 是最近几年比较火的分析型数据库,有些公司经过把监控数据发送到 Clickhouse, 作实时监控和告警分析。咱们能够用 Flink 替换 logstash 组件,经过简单的计算,把慢日志数据写入到 Clickhouse。

由于伴鱼的慢日志系统作得比较早,因此采用的是 ELK 的架构

首先,Filebeat 足够轻量。咱们在线上对几百兆文件作过解析测试,结论是对数据库的性能基本上没有影响。

其次,当线上出现问题时,瞬时的日志量是特别大的,若是把慢日志直接写入到 Logstash,会对 Logstash 机器负载形成冲击,因此经过 Kafka 来消峰

当 Logstash 解析慢日志的时候,应尽可能少用模糊匹配的规则。由于用模糊匹配的规则去解析慢日志,会致使机器 CPU 飙高的问题。

而后,ES 索引自己就是 Schema Free 的,而后加上倒排索引这种数据结构,这种特性很是适合统计分析类场景。

同时,经过 Kibana 作可视化检索和统计分析。

最后,咱们每 2 分钟读取一次 ES 的慢日志数据,作监控报警。

日志采集

接下来看一下每一个组件的细节,左边是 Filebeat 采集的配置,以下图所示。咱们在部署 Filebeat 的时候,会把部署机器的 IP 给传进去,这样在后期统计的时候,就知道慢日志是来源于哪台机器。而后右边是 Kafka 的配置,数据收集好以后,会发送到 Kafka 集群。

下面是一条 TiDB 慢日志的示例,格式是这样的。

慢日志以 Time 开头,带有 Query_time,Total_keys,Process_keys,DB 等字段,最后还有 SQL 的信息。这条慢日志在经过 Filebeat 的采集以后,会变成下面这样的一行文本,以下图所示。若是把这行文本直接存到 ES 的话,是没办法去作检索和统计分析的。

字段筛选

一条文本无法作统计分析和多维检索的,若是咱们要作,就须要把这行文本里面的字段解析出来,那么咱们关注哪些字段呢?首先来看一下 MySQL 5.7 的慢日志,以下图所示。咱们在处理 MySQL 故障的时候,首先会看一条 SQL 的查询时间,若是改 SQL 查询时间比较长,咱们认为它可能会是致使线上问题的缘由。

可是当线上请求量比较大的时候,查询时间长并不能表明它就是出现问题的根本缘由,还要结合其余关键字来综合分析。好比慢日志里一个特别重要的关键字 Rows_examined,Rows_examined 表明了数据逻辑扫描的行数,一般咱们经过 Query_time 和 Rows_examined 综合分析,才能够定位问题 SQL。

接下来,咱们看一下TiDB 的慢日志。首先来看一下 TiDB 3.0.13 走 KV 接口的慢日志,以下图所示。这里有一些比较重要的关键字,好比说 Query_time,DB,SQL 和 Prewrite_time,这些关键字对于定位线上问题是颇有帮助的。

下面是另一种格式的 TiDB 3.0.13 的慢日志,它是走 DistSQL 接口的,以下图所示。

它除了把 Query_time、Total_keys 同时打印出来以后,还有 Index_names,表明这条 SQL 有没有走索引,同时 Index_names 字段里面还有表名等信息。

看完了 TiDB 3.0.13 的慢日志,咱们再来看一下 TiDB 4.0.13 的慢日志,慢日志内容相比 TiDB 3.0.13 版本又增长了一些字段,好比 KV_total,PD_total,Backoff_total 等信息。

经过上面的慢日志,咱们能够发现其中包含了不少关键信息,咱们甚至能够看到请求慢在数据库的哪一个环节。若是咱们把慢日志收集起来,经过某些关系进行检索,甚至聚合,对于发现问题是颇有帮助的。

在伴鱼,咱们关注的 TiDB 慢日志字段主要有如下几个:

  • TiDB IP:在部署 Filebeat 的时候,会把机器的 IP 给传进去。有了这个 IP,咱们能够知道日志的来源以及按照 IP 的维度进行统计;
  • DB:执行语句时使用的 DATABASE。咱们能够按照 DB 维度进行统计,同时也能够经过内部系统将 DB 和具体的数据库集群映射起来;
  • TABLE:有些慢日志是能够解析出表名的,可按照表的维度进行统计;
  • IDX_NAME:除 Insert 语句 和走 KV 接口的语句外,慢日志信息记录了语句有没有走索引;
  • TOTAL_KEYS:Coprocessor 扫过的 Key 的数量;
  • PROCESS_KEYS:Coprocessor 处理的 Key 的数量;
  • QUERY_TIME:语句执行的时间;
  • SQL:具体的 SQL 语句。

字段解析

经过 Logstash 的 Grok 语法将一条慢日志所须要的字段解析出来,以下图所示。

统计分析

下面这个图是咱们全部集群在最近 30 分钟以内的慢日志状况。咱们经过 Kibana,能够看到慢日志的总条数,能够经过 DB、Quwry_time、Total_keys 来进行检索,还能够按 DB、Table、IP 等维度进行统计。这样可以极大地提升定位问题 SQL 的效率。

除了经过 Kibana 进行可视化检索和聚合以外,咱们内部平台系统也会经过慢日志的各类维度去进行聚合和排序,聚合维度包括集群,库、表、IP和操做类型等,排序规则能够按照总耗时,平均耗时,最大耗时和日志条数等维度。咱们能够按期向研发发送慢日志报表。

监控告警

除了可视化检索和统计分析以外,咱们还对慢日志作了监控和告警,以下图所示。经过统计每一个库下的慢 SQL 条数,每一个库设置两种告警规则。好比说 advertising 这个库,通用的规则是执行时间超过 200 毫秒,告警阀值达到 5 条的会告警。

可是咱们发现线上也存在执行频率特别低,可是执行时间特别长的状况,就没办法经过通用的规则去覆盖。因此后面又加了一条规则:执行时间超过 500 毫秒,告警阀值达到 2 条就告警。这样对于线上的慢 SQL 就基本上全覆盖了。

告警信息,以下图所示。能够看一下左边的这张图,咱们采集了慢日志的 DB 字段,经过内部系统把 DB 和数据库集群关联起来,咱们能够看到慢日志发生在哪一个集群,哪一个库。慢日志产生的时候,这些慢日志超过了多少阀值,总的 SQL 执行时间以及平均时间等信息,经过这样的慢日志告警信息,咱们能在短期内判断问题 SQL 对线上的冲击有多大。

案例分享

讲完了慢日志系统是怎么作的,接下来来看一下咱们是如何经过慢日志系统去发现线上问题。

第一个案例,以下图所示。咱们在某天发现集群的 Coprocessor CPU 上去了,同时对应着右边的延时也上去了,经过慢日志系统很快就能发现问题 SQL,它的 Total_keys 和 Process_keys 耗得比较多,另外它的index_name 是空的,说明它没有走到索引。咱们经过给这条 SQL 加上索引,性能问题就快速地解决了。

第二个案例也相似,咱们发现 Coprocessor CPU 指标上去了,而后经过慢日志系统检索一下,就能发现 SQL 没有索引。定位问题的速度很快,由于经过 ES 去进行聚合和检索是特别快的。

总结

以上是伴鱼慢日志系统在性能问题发现和预防数据库性能风险等方面的一些经验,但愿对你们有所帮助。将来,咱们将继续挖掘慢日志的信息,丰富慢日志系统的功能,为伴鱼数据库保驾护航。

上一篇: centos中KVM的安装
下一篇: 迟到