天天看點

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

熟悉mysql的朋友應該都知道,error日志隻記錄資料庫層的報錯,binlog隻記錄增/删/改的記錄,但是沒記錄誰執行,隻記錄執行使用者名,slowlog雖然詳細,但是隻記錄超過設定值的慢查詢sql資訊.

    隻有general-log才是記錄所有的記錄檔,不過他會耗費資料庫5%-10%的性能,是以一般沒什麼特别需要,大多數情況是不開的,例如一些sql審計和不知名的排錯等,那就是打開來使用了.

開啟的方法

    開啟方法很簡單,

<code>#先檢視目前狀态</code>

<code>mysql&gt; show variables like </code><code>'general%'</code><code>;</code>

<code>+------------------+--------------------------------+</code>

<code>| Variable_name    | Value                          |</code>

<code>| general_log      | OFF                            |</code>

<code>| general_log_file | </code><code>/data/mysql/data/localhost</code><code>.log |</code>

<code>2 rows </code><code>in</code> <code>set</code> <code>(0.00 sec)</code>

<code>#可以在my.cnf裡添加,1開啟(0關閉),當然了,這樣要重新開機才能生效,有點多餘了</code>

<code>general-log = 1</code>

<code>log = </code><code>/log/mysql_query</code><code>.log路徑</code>

<code>#也可以設定變量那樣更改,1開啟(0關閉),即時生效,不用重新開機,首選當然是這樣的了</code>

<code>set</code> <code>global general_log=1</code>

<code>#這個日志對于操作頻繁的庫,産生的資料量會很快增長,出于對硬碟的保護,可以設定其他存放路徑</code>

<code>set</code> <code>global general_log_file=</code><code>/tmp/general_log</code><code>.log</code>

    然後就開啟完了,看看是否有這個檔案存在并産生了日志,我們看到localhost.log已經生成了,因為我是預設的,是以名字就是這樣的.

<code>#ll</code>

<code>總用量 3215528</code>

<code>-rw-rw----. 1 mysql mysql         56 9月   5 11:32 auto.cnf</code>

<code>drwx------  2 mysql mysql       4096 9月  17 14:09 gw</code>

<code>-rw-rw----  1 mysql mysql      25666 9月   8 17:07 ib_buffer_pool</code>

<code>-rw-rw----. 1 mysql mysql 1073741824 9月  19 10:21 ibdata1</code>

<code>-rw-rw----. 1 mysql mysql 1073741824 9月  19 10:21 ib_logfile0</code>

<code>-rw-rw----. 1 mysql mysql 1073741824 9月   5 11:27 ib_logfile1</code>

<code>-rw-rw----  1 mysql mysql          5 9月   8 17:11 localhost.localdomain.pid</code>

<code>-rw-rw----  1 mysql mysql    6699602 9月  19 09:50 localhost.log</code>

<code>-rw-rw----  1 mysql mysql          5 9月  14 09:16 localhost.pid</code>

<code>drwx------. 2 mysql mysql       4096 9月   5 11:27 mysql</code>

<code>-rw-rw----  1 mysql mysql      34539 9月   7 14:57 mysql-bin.000006</code>

<code>-rw-rw----  1 mysql mysql   13746613 9月   8 17:07 mysql-bin.000007</code>

<code>-rw-rw----  1 mysql mysql     498989 9月  14 09:16 mysql-bin.000008</code>

<code>-rw-rw----  1 mysql mysql   48302055 9月  19 10:20 mysql-bin.000009</code>

<code>-rw-rw----  1 mysql mysql        136 9月  14 09:16 mysql-bin.index</code>

<code>-rw-rw----. 1 mysql mysql      57569 9月  14 09:16 mysql.err</code>

<code>drwx------. 2 mysql mysql       4096 9月   5 11:27 performance_schema</code>

<code>drwx------  2 mysql mysql       4096 9月  17 14:35 </code><code>test</code>

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

分析日志

    其實也比較直覺,隻是容易混淆,下面來看例子.

<code>/usr/local/mysql/bin/mysqld</code><code>, Version: 5.6.32-78.0-log (Percona Server (GPL), Release 78.0, Revision 8a8e016). started with:</code>

<code>Tcp port: 3306  Unix socket: </code><code>/tmp/mysql</code><code>.sock</code>

<code>Time                 Id Command    Argument</code>

