MySQL 抓包工具 - MySQL Sniffer 使用小结 (含带general_log日志)
在mysql运维工作中，一般会使用tcpdump做一些分析（直接读分析日志比较难以看明白，在数据库连接值高时使用）；对于mysql实时的连接监控分析，通常会使用"mysqladmin/show full processlist"查看，也可直接查询processlist表。但对于长时间监控连接数据库的应用IP、操作记录而言，MySQL Sniffer的出现，让人眼前一亮！有时候我们需要统计线上的SQL执行情况，比如想知道哪条SQL执行最频繁，我们可以开启general_log，然后进行统计，但是general_log开启非常损耗性能, 这时候就可以使用mysql-sniffer来代替了。
MySQL Sniffer 是一个基于 MySQL 协议的实时抓包工具，实时抓取 MySQLServer 端的请求，并格式化输出。输出内容包访问括时间、访问用户、来源 IP、访问 Database、命令耗时、返回数据行数、执行语句等。有批量抓取多个端口，后台运行，日志分割等多种使用方式，操作便捷，输出友好。MySQL Sniffer是第三方SQL语句监控工具，是个不错的调试工具，在客户端、WebServer端无法有效跟踪特定SQL查询时，MySQL Sniffer显得尤其有用。虽然我们可以打开MySQL的所有SQL语句记录设置，设置的方法是在my.cnf文件的mysqld区域配置下加入内容"log=/var/mysqllog/sql.log" ，但是这样做，會记录全部SQL查询，如果网站访问量很大，日志增长也会很快，容易导致硬盘满，也不方便分析SQL语句，同时也会增加数据库服务器负担。而MySQLSniffer可以不必生成日志文件，且可以跟踪特定的SQL查询，所以这时候就是MySQLSniffer发挥作用的时候。同类型工具还有vc-mysql-sniffer，以及 tshark 的 -e mysql.query 参数来解析 MySQL 协议。
Mysql Sniffer 安装使用记录
[root@kevin-mysql ~]# wget http://dl.fedoraproject.org/pub/epel/epel-release-latest-6.noarch.rpm
[root@kevin-mysql ~]# rpm -ivh epel-release-latest-6.noarch.rpm --force
[root@kevin-mysql ~]# yum install cmake libpcap-devel glib2-devel libnet-devel
[root@kevin-mysql ~]# git clone https://github.com/Qihoo360/mysql-sniffer.git
[root@kevin-mysql ~]# cd mysql-sniffer
[root@kevin-mysql mysql-sniffer]# mkdir proj
[root@kevin-mysql mysql-sniffer]# cd proj
[root@kevin-mysql proj]# cmake ../
[root@kevin-mysql proj]# make
在bin目录下面生成了mysql-sniffer
[root@kevin-mysql proj]# ls bin/mysql-sniffer
bin/mysql-sniffer
[root@kevin-mysql proj]# vim /etc/profile
..........
PATH=$PATH:/usr/local/src/mysql-sniffer/proj/bin/
使之生效
[root@kevin-mysql ~]# source /etc/profile
查看mysql-sniffer帮助
[root@kevin-mysql ~]# mysql-sniffer --help
mysql-sniffer: invalid option -- '-'
Usage mysql-sniffer [-d] -i eth0 -p 3306,3307,3308 -l /var/log/mysql-sniffer/ -e stderr
[-d] -i eth0 -r 3000-4000
-d daemon mode. #
-s how often to split the log file(minute, eg. 1440). if less than 0, split log everyday
-i interface. Default to eth0 #网卡名
-p port, default to 3306. Multiple ports should be splited by ','. eg. 3306,3307
this option has no effect when -f is set. #端口，多个端口,分割，不能和-f一起使用
-r port range, Don't use -r and -p at the same time #端口范围，不能和-p一起使用
-l query log DIRECTORY. Make sure that the directory is accessible. Default to stdout. #输出打印到文件
-e error log FILENAME or 'stderr'. if set to /dev/null, runtime error will not be recorded
-f filename. use pcap file instead capturing the network interface
-w white list. dont capture the port. Multiple ports should be splited by ','. #排除的端口
-t truncation length. truncate long query if it's longer than specified length. Less than 0 means no truncation #截取制定长度的SQL
-n keeping tcp stream count, if not set, default is 65536. if active tcp count is larger than the specified count, mysql-sniffer will remove the oldest one #指定数据包个数
输出格式：时间，访问用户，来源 IP，访问 Database，命令耗时，返回数据行数，执行语句。
1) 实时抓取某端口信息并打印到屏幕: -i 指定网卡名，-p 指定抓取的端口
[root@kevin-mysql ~]# mysql-sniffer -i eth0 -p 3306
2019-01-22 21:26:23 NULL 172.16.50.190 NULL 0ms 1 SELECT * FROM QRTZ_SCHEDULER_STATE WHERE SCHED_NAME = 'schedulerFactoryBean'
2019-01-22 21:26:23 NULL 172.16.50.190 NULL 0ms 1 UPDATE QRTZ_SCHEDULER_STATE SET LAST_CHECKIN_TIME = 1548163583372 WHERE SCHED_NAME = 'schedulerFactoryBean' AND INSTANCE_NAME = 'uatcx02.veredholdings.cn1547705543409'
2019-01-22 21:26:23 NULL 172.16.50.190 NULL 1ms 0 commit
2019-01-22 21:26:23 NULL 172.16.50.190 NULL 0ms 0 commit
2019-01-22 21:26:23 NULL 172.16.50.190 NULL 0ms 0 SET autocommit=1
2019-01-22 21:26:28 NULL 172.16.50.190 NULL 0ms 0 SET autocommit=0
2019-01-22 21:26:28 NULL 172.16.50.190 NULL 0ms 1 SELECT * FROM QRTZ_SCHEDULER_STATE WHERE SCHED_NAME = 'schedulerFactoryBean'
2019-01-22 21:26:28 NULL 172.16.50.190 NULL 0ms 1 UPDATE QRTZ_SCHEDULER_STATE SET LAST_CHECKIN_TIME = 1548163588398 WHERE SCHED_NAME = 'schedulerFactoryBean' AND INSTANCE_NAME = 'uatcx02.veredholdings.cn1547705543409'
2019-01-22 21:26:28 NULL 172.16.50.190 NULL 1ms 0 commit
2019-01-22 21:26:28 NULL 172.16.50.190 NULL 0ms 0 commit
2019-01-22 21:26:28 NULL 172.16.50.190 NULL 0ms 0 SET autocommit=1
2019-01-22 21:26:33 NULL 172.16.50.190 NULL 0ms 0 SET autocommit=0
2019-01-22 21:26:33 NULL 172.16.50.190 NULL 0ms 1 SELECT COUNT(TRIGGER_NAME) FROM QRTZ_TRIGGERS WHERE SCHED_NAME = 'schedulerFactoryBean' AND NOT (MISFIRE_INSTR = -1) AND NEXT_FIRE_TIME < 1548163533068 AND TRIGGER_STATE = 'WAITING'
2) 实时抓取某端口信息并打印到文件: -l 指定日志输出路径，日志文件将以 port.log 命名。
[root@kevin-mysql ~]# mysql-sniffer -i eth0 -p 3306 -l /tmp/
[root@kevin-mysql ~]# cat /tmp/3306.log
2019-01-22 21:28:33 NULL 172.16.50.190 NULL 0ms 1 SELECT COUNT(TRIGGER_NAME) FROM QRTZ_TRIGGERS WHERE SCHED_NAME = 'schedulerFactoryBean' AND NOT (MISFIRE_INSTR = -1) AND NEXT_FIRE_TIME < 1548163653068 AND TRIGGER_STATE = 'WAITING'
2019-01-22 21:28:33 NULL 172.16.50.190 NULL 0ms 0 commit
2019-01-22 21:28:33 NULL 172.16.50.190 NULL 0ms 0 SET autocommit=1
2019-01-22 21:28:33 NULL 172.16.50.190 NULL 0ms 0 SET autocommit=0
2019-01-22 21:28:33 NULL 172.16.50.190 NULL 0ms 1 SELECT * FROM QRTZ_SCHEDULER_STATE WHERE SCHED_NAME = 'schedulerFactoryBean'
2019-01-22 21:28:33 NULL 172.16.50.190 NULL 0ms 1 UPDATE QRTZ_SCHEDULER_STATE SET LAST_CHECKIN_TIME = 1548163713643 WHERE SCHED_NAME = 'schedulerFactoryBean' AND INSTANCE_NAME = 'uatcx02.veredholdings.cn1547705543409'
2019-01-22 21:28:33 NULL 172.16.50.190 NULL 1ms 0 commit
2019-01-22 21:28:33 NULL 172.16.50.190 NULL 0ms 0 commit
2019-01-22 21:28:33 NULL 172.16.50.190 NULL 0ms 0 SET autocommit=1
3) 实时抓取多个端口信息并打印到文件: -l 指定日志输出路径，-p指定需要抓取的端口列表逗号分割，日志文件将以各自 port.log 命名。
[root@kevin-mysql ~]# mysql-sniffer -i eth0 -p 3306,3307,3307 -l /tmp/
[root@kevin-mysql ~]# cat /tmp/3306.log
4) 实时抓取多个连续递增的端口并打印到文件: -l 指定日志输出路径，-r 指定端口范围，日志文件将以各自 port.log 命名。
[root@kevin-mysql ~]# mysql-sniffer -i eth0 -r 3306-3309 -l /tmp/
[root@kevin-mysql ~]# cat /tmp/3306.log
5) 实时抓取多个连续递增的端口同时过滤某几个端口，并打印到文件:-l 指定日志输出路径，-r 指定端口范围， -w 指定过滤端口列表逗号分割，日志文件将以各自 port.log 命名。
[root@kevin-mysql ~]# mysql-sniffer -i eth0 -r 3306-3311 -w 3307,3309 -l /tmp/
[root@kevin-mysql ~]# cat /tmp/3306.log
6) 抓取某个端口以 daemon 模式运行（-d），并打印到文件: -l 指定日志输出路径，-p 指定端口， -n 指定数据包个数，日志文件将以各自 port.log 命名。
[root@kevin-mysql ~]# mysql-sniffer -i eth0 -p 3306 -l /tmp/ -d
[root@kevin-mysql ~]# cat /tmp/3306.log
7) 抓取某个端口并截取指定长度的 SQL: -p 指定端口， -t 指定SQL长度，将输出 SQL的前n个字符 (适用于 SQL 过长的场景)。
[root@kevin-mysql ~]# mysql-sniffer -i eth0 -p 3306 -t 10
2019-01-22 21:32:29 NULL 172.16.50.190 NULL 0ms 1 SELECT * F...
2019-01-22 21:32:29 NULL 172.16.50.190 NULL 0ms 1 UPDATE QRT...
2019-01-22 21:32:29 NULL 172.16.50.190 NULL 1ms 0 commit
2019-01-22 21:32:29 NULL 172.16.50.190 NULL 0ms 0 commit
2019-01-22 21:32:29 NULL 172.16.50.190 NULL 0ms 0 SET autoco...
2019-01-22 21:32:33 NULL 172.16.50.190 NULL 0ms 0 SET autoco...
2019-01-22 21:32:33 NULL 172.16.50.190 NULL 0ms 1 SELECT COU...
2019-01-22 21:32:33 NULL 172.16.50.190 NULL 0ms 0 commit
2019-01-22 21:32:33 NULL 172.16.50.190 NULL 0ms 0 SET autoco...
8) 抓取mysql 3306端口，统计执行最频繁的10条SQL
[root@kevin-mysql ~]# mysql-sniffer -i eth0 -p 3306 -l /tmp/
[root@kevin-mysql ~]# cat /tmp/3306.log |sort | uniq -c | sort -nr |head -n 10
4 2019-01-22 22:12:48 NULL 172.16.50.190 NULL 0ms 0 SET autocommit=1
4 2019-01-22 22:12:48 NULL 172.16.50.190 NULL 0ms 0 SET autocommit=0
4 2019-01-22 22:12:48 NULL 172.16.50.190 NULL 0ms 0 commit
2 2019-01-22 22:13:33 NULL 172.16.50.190 NULL 0ms 0 SET autocommit=1
2 2019-01-22 22:13:33 NULL 172.16.50.190 NULL 0ms 0 SET autocommit=0
2 2019-01-22 22:13:33 NULL 172.16.50.190 NULL 0ms 0 commit
2 2019-01-22 22:12:48 NULL 172.16.50.190 NULL 1ms 0 commit
2 2019-01-22 22:12:48 NULL 172.16.50.190 NULL 0ms 1 UPDATE QRTZ_SCHEDULER_STATE SET LAST_CHECKIN_TIME = 1548166368279 WHERE SCHED_NAME = 'schedulerFactoryBean' AND INSTANCE_NAME = 'uatcx02.veredholdings.cn1547705543409'
2 2019-01-22 22:12:48 NULL 172.16.50.190 NULL 0ms 1 SELECT * FROM QRTZ_SCHEDULER_STATE WHERE SCHED_NAME = 'schedulerFactoryBean'
2 2019-01-22 22:12:48 NULL 172.16.50.190 NULL 0ms 1 SELECT * FROM QRTZ_LOCKS WHERE SCHED_NAME = 'schedulerFactoryBean' AND LOCK_NAME = 'TRIGGER_ACCESS' FOR UPDATE
总结: 通过上面的示例，看到mysql-sniffer工具通过指定的端口监控mysql，把所有的命里打印出来。看着和MySQL自己的general_log看似差不多，不过该工具已经按照需要的输出格式更好方便的查看，重要的还可以查看SQL范围的行数，便于在排查故障的时候用得到。
这里顺便说一下MySQL的general_log日志(用于跟踪统计sql执行记录)
general log会记录下发送给MySQL服务器的所有SQL记录，因为SQL的量大，默认是不开启的。一些特殊情况（如排除故障）可能需要临时开启一下。因为有时候我们需要统计线上的SQL执行情况，比如想知道哪条SQL执行最频繁，我们可以开启general_log，然后进行统计，但是general_log开启非常损耗性能, 这时候就可以使用mysql-sniffer来代替了。
MySQL有三个参数用于设置general log：
- general_log：用于开启general log。ON表示开启，OFF表示关闭。
- log_output：日志输出的模式。FILE表示输出到文件，TABLE表示输出到mysq库的general_log表，NONE表示不记录general_log。
- general_log_file：日记输出文件的路径，这是log_output=FILE时才会输出到此文件。
1) 查看先是否开启了general log
mysql> show variables where Variable_name="general_log"; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | general_log | OFF | +---------------+-------+ 1 row in set (0.00 sec)
2) 查看日志输出模式
mysql> show variables where Variable_name="log_output"; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | log_output | FILE | +---------------+-------+ 1 row in set (0.00 sec)
3) 查看日志输出路径
mysql> show variables where Variable_name="general_log_file"; +------------------+----------------------------+ | Variable_name | Value | +------------------+----------------------------+ | general_log_file | /var/run/mysqld/mysqld.log | +------------------+----------------------------+ 1 row in set (0.00 sec)
4) 设置日志模式为TABLE，FILE双模式
mysql> set global log_output='TABLE,FILE'; Query OK, 0 rows affected (0.00 sec) mysql> show variables where Variable_name="log_output"; +---------------+------------+ | Variable_name | Value | +---------------+------------+ | log_output | FILE,TABLE | +---------------+------------+ 1 row in set (0.00 sec) mysql> show variables where Variable_name="general_log_file"; +------------------+------------------------------+ | Variable_name | Value | +------------------+------------------------------+ | general_log_file | /var/lib/mysql/MGR-node1.log | +------------------+------------------------------+ 1 row in set (0.00 sec) mysql> select * from mysql.general_log; +----------------------------+-------------------------------------+-----------+-----------+--------------+--------------------------------------------------+ | event_time | user_host | thread_id | server_id | command_type | argument | +----------------------------+-------------------------------------+-----------+-----------+--------------+--------------------------------------------------+ | 2019-01-22 22:25:44.151592 | monitor[monitor] @ [172.16.60.214] | 10746 | 1 | Query | SELECT @@global.read_only | | 2019-01-22 22:25:45.635513 | monitor[monitor] @ [172.16.60.214] | 10746 | 1 | Query | SELECT @@global.read_only | | 2019-01-22 22:25:47.135686 | monitor[monitor] @ [172.16.60.214] | 10746 | 1 | Query | SELECT @@global.read_only | | 2019-01-22 22:25:48.635743 | monitor[monitor] @ [172.16.60.214] | 10746 | 1 | Query | SELECT @@global.read_only | | 2019-01-22 22:25:50.170598 | monitor[monitor] @ [172.16.60.214] | 10746 | 1 | Query | SELECT @@global.read_only | | 2019-01-22 22:25:51.636044 | monitor[monitor] @ [172.16.60.214] | 10746 | 1 | Query | SELECT @@global.read_only | | 2019-01-22 22:25:53.147893 | monitor[monitor] @ [172.16.60.214] | 10746 | 1 | Query | SELECT @@global.read_only | | 2019-01-22 22:25:54.346027 | root[root] @ localhost [] | 10892 | 1 | Query | show variables where Variable_name="general_log" | ............ ............ 如上设置后，所有对此mysql数据库的sql操作不仅会被记录/var/lib/mysql/MGR-node1.log日志中(即general.log文件） 而且这些sql操作还会被记录到mysql库下的general_log表内 ============================================================== 还可以自定义设置general.log日志文件的路径，一般要设置到/tmp 或 /var 文件夹下，设置其他路径出错!!! mysql> set global general_log_file='/tmp/general.log'; Query OK, 0 rows affected (0.00 sec) mysql> show variables where Variable_name="general_log_file"; +------------------+------------------+ | Variable_name | Value | +------------------+------------------+ | general_log_file | /tmp/general.log | +------------------+------------------+ 1 row in set (0.01 sec)
5) 开启general log
mysql> set global general_log=ON; Query OK, 0 rows affected (0.00 sec) mysql> show variables where Variable_name="general_log"; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | general_log | ON | +---------------+-------+ 1 row in set (0.01 sec)
6) 关闭general log
大多数情况是临时开启general log，需要记得关闭，并把日志的输出模式恢复为FILE
mysql> set global general_log=OFF; Query OK, 0 rows affected (0.00 sec) mysql> set global log_output='FILE'; Query OK, 0 rows affected (0.00 sec) mysql> show variables where Variable_name="general_log"; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | general_log | OFF | +---------------+-------+ 1 row in set (0.00 sec) mysql> show variables where Variable_name="log_output"; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | log_output | FILE | +---------------+-------+ 1 row in set (0.00 sec)
*************** 当你发现自己的才华撑不起野心时，就请安静下来学习吧！***************
