Mysql抓包工具 - MySQL Sniffer 使用小結 (含帶general_log日誌)

時間 2019-11-10

標籤 mysql 抓包工具 sniffer 使用小結 general log 日誌欄目 MySQL 简体版

原文原文鏈接

在mysql運維工做中，通常會使用tcpdump作一些分析（直接讀分析日誌比較難以看明白，在數據庫鏈接值高時使用）；對於mysql實時的鏈接監控分析，一般會使用"mysqladmin/show full processlist"查看，也可直接查詢processlist表。但對於長時間監控鏈接數據庫的應用IP、操做記錄而言，MySQL Sniffer的出現，讓人眼前一亮！有時候咱們須要統計線上的SQL執行狀況，好比想知道哪條SQL執行最頻繁，咱們能夠開啓general_log，而後進行統計，可是general_log開啓很是損耗性能, 這時候就能夠使用mysql-sniffer來代替了。node

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

Mysql Sniffer 安裝使用記錄 git

[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範圍的行數，便於在排查故障的時候用獲得。github

這裏順便說一下MySQL的general_log日誌(用於跟蹤統計sql執行記錄) 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時纔會輸出到此文件。vim

1) 查看先是否開啓了general logbash

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) 查看日誌輸出路徑less

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)