mysql抓包分析_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)