程序員小樂(ID:study_tech)第 910 次推文 圖源：百度
往日回顧：JVM 史上最最最完整深入解析
正文
前言
日志文件記錄了影響MySQL數(shù)據(jù)庫的各種類型活動，MySQL數(shù)據(jù)庫中常見的日志文件有錯誤日志，二進(jìn)制日志，慢查詢?nèi)罩竞筒樵內(nèi)罩?。下面分別對他們進(jìn)行介紹。
錯誤日志
錯誤日志文件對MySQL的啟動，運行，關(guān)閉過程進(jì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)
例子，沒有用到索引進(jìn)行查詢：
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)
可以看到是進(jìn)行了全表掃描；然后去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ù)來進(jìn)行分析，比 mysqldumpslow 更具體，更完善。以下是使用pt-query-digest的示例:
//直接分析慢查詢文件
pt-query-digest slow.log > slow_report.log
該工具可以將查詢的剖析報告打印出來，可以分析結(jié)果輸出到文件中，分析過程是先對查詢語句的條件進(jìn)行參數(shù)化，然后對參數(shù)化以后的查詢進(jìn)行分組統(tǒng)計，統(tǒng)計出各查詢的執(zhí)行時間，次數(shù)，占比等，可以借助分析結(jié)果找出問題進(jìn)行優(yōu)化。
更多關(guān)于pt-query-digest的安裝與使用，請參閱 :
www.ywnds.com/?p=8179
查詢?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)
二進(jìn)制日志
二進(jìn)制日志記錄了對數(shù)據(jù)庫執(zhí)行更改的所有操作，但是不包括select和show這類操作，因為這類操作對數(shù)據(jù)本身并沒有修改，如果你還想記錄select和show操作，那只能使用查詢?nèi)罩玖耍皇嵌M(jìn)制日志。
此外，二進(jìn)制還包括了執(zhí)行數(shù)據(jù)庫更改操作的時間和執(zhí)行時間等信息。二進(jìn)制日志主要有以下幾種作用:
- 恢復(fù)(recovery)：某些數(shù)據(jù)的恢復(fù)需要二進(jìn)制日志，如當(dāng)一個數(shù)據(jù)庫全備文件恢復(fù)后，我們可以通過二進(jìn)制的日志進(jìn)行 point-in-time的恢復(fù)
- 復(fù)制(replication) : 通過復(fù)制和執(zhí)行二進(jìn)制日志使得一臺遠(yuǎn)程的 MySQL 數(shù)據(jù)庫(一般是slave 或者 standby) 與一臺MySQL數(shù)據(jù)庫(一般為master或者primary) 進(jìn)行實時同步
- 審計(audit)：用戶可以通過二進(jìn)制日志中的信息來進(jìn)行審計，判斷是否有對數(shù)據(jù)庫進(jìn)行注入攻擊
開啟二進(jìn)制日志
通過配置參數(shù) log-bin[=name] 可以啟動二進(jìn)制日志。如果不指定name,則默認(rèn)二進(jìn)制日志文件名為主機名，后綴名為二進(jì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即為二進(jìn)制日志文件，而mysqld-bin.index為二進(jìn)制的索引文件，為了管理所有的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
查看二進(jìn)制日志文件
對于二進(jìn)制日志文件來說，不像錯誤日志文件，慢查詢?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*/;
二進(jìn)制日志文件配置參數(shù)
下面比較簡要介紹下二進(jìn)制日志文件幾個重要的配置參數(shù)
max_binlog_size
可以通過max_binlog_size參數(shù)來限定單個binlog文件的大小(默認(rèn)1G)
binlog_cache_size
當(dāng)使用事務(wù)的表存儲引擎(如InnoDB存儲引擎)時，所有未提交(uncommitted)的二進(jìn)制日志會被記錄到一個緩沖中去，等該事務(wù)提交(committed)時，直接將緩存中的二進(jìn)制日志寫入二進(jìn)制日志文件中，而該緩沖的大小由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)情況下，二進(jìn)制日志并不是在每次寫的時候同步到磁盤。參數(shù) sync_binlog = [N] 表示每寫緩沖多少次就同步到磁盤。如果將N設(shè)置為1，即 sync_binlog = 1表示采用同步寫磁盤的方式來寫二進(jìn)制日志，這時寫操作就不用向上面所說的使用操作系統(tǒng)的緩沖來寫二進(jìn)制日志
binlog_format
binlog_format 參數(shù)十分重要，它影響了記錄二進(jìn)制日志的格式,分為三種格式:
1、statement : 記錄的是日志的邏輯SQL語句
2、row: 記錄表的行更改情況
3、mixed: 在此格式下，mysql默認(rèn)采用statement格式進(jìn)行二進(jìn)制日志文件的記錄，但是有些情況下使用ROW格式，有以下幾種情況:
- 表的存儲引擎為NDB，這時對表的DML操作都會以ROW格式記錄。
- 使用了UUID()、USER()、CURRENT_USER()、FOUND_ROW()、ROW_COUNT()等不確定函數(shù)。
- 使用了INSERT DELAY語句。
- 使用了用戶定義函數(shù)（UDF）。
- 使用了臨時表（temporary table）。
參考
https://book.douban.com/subject/24708143/
http://search.dangdang.com/?key=高性能MySQL
