mysql的全量(查詢)日志general-log的開啟和分析方法

    熟悉mysql的朋友應(yīng)該都知道,error日志只記錄數(shù)據(jù)庫(kù)層的報(bào)錯(cuò),binlog只記錄增/刪/改的記錄,但是沒(méi)記錄誰(shuí)執(zhí)行,只記錄執(zhí)行用戶名,slowlog雖然詳細(xì),但是只記錄超過(guò)設(shè)定值的慢查詢sql信息.

    只有g(shù)eneral-log才是記錄所有的操作日志,不過(guò)他會(huì)耗費(fèi)數(shù)據(jù)庫(kù)5%-10%的性能,所以一般沒(méi)什么特別需要,大多數(shù)情況是不開的,例如一些sql審計(jì)和不知名的排錯(cuò)等,那就是打開來(lái)使用了.

開啟的方法

    開啟方法很簡(jiǎn)單,

#先查看當(dāng)前狀態(tài)
mysql> show variables like 'general%';
+------------------+--------------------------------+
| Variable_name    | Value                          |
+------------------+--------------------------------+
| general_log      | OFF                            |
| general_log_file | /data/mysql/data/localhost.log |
+------------------+--------------------------------+
2 rows in set (0.00 sec)
#可以在my.cnf里添加,1開啟（0關(guān)閉）,當(dāng)然了,這樣要重啟才能生效,有點(diǎn)多余了
general-log = 1
log = /log/mysql_query.log路徑
#也可以設(shè)置變量那樣更改,1開啟（0關(guān)閉）,即時(shí)生效,不用重啟,首選當(dāng)然是這樣的了
set global general_log=1
#這個(gè)日志對(duì)于操作頻繁的庫(kù),產(chǎn)生的數(shù)據(jù)量會(huì)很快增長(zhǎng),出于對(duì)硬盤的保護(hù),可以設(shè)置其他存放路徑
set global general_log_file=/tmp/general_log.log

    然后就開啟完了,看看是否有這個(gè)文件存在并產(chǎn)生了日志,我們看到localhost.log已經(jīng)生成了,因?yàn)槲沂悄J(rèn)的,所以名字就是這樣的.

#ll
總用量 3215528
-rw-rw----. 1 mysql mysql         56 9月   5 11:32 auto.cnf
drwx------  2 mysql mysql       4096 9月  17 14:09 gw
-rw-rw----  1 mysql mysql      25666 9月   8 17:07 ib_buffer_pool
-rw-rw----. 1 mysql mysql 1073741824 9月  19 10:21 ibdata1
-rw-rw----. 1 mysql mysql 1073741824 9月  19 10:21 ib_logfile0
-rw-rw----. 1 mysql mysql 1073741824 9月   5 11:27 ib_logfile1
-rw-rw----  1 mysql mysql          5 9月   8 17:11 localhost.localdomain.pid
-rw-rw----  1 mysql mysql    6699602 9月  19 09:50 localhost.log
-rw-rw----  1 mysql mysql          5 9月  14 09:16 localhost.pid
drwx------. 2 mysql mysql       4096 9月   5 11:27 mysql
-rw-rw----  1 mysql mysql      34539 9月   7 14:57 mysql-bin.000006
-rw-rw----  1 mysql mysql   13746613 9月   8 17:07 mysql-bin.000007
-rw-rw----  1 mysql mysql     498989 9月  14 09:16 mysql-bin.000008
-rw-rw----  1 mysql mysql   48302055 9月  19 10:20 mysql-bin.000009
-rw-rw----  1 mysql mysql        136 9月  14 09:16 mysql-bin.index
-rw-rw----. 1 mysql mysql      57569 9月  14 09:16 mysql.err
drwx------. 2 mysql mysql       4096 9月   5 11:27 performance_schema
drwx------  2 mysql mysql       4096 9月  17 14:35 test

    開啟完了,就看怎么分析了.

分析日志

    其實(shí)也比較直觀,只是容易混淆,下面來(lái)看例子.

