TIDB General Log抓取分析神器

背景

在社区经常见到小伙伴的一个需求，抓取数据库所有操作记录，严格来说是所有业务端执行过的sql，大部分原因是开发或者老板要查问题，又不知道问题发生在哪个模块，所以就要所有数据库操作记录。

本文主要讲述通过数据库自带的日志功能和抓取抓网络包两种方法来解决该需求。

数据库开启日志记录

mysql开启general_log1. 相关参数

开启 general log 会将所有mysql执行过的的SQL语句记录下来。一般不会开启开此功能，因为log的量会非常庞大。但个别情况下会临时打开general log以供排障使用，使用完毕后再关闭。 ​ 相关参数一共有3个：general_log、log_output、general_log_file。

 show variables like general_log; -- 查看日志是否开启  set global general_log=on; -- 开启日志功能  show variables like general_log_file; -- 查看日志文件保存位置  set global general_log_file=tmp/general.lg; -- 设置日志文件保存位置  show variables like log_output; -- 看看日志输出类型 table或file  set global log_output=table; -- 设置输出类型为 table  set global log_output=file; -- 设置输出类型为file

log_output=’FILE’ 表示将日志存入文件,默认值是FILE；’TABLE’表示将日志存入数据库,这样日志信息就会被写入到mysql.slow_log表中。mysql数据库支持同时两种日志存储方式,配置的时候以逗号隔开即可,如:log_output=‘FILE,TABLE‘.日志记录到系统专用日志表中,要比记录到文件耗费更多的系统资源,因此对于需要启用慢查询日志,又对性能有要求,那么建议记录到文件。

2. 开启数据库general_log步骤

先执行sql指令：show variables like ‘%log%’;

默认general_log是OFF的，直接开启：set global general_log = ON;（永久修改需要在my.cnf的【mysqld】中添加：general_log = 1）

现在mysql就会在general_log_file显示的路径文件里记录general日志了。

TiDB开启general log1. 相关参数

官方文档关于general_log的描述如下：

tidb_general_log

作用域：GLOBAL

是否持久化到集群：否，仅作用于当前连接的 TiDB 实例

默认值：OFF

这个变量用来设置是否在日志里记录所有的 SQL 语句。该功能默认关闭。如果系统运维人员在定位问题过程中需要追踪所有 SQL 记录，可考虑开启该功能。

在 TiDB 配置项 log.level 为"info"或"debug"时，通过查询"GENERAL_LOG"字符串可以定位到该功能在日志中的所有记录。日志会记录以下内容：

conn：当前会话对应的 ID

user：当前会话用户

schemaVersion：当前 schema 版本

txnStartTS：当前事务的开始时间戳

forUpdateTS：事务模式为悲观事务时，SQL 语句的当前时间戳。悲观事务内发生写冲突时，会重试当前执行语句，该时间戳会被更新。重试次数由 max-retry-count 配置。事务模式为乐观事务时，该条目与 txnStartTS 等价。

isReadConsistency：当前事务隔离级别是否是读已提交 (RC)

current_db：当前数据库名

txn_mode：事务模式。可选值：OPTIMISTIC（乐观事务模式），或 PESSIMISTIC（悲观事务模式）

sql：当前查询对应的 SQL 语句

2. tidb开启general log

set global tidb_general_log=on ，开启后针对当前节点立即生效，其他节点并不会开启，并且不会持久化到集群

 ## 更改前查看配置  TiDB root@10.18.13.224:test> show variables like %general%;  +--------------------------------+-------------------------------------+  | Variable_name | Value |  +--------------------------------+-------------------------------------+  | general_log | OFF |  | general_log_file | /usr/local/mysql/data/localhost.log |  | tidb_enable_general_plan_cache | OFF |  | tidb_general_log | OFF |  | tidb_general_plan_cache_size | 100 |  +--------------------------------+-------------------------------------+  5 rows in set  Time: 0.016s  TiDB root@10.18.13.224:test>  ​  ## 修改参数  TiDB root@10.18.13.224:test> set global tidb_general_log=on;  Query OK, 0 rows affected  Time: 0.009s  TiDB root@10.18.13.224:test>  ​  ## 查看修改结果  TiDB root@10.18.13.224:test> show variables like %general%;  +--------------------------------+-------------------------------------+  | Variable_name | Value |  +--------------------------------+-------------------------------------+  | general_log | OFF |  | general_log_file | /usr/local/mysql/data/localhost.log |  | tidb_enable_general_plan_cache | OFF |  | tidb_general_log | ON |  | tidb_general_plan_cache_size | 100 |  +--------------------------------+-------------------------------------+  5 rows in set  Time: 0.023s  TiDB root@10.18.13.224:test>

通过修改配置文件参数，使该参数永久生效，作用域范围根据配置，可以是单个节点，也可以是所有的tidb server。例（修改所有tidb server）：

 ## 更改前查看相关参数  TiDB root@10.18.13.224:test> show config where name like %general%  +------+-------------------+---------------------------+-------+  | Type | Instance | Name | Value |  +------+-------------------+---------------------------+-------+  | tidb | 10.18.13.225:4000 | instance.tidb_general_log | false |  | tidb | 10.18.13.227:4000 | instance.tidb_general_log | false |  | tidb | 10.18.13.226:4000 | instance.tidb_general_log | false |  +------+-------------------+---------------------------+-------+  3 rows in set  Time: 0.074s  TiDB root@10.18.13.224:test>  ​  ## 编辑配置文件  tiup cluster edit-config tidb-fl  ##配置文件中添加如下部分：  server_configs:   tidb:   instance.tidb_general_log: true  ## reload集群  tiup cluster reload tidb-fl  ## 查看更改  结果  TiDB root@10.18.13.224:test> show config where name like %general%  +------+-------------------+---------------------------+-------+  | Type | Instance | Name | Value |  +------+-------------------+---------------------------+-------+  | tidb | 10.18.13.225:4000 | instance.tidb_general_log | true |  | tidb | 10.18.13.227:4000 | instance.tidb_general_log | true |  | tidb | 10.18.13.226:4000 | instance.tidb_general_log | true |  +------+-------------------+---------------------------+-------+  3 rows in set  Time: 0.071s  TiDB root@10.18.13.224:test>

