后端開發(fā)必備的MySQL日志文件知識點
前言
日志文件記錄了影響MySQL數(shù)據(jù)庫的各種類型活動，MySQL數(shù)據(jù)庫中常見的日志文件有錯誤日志，二進制日志，慢查詢?nèi)罩竞筒樵內(nèi)罩?。下面分別對他們進行介紹。
錯誤日志
錯誤日志文件對MySQL的啟動，運行，關(guān)閉過程進行了記錄。
- mysql> show variables like 'log_error';
- +---------------+---------------------+
- | Variable_name | Value |
- +---------------+---------------------+
- | log_error | /var/log/mysqld.log |
- +---------------+---------------------+
- 1 row in set (0.03 sec)
可以看到錯誤日志的路徑和文件名，默認(rèn)情況下錯誤文件的文件名為服務(wù)器的主機名，即：hostname.err。只不過我這里設(shè)置的是/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
當(dāng)出現(xiàn)MySQL數(shù)據(jù)庫不能正常啟動時，第一個必須查找的文件就是錯誤日志文件，該文件記錄了出錯信息，能夠幫助我們找到問題。
慢查詢?nèi)罩?/strong>
慢查詢?nèi)罩居脕碛涗涰憫?yīng)時間超過閾值的SQL語句，所以我們可以設(shè)置一個閾值，將運行時間超過該值的所有SQL語句都記錄到慢查詢?nèi)罩疚募?。該閾值可以通過參數(shù) long_query_time 來設(shè)置，默認(rèn)為10秒。
啟動慢查詢?nèi)罩?/strong>
默認(rèn)情況下，MySQL數(shù)據(jù)庫并不啟動慢查詢?nèi)罩?，需要手動將這個參數(shù)設(shè)為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' 開啟慢查詢?nèi)罩?，只是對?dāng)前數(shù)據(jù)庫有效，如果MySQL數(shù)據(jù)庫重啟后就會失效。所以如果要永久生效，就要修改配置文件 my.cnf (其他系統(tǒng)變量也是如此)，如下：
- [mysqld]
- slow_query_log=1
然后重啟MySQL就可以讓慢查詢?nèi)罩居涗涢_啟了,至于日志文件的路徑就是上面slow_query_log_file對應(yīng)的路徑。
設(shè)置閾值
- mysql> show variables like 'long_query_time';
- +-----------------+-----------+
- | Variable_name | Value |
- +-----------------+-----------+
- | long_query_time | 10.000000 |
- +-----------------+-----------+
- 1 row in set (0.00 sec)
閾值默認(rèn)為10秒，我們可以修改閾值大小，比如(當(dāng)然這還是對當(dāng)前數(shù)據(jù)庫有效)：
- mysql> set global long_query_time=0.05;
- Query OK, 0 rows affected (0.00 sec)
設(shè)置long_query_time這個閾值之后，MySQL數(shù)據(jù)庫會記錄運行時間超過該值的所有SQL語句，但對于運行時間正好等于 long_query_time 的情況，并不會被記錄下。而設(shè)置 long_query_time為0來捕獲所有的查詢
參數(shù)log_queries_not_using_indexes
另一個和慢查詢?nèi)罩居嘘P(guān)的參數(shù)是 log_queries_not_using_indexes,
如果運行的SQL語句沒有使用索引，則MySQL數(shù)據(jù)庫同樣會將這條SQL語句記錄到慢查詢?nèi)罩疚募?。首先確認(rèn)打開了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已經(jīng)被標(biāo)記為慢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數(shù)據(jù)庫下，名為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' |
參數(shù)log_output指定了慢查詢輸出的格式，默認(rèn)為file,可以將它設(shè)置成table，將變成了上面的slow_log中
- mysql> show variables like "log_output";
- +---------------+-------+
- | Variable_name | Value |
- +---------------+-------+
- | log_output | FILE |
- +---------------+-------+
- 1 row in set (0.19 sec)
但是多數(shù)情況下這樣做沒什么必要，這不但對性能有較大影響，而且 MySQL 5.1 在將慢查詢記錄到文件中時已經(jīng)支持微秒級別的信息，然而將慢查詢記錄到表中會導(dǎo)致時間粒度退化為只能到秒級，而秒級別的慢查詢?nèi)罩緵]有太大的意義
慢查詢?nèi)罩痉治龉ぞ?/strong>
mysqldumpslow命令
當(dāng)越來越多的SQL查詢被記錄到慢查詢?nèi)罩疚募?，這時候直接看日志文件就不容易了，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
更多關(guān)于 mysqldumpslow 命令的介紹，請參閱 ：
https://github.com/luisedware/Archives/issues/7
pt-query-digest 工具
pt-query-digest 是分析MySQL查詢?nèi)罩咀钣辛Φ墓ぞ?，該工具功能強大，它可以分析binlog，Generallog，slowlog，也可以通過show processlist或者通過 tcpdump 抓取的MySQL協(xié)議數(shù)據(jù)來進行分析，比 mysqldumpslow 更具體，更完善。以下是使用pt-query-digest的示例:
- //直接分析慢查詢文件
- pt-query-digest slow.log > slow_report.log
該工具可以將查詢的剖析報告打印出來，可以分析結(jié)果輸出到文件中，分析過程是先對查詢語句的條件進行參數(shù)化，然后對參數(shù)化以后的查詢進行分組統(tǒng)計，統(tǒng)計出各查詢的執(zhí)行時間，次數(shù)，占比等，可以借助分析結(jié)果找出問題進行優(yōu)化。
更多關(guān)于pt-query-digest的安裝與使用，請參閱 :
查詢?nèi)罩?/strong>
查看日志記錄了所有對 MySQL 數(shù)據(jù)庫請求的信息，不論這些請求是否得到了正確的執(zhí)行。默認(rèn)為 主機名.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)
默認(rèn)情況下不啟動查詢?nèi)罩?，必須要先開啟。
- 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)
二進制日志
二進制日志記錄了對數(shù)據(jù)庫執(zhí)行更改的所有操作，但是不包括select和show這類操作，因為這類操作對數(shù)據(jù)本身并沒有修改，如果你還想記錄select和show操作，那只能使用查詢?nèi)罩玖耍皇嵌M制日志。
此外，二進制還包括了執(zhí)行數(shù)據(jù)庫更改操作的時間和執(zhí)行時間等信息。二進制日志主要有以下幾種作用:
- 恢復(fù)(recovery)：某些數(shù)據(jù)的恢復(fù)需要二進制日志，如當(dāng)一個數(shù)據(jù)庫全備文件恢復(fù)后，我們可以通過二進制的日志進行 point-in-time的恢復(fù)
- 復(fù)制(replication) : 通過復(fù)制和執(zhí)行二進制日志使得一臺遠(yuǎn)程的 MySQL 數(shù)據(jù)庫(一般是slave 或者 standby) 與一臺MySQL數(shù)據(jù)庫(一般為master或者primary) 進行實時同步
- 審計(audit)：用戶可以通過二進制日志中的信息來進行審計，判斷是否有對數(shù)據(jù)庫進行注入攻擊
開啟二進制日志
通過配置參數(shù) log-bin[=name] 可以啟動二進制日志。如果不指定name,則默認(rèn)二進制日志文件名為主機名，后綴名為二進制日志的序列號
- [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額外創(chuàng)建了一個index文件，它按順序記錄了MySQL使用的所有binlog文件。如果你想自定義index文件的名稱，可以設(shè)置 log_bin_index=file參數(shù)。
- -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
查看二進制日志文件
對于二進制日志文件來說，不像錯誤日志文件，慢查詢?nèi)罩疚募菢佑胏at，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*/;
二進制日志文件配置參數(shù)
下面比較簡要介紹下二進制日志文件幾個重要的配置參數(shù)
max_binlog_size
可以通過max_binlog_size參數(shù)來限定單個binlog文件的大小(默認(rèn)1G)
binlog_cache_size
當(dāng)使用事務(wù)的表存儲引擎(如InnoDB存儲引擎)時，所有未提交(uncommitted)的二進制日志會被記錄到一個緩沖中去，等該事務(wù)提交(committed)時，直接將緩存中的二進制日志寫入二進制日志文件中，而該緩沖的大小由binlog_cache_size決定，默認(rèn)大小為32K。
此外，binlog_cache_size 是基于會話(session)的，當(dāng)每一個線程開啟一個事務(wù)時，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
在默認(rèn)情況下，二進制日志并不是在每次寫的時候同步到磁盤。參數(shù) sync_binlog = [N] 表示每寫緩沖多少次就同步到磁盤。如果將N設(shè)置為1，即 sync_binlog = 1表示采用同步寫磁盤的方式來寫二進制日志，這時寫操作就不用向上面所說的使用操作系統(tǒng)的緩沖來寫二進制日志
binlog_format
binlog_format 參數(shù)十分重要，它影響了記錄二進制日志的格式,分為三種格式:
1、statement : 記錄的是日志的邏輯SQL語句
2、row: 記錄表的行更改情況
3、mixed: 在此格式下，mysql默認(rèn)采用statement格式進行二進制日志文件的記錄，但是有些情況下使用ROW格式，有以下幾種情況:
- 表的存儲引擎為NDB，這時對表的DML操作都會以ROW格式記錄。
- 使用了UUID()、USER()、CURRENT_USER()、FOUND_ROW()、ROW_COUNT()等不確定函數(shù)。
- 使用了INSERT DELAY語句。
- 使用了用戶定義函數(shù)（UDF）。
- 使用了臨時表（temporary table）。