/usr/local/mysql/bin/mysqld, Version: 5.6.32-78.0-log (Percona Server (GPL), Release 78.0, Revision 8a8e016). started with:
Tcp port: 3306  Unix socket: /tmp/mysql.sock
Time                 Id Command    Argument
160919  9:28:19 30722 Connect   root@192.168.1.252 on test
                30722 Query     SET SESSION sql_mode =
                                        REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(
                                        @@sql_mode,
                                        "STRICT_ALL_TABLES,", ""),
                                        ",STRICT_ALL_TABLES", ""),
                                        "STRICT_ALL_TABLES", ""),
                                        "STRICT_TRANS_TABLES,", ""),
                                        ",STRICT_TRANS_TABLES", ""),
                                        "STRICT_TRANS_TABLES", "")
                30722 Query     SET NAMES utf8
                30722 Query     SELECT *
FROM `type`
WHERE `pid` = 30
                30722 Quit
160919  9:28:38 29975 Query     SHOW GLOBAL STATUS
160919  9:28:39 30728 Connect   root@192.168.1.95 on test
                30728 Query     SET SESSION sql_mode =
                                        REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(
                                        @@sql_mode,
                                        "STRICT_ALL_TABLES,", ""),
                                        ",STRICT_ALL_TABLES", ""),
                                        "STRICT_ALL_TABLES", ""),
                                        "STRICT_TRANS_TABLES,", ""),
                                        ",STRICT_TRANS_TABLES", ""),
                                        "STRICT_TRANS_TABLES", "")
                30728 Query     SET NAMES utf8
                30728 Query     SELECT `a`.*, `b`.`clientname`, `b`.`deptname`, `b`.`receiveprovince`, `b`.`carriers`, `b`.`receivecity`
FROM `repri` as `a`
LEFT JOIN `illmain` as `b` ON `a`.`illid` = `b`.`illID`
WHERE `a`.`id` = '21'
                30728 Query     SELECT `typename`
FROM `type`
WHERE `id` = '8'
                30728 Query     SELECT `typename`
FROM `type`
WHERE `id` = '9'
                30728 Query     SELECT *
FROM `handlepri`
WHERE `id` = '21'
                30728 Query     SELECT *
FROM `low_re`
WHERE `low` = '21'
AND `type` =0
ORDER BY `id` desc
                30728 Query     SELECT *
FROM `guide`
WHERE `ll_type` = '9'
                30728 Query     SELECT *
FROM `illmain`
WHERE `illid` = '0992016'
OR `orderid` = '0992016'
                30728 Quit

    我們來(lái)按列來(lái)解析

第一列:時(shí)間列,前面一個(gè)是日期,后面一個(gè)是小時(shí)和分鐘,有一些不顯示的原因是因?yàn)檫@些sql語(yǔ)句幾乎是同時(shí)執(zhí)行的,所以就不另外記錄時(shí)間了.

第二列:ID列,就是show processlist出來(lái)的第一列的線程ID,對(duì)于長(zhǎng)連接和一些比較耗時(shí)的sql語(yǔ)句,你可以精確找出究竟是那一條那一個(gè)線程在運(yùn)行.

第三列:操作類型,Connect就是連接數(shù)據(jù)庫(kù),Query就是查詢數(shù)據(jù)庫(kù)(增刪查改都顯示為查詢),可以特定過(guò)慮一些操作.

第四列:詳細(xì)信息,例如上面例子Connect的詳細(xì)信息就是root@192.168.1.95 on test,意思就是root@192.168.1.95連上test庫(kù),如此類推,下面的意思就是30728這個(gè)線程號(hào)連上數(shù)據(jù)庫(kù)之后,做了什么查詢的操作.

    還有其他一些grant/drop/create/alter等的操作,general_log都回全部記錄下來(lái),不過(guò)這里就不細(xì)細(xì)演示了,各位可以嘗試一下.

    最后,也正如我開始說(shuō)的,有了這些信息,做sql語(yǔ)句審計(jì)就變得可能了,找到責(zé)任人也是沒(méi)有壓力的,而對(duì)于一些疑難雜癥的sql分析也是很簡(jiǎn)單了.