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

散盡浮華發表於2016-07-19

 

在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)  

相關文章