探究MySQL中的日誌檔案

pjmike_pj發表於2018-08-21

前言

日誌檔案記錄了影響MySQL資料庫的各種型別活動,MySQL資料庫中常見的日誌檔案有錯誤日誌,二進位制日誌,慢查詢日誌和查詢日誌。下面分別對他們進行介紹。

錯誤日誌

錯誤日誌檔案對MySQL的啟動,執行,關閉過程進行了記錄。

mysql> show variables like 'log_error';
+---------------+---------------------+
| Variable_name | Value               |
+---------------+---------------------+
| log_error     | /var/log/mysqld.log |
+---------------+---------------------+
1 row in set (0.03 sec)
複製程式碼

可以看到錯誤日誌的路徑和檔名,預設情況下錯誤檔案的檔名為伺服器的主機名,即:hostname.err。只不過我這裡設定的是/var/log/mysqld.log,修改錯誤日誌地址可以在/etc/my.cnf中新增

# Recommended in standard MySQL setup
sql_mode=NO_ENGINE_SUBSTITUTION,STRICT_TRANS_TABLES

[mysqld_safe]
log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid
複製程式碼

當出現MySQL資料庫不能正常啟動時,第一個必須查詢的檔案就是錯誤日誌檔案,該檔案記錄了出錯資訊,能夠幫助我們找到問題。

慢查詢日誌

慢查詢日誌用來記錄響應時間超過閾值的SQL語句,所以我們可以設定一個閾值,將執行時間超過該值的所有SQL語句都記錄到慢查詢日誌檔案中。該閾值可以通過引數 long_query_time 來設定,預設為10秒。

啟動慢查詢日誌

預設情況下,MySQL資料庫並不啟動慢查詢日誌,需要手動將這個引數設為ON,然後啟動

mysql> show variables like "%slow%";
+---------------------------+-------------------------------------------------+
| Variable_name             | Value                                           |
+---------------------------+-------------------------------------------------+
| log_slow_admin_statements | OFF                                             |
| log_slow_slave_statements | OFF                                             |
| slow_launch_time          | 2                                               |
| slow_query_log            | OFF                                             |
| slow_query_log_file       | /var/lib/mysql/iz2zeaf3cg1099kiidi06mz-slow.log |
+---------------------------+-------------------------------------------------+
5 rows in set (0.00 sec)

mysql> set global slow_query_log='ON';
Query OK, 0 rows affected (0.00 sec)


mysql> show variables like "slow_query_log";
+---------------------------+-------------------------------------------------+
| Variable_name             | Value                                           |
+---------------------------+-------------------------------------------------+                                        |
| slow_query_log            | ON                                              |
| slow_query_log_file       | /var/lib/mysql/iz2zeaf3cg1099kiidi06mz-slow.log |
+---------------------------+-------------------------------------------------+
2   rows in set (0.00 sec)

複製程式碼

但是使用 set global slow_query_log='ON' 開啟慢查詢日誌,只是對當前資料庫有效,如果MySQL資料庫重啟後就會失效。所以如果要永久生效,就要修改配置檔案 my.cnf (其他系統變數也是如此),如下:

[mysqld]
slow_query_log=1
複製程式碼

然後重啟MySQL就可以讓慢查詢日誌記錄開啟了,至於日誌檔案的路徑就是上面slow_query_log_file對應的路徑。

設定閾值

mysql> show variables like 'long_query_time';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.00 sec)
複製程式碼

閾值預設為10秒,我們可以修改閾值大小,比如(當然這還是對當前資料庫有效):

mysql> set global long_query_time=0.05;
Query OK, 0 rows affected (0.00 sec)
複製程式碼

設定long_query_time這個閾值之後,MySQL資料庫會記錄執行時間超過該值的所有SQL語句,但對於執行時間正好等於 long_query_time 的情況,並不會被記錄下。而設定 long_query_time為0來捕獲所有的查詢

引數log_queries_not_using_indexes

另一個和慢查詢日誌有關的引數是 log_queries_not_using_indexes, 如果執行的SQL語句沒有使用索引,則MySQL資料庫同樣會將這條SQL語句記錄到慢查詢日誌檔案。首先確認開啟了log_queries_not_using_indexes;

mysql> show variables like 'log_queries_not_using_indexes';
+-------------------------------+-------+
| Variable_name                 | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | ON    |
+-------------------------------+-------+
1 row in set (0.12 sec)

複製程式碼

例子,沒有用到索引進行查詢:

mysql> explain select * from vote_record_memory where vote_id = 323;
+----+-------------+--------------------+------+---------------+------+---------+------+--------+-------------+
| id | select_type | table              | type | possible_keys | key  | key_len | ref  | rows   | Extra       |
+----+-------------+--------------------+------+---------------+------+---------+------+--------+-------------+
|  1 | SIMPLE      | vote_record_memory | ALL  | NULL          | NULL | NULL    | NULL | 149272 | Using where |
+----+-------------+--------------------+------+---------------+------+---------+------+--------+-------------+
1 row in set (1.56 sec)
複製程式碼