抓取网络日志

开启日志缺点

不论是tidb还是mysql，开启general会有性能损耗，尤其是生产环境。

写大量日志，io有影响；并发高、监控不及时的情况下还可能会把磁盘打爆。

所有的日志回记录到一个文件里面，查看起来并不友好。尤其是tidb，tidb的general log是跟tidb server的日志tidb.log记录到一起的，查看起来非常麻烦。

另外，在极端的高并发和高负载模式下，数据库可能会hang住，日志可能会记录不成功。

在上边这种情况下，我们可以跳过数据库层，直接从网络层抓取sql。本文主要介绍三个工具，tcpdump，vc-mysql-sniffer，mysql-snaffer

tcpdump

tcpdump是抓取网络包的一个工具，大家可能对其并不陌生，就简单说说使用方法，但是这种方式抓出来的文件，格式并不太友好，查看起来比较麻烦。

 tcpdump -i eth0 port 4000 -l -s 0 -w - | strings | grep -A 5 "select" > /tmp/tcpdump.txt

可以抓包结合pt-query-digest来分析查看

 ## 抓包  tcpdump -s 65535 -x -nn -q -tttt -i eth0 -c 1000 port 4000 > /tmp/tidb.tcp.txt  ​  ## pt-query-digest分析抓包结果  pt-query-digest --type tcpdump /tmp/tidb.tcp.txt vc-mysql-sniffer

vc-mysql-sniffer是一个免费的基于 MySQL 协议的抓包工具，只要是mysql协议的数据库都支持，是本文力荐的一个工具（个人测试对tidb支持非常友好）。说明如下

 vc-mysql-sniffer - A free tool to output query traffic for MySQL  ​  To run: Simply execute the binary to see queries written to stdout in  the format used by MySQLs slow query log. Add the -output=[filename] option  to write the output to the specified file instead.1. 主要优点

是一个二进制工具，使用起来比较方便。

对数据库server性能影响非常小。

相比tcpdump，不会生产很大的日志文件。

只要是支持mysql协议的数据库，都可以用其来抓取。

生成的日志文件，跟slow log类似，可以直接查看，也可以直接用pt-query-digest分析。

抓取的时候启动，不抓取随时可以停掉，数据库不用做任何配置更改。

***：vonwind/analysis-vc-mysql-sniffer (github.com)（由于官方已经不再更新该工具，这里就放了github的地址）

2. 使用方法一：

注意：vc-mysql-sniffer部署在数据库服务器上，如果tidb集群前端有代理（比如haproxy），需要部署在代理服务器上，以抓取所有的sql。

 ## help说明  [fenglei@qa-fenglei-01 vc-mysql-sniffer]$ ./vc-mysql-sniffer --help  vc-mysql-sniffer is a utility from VividCortex to monitor query activity and write results to a file.  See --license for the terms governing your usage of this program.  ​   -binding="[::]:3306" This is a list of comma separated bind strings as seen in /proc/net/tcp   -help="false" Show this usage message   -license="false" Print the usage terms of this program   -output="" Filepath to output queries to. Defaults to stdout if none specified.   -show-database="false" Include a USE `database` for every statement. Supersedes show-database-changes.   -show-database-changes="true"   Include a USE `database` every time the database is changed.   -verbose="false" Enable logging on program startup to stderr   -version="false" Show version and exit  ​   Flag Current value  --------------------------------------------   -binding "[::]:3306"   -help "true"   -license "false"   -output ""   -show-database "false"   -show-database-changes "true"   -verbose "false"   -version "false"  [fenglei@qa-fenglei-01 vc-mysql-sniffer]$  ​  ## 执行需要sudo权限  [fenglei@qa-fenglei-01 vc-mysql-sniffer]$ sudo ./vc-mysql-sniffer -binding="[::]:4000" -output="/tmp/vc_tidb_sql.log"  ​  ## 生成的结果可以用pt-query-digest直接分析  ./pt-query-digest /tmp/vc_tidb_sql.log > /tmp/result.log3. 使用方法二：用网友提供的一个脚本直接调用vc-mysql-sniffer直接生成sql统计结果

脚本地址：analysis-vc-mysql-sniffer/analysis-vc-log.py at master · vonwind/analysis-vc-mysql-sniffer (github.com)

 python analysis-vc-log.py yourip 3306 | sort | uniq -c | sort -nr |head -n 10mysql-sniffer

MySQL Sniffer 是一个基于 MySQL 协议的抓包工具，实时抓取 MySQLServer 端或 Client 端请求，并格式化输出。输出内容包括访问时间、访问用户、来源 IP、访问 Database、命令耗时、返回数据行数、执行语句等。有批量抓取多个端口，后台运行，日志分割等多种使用方式，操作便捷，输出友好。项目地址：Qihoo360/mysql-sniffer: mysql-sniffer is a network traffic analyzer tool for mysql, it is developed by Qihoo DBA and infrastructure team (github.com)

由于该项目也已经不再维护，原理跟vc-mysql-sniffer类似，只是输出结果（展示方式）不太一样。但是输出的结果不能用pt-query-digest分析，所以，个人还是更推荐 vc-mysql-sniffer。

总结

个人还是力荐vc-mysql-sniffer，也希望这个小工具能给大家的工作带来便利。文中有误不对的地方，也请大家拍砖指正。