<code>160919  9:28:19 30722 Connect   [email protected] on </code><code>test</code>

<code>                </code><code>30722 Query     SET SESSION sql_mode =</code>

<code>                                        </code><code>REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(REPLACE(</code>

<code>                                        </code><code>@@sql_mode,</code>

<code>                                        </code><code>"STRICT_ALL_TABLES,"</code><code>, </code><code>""</code><code>),</code>

<code>                                        </code><code>",STRICT_ALL_TABLES"</code><code>, </code><code>""</code><code>),</code>

<code>                                        </code><code>"STRICT_ALL_TABLES"</code><code>, </code><code>""</code><code>),</code>

<code>                                        </code><code>"STRICT_TRANS_TABLES,"</code><code>, </code><code>""</code><code>),</code>

<code>                                        </code><code>",STRICT_TRANS_TABLES"</code><code>, </code><code>""</code><code>),</code>

<code>                                        </code><code>"STRICT_TRANS_TABLES"</code><code>, </code><code>""</code><code>)</code>

<code>                </code><code>30722 Query     SET NAMES utf8</code>

<code>                </code><code>30722 Query     SELECT *</code>

<code>FROM `</code><code>type</code><code>`</code>

<code>WHERE `pid` = 30</code>

<code>                </code><code>30722 Quit</code>

<code>160919  9:28:38 29975 Query     SHOW GLOBAL STATUS</code>

<code>160919  9:28:39 30728 Connect   [email protected] on </code><code>test</code>

<code>                </code><code>30728 Query     SET SESSION sql_mode =</code>

<code>                </code><code>30728 Query     SET NAMES utf8</code>

<code>                </code><code>30728 Query     SELECT `a`.*, `b`.`clientname`, `b`.`deptname`, `b`.`receiveprovince`, `b`.`carriers`, `b`.`receivecity`</code>

<code>FROM `repri` as `a`</code>

<code>LEFT JOIN `illmain` as `b` ON `a`.`illid` = `b`.`illID`</code>

<code>WHERE `a`.`</code><code>id</code><code>` = </code><code>'21'</code>

<code>                </code><code>30728 Query     SELECT `typename`</code>

<code>WHERE `</code><code>id</code><code>` = </code><code>'8'</code>

<code>WHERE `</code><code>id</code><code>` = </code><code>'9'</code>

<code>                </code><code>30728 Query     SELECT *</code>

<code>FROM `handlepri`</code>

<code>WHERE `</code><code>id</code><code>` = </code><code>'21'</code>

<code>FROM `low_re`</code>

<code>WHERE `low` = </code><code>'21'</code>

<code>AND `</code><code>type</code><code>` =0</code>

<code>ORDER BY `</code><code>id</code><code>` desc</code>

<code>FROM `guide`</code>

<code>WHERE `ll_type` = </code><code>'9'</code>

<code>FROM `illmain`</code>

<code>WHERE `illid` = </code><code>'0992016'</code>

<code>OR `orderid` = </code><code>'0992016'</code>

<code>                </code><code>30728 Quit</code>

    我們來按列來解析

第一列:時間列,前面一個是日期,後面一個是小時和分鐘,有一些不顯示的原因是因為這些sql語句幾乎是同時執行的,是以就不另外記錄時間了.

第二列:ID列,就是show processlist出來的第一列的線程ID,對于長連接配接和一些比較耗時的sql語句,你可以精确找出究竟是那一條那一個線程在運作.

第三列:操作類型,Connect就是連接配接資料庫,Query就是查詢資料庫(增删查改都顯示為查詢),可以特定過慮一些操作.

第四列:詳細資訊,例如上面例子Connect的詳細資訊就是[email protected] on test,意思就是[email protected]連上test庫,如此類推,下面的意思就是30728這個線程号連上資料庫之後,做了什麼查詢的操作.

    還有其他一些grant/drop/create/alter等的操作,general_log都回全部記錄下來,不過這裡就不細細示範了,各位可以嘗試一下.

    最後,也正如我開始說的,有了這些資訊,做sql語句審計就變得可能了,找到責任人也是沒有壓力的,而對于一些疑難雜症的sql分析也是很簡單了.

     本文轉自arthur376 51CTO部落格,原文連結:http://blog.51cto.com/arthur376/1853924,如需轉載請自行聯系原作者