程序員小樂(ID:study_tech)第 910 次推文 圖源:百度
往日回顧:JVM 史上最最最完整深入解析
正文
前言
日志文件記錄了影響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 命令的介紹,請參閱 :
https://github.com/luisedware/Archives/issues/7
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)
二進制日志
二進制日志記錄了對數據庫執行更改的所有操作,但是不包括select和show這類操作,因為這類操作對數據本身并沒有修改,如果你還想記錄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 參數十分重要,它影響了記錄二進制日志的格式,分為三種格式:
1、statement : 記錄的是日志的邏輯SQL語句
2、row: 記錄表的行更改情況
3、mixed: 在此格式下,mysql默認采用statement格式進行二進制日志文件的記錄,但是有些情況下使用ROW格式,有以下幾種情況:
- 表的存儲引擎為NDB,這時對表的DML操作都會以ROW格式記錄。
- 使用了UUID()、USER()、CURRENT_USER()、FOUND_ROW()、ROW_COUNT()等不確定函數。
- 使用了INSERT DELAY語句。
- 使用了用戶定義函數(UDF)。
- 使用了臨時表(temporary table)。
參考
https://book.douban.com/subject/24708143/
http://search.dangdang.com/?key=高性能MySQL