可以看到是進行了全表掃描; 然後去log日誌檔案中檢視這條SQL已經被標記為慢SQL,因為它沒有使用索引。

# Time: 180817 11:42:59
# User@Host: root[root] @  [117.136.86.151]  Id:  2625
# Query_time: 0.016542  Lock_time: 0.000112 Rows_sent: 142  Rows_examined: 149272
SET timestamp=1534477379;
select * from vote_record_memory where vote_id = 323;

複製程式碼

將日誌記錄放入表中

MySQL5.1開始可以將慢查詢的日誌記錄放入一張表中,在mysql資料庫下,名為slow_log

| slow_log | CREATE TABLE `slow_log` (
  `start_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
  `user_host` mediumtext NOT NULL,
  `query_time` time NOT NULL,
  `lock_time` time NOT NULL,
  `rows_sent` int(11) NOT NULL,
  `rows_examined` int(11) NOT NULL,
  `db` varchar(512) NOT NULL,
  `last_insert_id` int(11) NOT NULL,
  `insert_id` int(11) NOT NULL,
  `server_id` int(10) unsigned NOT NULL,
  `sql_text` mediumtext NOT NULL,
  `thread_id` bigint(21) unsigned NOT NULL
) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log' |
複製程式碼

引數log_output指定了慢查詢輸出的格式,預設為file,可以將它設定成table,將變成了上面的slow_log中

mysql> show variables like "log_output";
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_output    | FILE  |
+---------------+-------+
1 row in set (0.19 sec)
複製程式碼

但是多數情況下這樣做沒什麼必要,這不但對效能有較大影響,而且 MySQL 5.1 在將慢查詢記錄到檔案中時已經支援微秒級別的資訊,然而將慢查詢記錄到表中會導致時間粒度退化為只能到秒級,而秒級別的慢查詢日誌沒有太大的意義

慢查詢日誌分析工具

mysqldumpslow命令

當越來越多的SQL查詢被記錄到慢查詢日誌檔案中,這時候直接看日誌檔案就不容易了,MySQL提供了mysqldumpslow 命令解決:

[root@iz2zeaf3cg1099kiidi06mz mysql]# mysqldumpslow iz2zeaf3cg1099kiidi06mz-slow.log

Reading mysql slow query log from iz2zeaf3cg1099kiidi06mz-slow.log
Count: 1  Time=60.02s (60s)  Lock=0.00s (0s)  Rows=149272.0 (149272), root[root]@[117.136.86.151]
  select * from vote_record_memory

Count: 1  Time=14.85s (14s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@[117.136.86.151]
  CALL add_vote_memory(N)

Count: 1  Time=1.72s (1s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@[117.136.86.151]
  INSERT into vote_record SELECT * from  vote_record_memory

Count: 1  Time=0.02s (0s)  Lock=0.00s (0s)  Rows=142.0 (142), root[root]@[117.136.86.151]
  select * from vote_record_memory where vote_id = N

複製程式碼

更多關於 mysqldumpslow 命令的介紹,請參閱 :mysqldumpslow 的引數講解與基礎使用

pt-query-digest 工具

pt-query-digest 是分析MySQL查詢日誌最有力的工具,該工具功能強大,它可以分析binlog,Generallog,slowlog,也可以通過show processlist或者通過 tcpdump 抓取的MySQL協議資料來進行分析,比 mysqldumpslow 更具體,更完善。以下是使用pt-query-digest的示例:

//直接分析慢查詢檔案
pt-query-digest  slow.log > slow_report.log
複製程式碼

該工具可以將查詢的剖析報告列印出來,可以分析結果輸出到檔案中,分析過程是先對查詢語句的條件進行引數化,然後對引數化以後的查詢進行分組統計,統計出各查詢的執行時間,次數,佔比等,可以藉助分析結果找出問題進行優化。更多關於pt-query-digest的安裝與使用,請參閱 : www.ywnds.com/?p=8179

查詢日誌

檢視日誌記錄了所有對 MySQL 資料庫請求的資訊,不論這些請求是否得到了正確的執行。預設為 主機名.log

mysql> show variables like "general_log%";
+------------------+--------------------------------------------+
| Variable_name    | Value                                      |
+------------------+--------------------------------------------+
| general_log      | OFF                                        |
| general_log_file | /var/lib/mysql/iz2zeaf3cg1099kiidi06mz.log |
+------------------+--------------------------------------------+
2 rows in set (0.24 sec)   
複製程式碼

預設情況下不啟動查詢日誌,必須要先開啟。

mysql> set global general_log='ON';
Query OK, 0 rows affected (0.05 sec)

mysql> show variables like "general_log%";
+------------------+--------------------------------------------+
| Variable_name    | Value                                      |
+------------------+--------------------------------------------+
| general_log      | ON                                         |
| general_log_file | /var/lib/mysql/iz2zeaf3cg1099kiidi06mz.log |
+------------------+--------------------------------------------+
2 rows in set (0.11 sec)
複製程式碼

二進位制日誌

二進位制日誌記錄了對資料庫執行更改的所有操作,但是不包括selectshow這類操作,因為這類操作對資料本身並沒有修改,如果你還想記錄select和show操作,那隻能使用查詢日誌了,而不是二進位制日誌。

此外,二進位制還包括了執行資料庫更改操作的時間和執行時間等資訊。二進位制日誌主要有以下幾種作用:

  • 恢復(recovery): 某些資料的恢復需要二進位制日誌,如當一個資料庫全備檔案恢復後,我們可以通過二進位制的日誌進行 point-in-time的恢復
  • 複製(replication) : 通過複製和執行二進位制日誌使得一臺遠端的 MySQL 資料庫(一般是slave 或者 standby) 與一臺MySQL資料庫(一般為master或者primary) 進行實時同步
  • 審計(audit):使用者可以通過二進位制日誌中的資訊來進行審計,判斷是否有對資料庫進行注入攻擊

開啟二進位制日誌

通過配置引數 log-bin[=name] 可以啟動二進位制日誌。如果不指定name,則預設二進位制日誌檔名為主機名,字尾名為二進位制日誌的序列號

[mysqld]
log-bin
複製程式碼
mysql> show variables like 'datadir';
+---------------+-----------------+
| Variable_name | Value           |
+---------------+-----------------+
| datadir       | /var/lib/mysql/ |
+---------------+-----------------+
1 row in set (0.00 sec)
複製程式碼

mysqld-bin.000001即為二進位制日誌檔案,而mysqld-bin.index為二進位制的索引檔案,為了管理所有的binlog檔案,MySQL額外建立了一個index檔案,它按順序記錄了MySQL使用的所有binlog檔案。如果你想自定義index檔案的名稱,可以設定 log_bin_index=file引數。

-rw-rw---- 1 mysql mysql      120 Aug 21 16:42 mysqld-bin.000001
-rw-rw---- 1 mysql mysql       20 Aug 21 16:42 mysqld-bin.index
複製程式碼

檢視二進位制日誌檔案

對於二進位制日誌檔案來說,不像錯誤日誌檔案,慢查詢日誌檔案那樣用cat,head, tail等命令可以檢視,它需要通過 MySQL 提供的工具 mysqlbinlog。如:

[root@iz2zeaf3cg1099kiidi06mz mysql]# mysqlbinlog mysqld-bin.000001
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#180821 16:42:53 server id 1  end_log_pos 120 CRC32 0x3e55be40 	Start: binlog v 4, server v 5.6.39-log created 180821 16:42:53 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
jdB7Ww8BAAAAdAAAAHgAAAABAAQANS42LjM5LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAACN0HtbEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAUC+
VT4=
'/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
複製程式碼

二進位制日誌檔案配置引數

下面比較簡要介紹下二進位制日誌檔案幾個重要的配置引數

max_binlog_size

可以通過max_binlog_size引數來限定單個binlog檔案的大小(預設1G)

binlog_cache_size

當使用事務的表儲存引擎(如InnoDB儲存引擎)時,所有未提交(uncommitted)的二進位制日誌會被記錄到一個緩衝中去,等該事務提交(committed)時,直接將快取中的二進位制日誌寫入二進位制日誌檔案中,而該緩衝的大小由binlog_cache_size決定,預設大小為32K。此外,binlog_cache_size 是基於會話(session)的,當每一個執行緒開啟一個事務時,MySQL會自動分配一個大小為 binlog_cache_size 的快取

mysql> show variables like 'binlog_cache_size';
+-------------------+-------+
| Variable_name     | Value |
+-------------------+-------+
| binlog_cache_size | 32768 |
+-------------------+-------+
1 row in set (0.00 sec)

複製程式碼

sync_binlog

在預設情況下,二進位制日誌並不是在每次寫的時候同步到磁碟。引數 sync_binlog = [N] 表示每寫緩衝多少次就同步到磁碟。如果將N設定為1,即 sync_binlog = 1表示採用同步寫磁碟的方式來寫二進位制日誌,這時寫操作就不用向上面所說的使用作業系統的緩衝來寫二進位制日誌

binlog_format

binlog_format 引數十分重要,它影響了記錄二進位制日誌的格式,分為三種格式:

  • statement : 記錄的是日誌的邏輯SQL語句
  • row: 記錄表的行更改情況
  • mixed: 在此格式下,mysql預設採用statement格式進行二進位制日誌檔案的記錄,但是有些情況下使用ROW格式,有以下幾種情況:
1)表的儲存引擎為NDB,這時對錶的DML操作都會以ROW格式記錄。
2)使用了UUID()、USER()、CURRENT_USER()、FOUND_ROW()、ROW_COUNT()等不確定函式。
3)使用了INSERT DELAY語句。
4)使用了使用者定義函式(UDF)。
5)使用了臨時表(temporary table)。
複製程式碼

參考資料 & 鳴謝

相關文章