MySQL 通用查詢日誌和慢查詢日誌分析

MySQL中的日誌包括：錯誤日誌、二進制日誌、通用查詢日誌、慢查詢日誌等等。這裏主要介紹下比較經常使用的兩個功能：通用查詢日誌和慢查詢日誌。

1）通用查詢日誌：記錄創建的客戶端鏈接和執行的語句。
2）慢查詢日誌：記錄全部執行時間超過long_query_time秒的全部查詢或者不使用索引的查詢

（1）通用查詢日誌

在學習通用日誌查詢時，須要知道兩個數據庫中的經常使用命令：

1） show variables like '%version%';

mysql> show variables like '%version%';
+-------------------------+------------------------------+
| Variable_name | Value                        | +-------------------------+------------------------------+ | innodb_version          | 5.6.37 |
| protocol_version | 10                           | | slave_type_conversions  | |
| version | 5.6.37-log                   | | version_comment         | MySQL Community Server (GPL) |
| version_compile_machine | x86_64                       | | version_compile_os      | Linux |
+-------------------------+------------------------------+
7 rows in set (0.00 sec)

上述命令，顯示當前數據庫中與版本號相關的東西。

1） show variables like ‘%general%’;

mysql>  show variables like '%general%';
+------------------+-------------------------------+
| Variable_name | Value                         | +------------------+-------------------------------+ | general_log      | OFF |
| general_log_file | /var/lib/mysql/nginx-test.log | +------------------+-------------------------------+ 2 rows in set (0.00 sec) 能夠查看，當前的通用日誌查詢是否開啓，若是general_log的值爲ON則爲開啓，爲OFF則爲關閉（默認狀況下是關閉的）。 1） show variables like ‘%log_output%’; mysql> show variables like '%log_output%'; +---------------+-------+ | Variable_name | Value |
+---------------+-------+
| log_output | FILE  | +---------------+-------+ 1 row in set (0.00 sec) 

查看當前慢查詢日誌輸出的格式，能夠是FILE（存儲在數數據庫的數據文件中的hostname.log），也能夠是TABLE（存儲在數據庫中的mysql.general_log）
問題：如何開啓MySQL通用查詢日誌，以及如何設置要輸出的通用日誌輸出格式呢？

開啓通用日誌查詢： set global general_log=on;

關閉通用日誌查詢： set global general_log=off;

設置通用日誌輸出爲表方式： set global log_output=’TABLE’;

設置通用日誌輸出爲文件方式： set global log_output=’FILE’;

設置通用日誌輸出爲表和文件方式：set global log_output=’FILE,TABLE’;

（注意：上述命令只對當前生效，當MySQL重啓失效，若是要永久生效，須要配置my.cnf）
日誌輸出的效果圖以下：
記錄到mysql.general_log表結構以下：

mysql> desc general_log;
+--------------+---------------------+------+-----+-------------------+-----------------------------+
| Field | Type                | Null | Key | Default | Extra                       | +--------------+---------------------+------+-----+-------------------+-----------------------------+ | event_time   | timestamp | NO   | | CURRENT_TIMESTAMP | on update CURRENT_TIMESTAMP |
| user_host | mediumtext          | NO |     | NULL |                             | | thread_id    | bigint(21) unsigned | NO   | | NULL              | |
| server_id | int(10) unsigned    | NO |     | NULL |                             | | command_type | varchar(64) | NO   | | NULL              | |
| argument | mediumtext          | NO |     | NULL |                             | +--------------+---------------------+------+-----+-------------------+-----------------------------+ 6 rows in set (0.00 sec)

my.cnf文件的配置以下：

general_log=1  #爲1表示開啓通用日誌查詢，值爲0表示關閉通用日誌查詢

log_output=FILE,TABLE#設置通用日誌的輸出格式爲文件和表

（2）慢查詢日誌

MySQL的慢查詢日誌是MySQL提供的一種日誌記錄，用來記錄在MySQL中響應時間超過閾值的語句，具體指運行時間超過long_query_time值的SQL，則會被記錄到慢查詢日誌中（日誌能夠寫入文件或者數據庫表，若是對性能要求高的話，建議寫文件）。默認狀況下，MySQL數據庫是不開啓慢查詢日誌的，long_query_time的默認值爲10（即10秒，一般設置爲1秒），即運行10秒以上的語句是慢查詢語句。
通常來講，慢查詢發生在大表（好比：一個表的數據量有幾百萬），且查詢條件的字段沒有創建索引，此時，要匹配查詢條件的字段會進行全表掃描，耗時查過long_query_time，
則爲慢查詢語句。
問題：如何查看當前慢查詢日誌的開啓狀況？
在MySQL中輸入命令：
show variables like '%quer%';

mysql> show variables like '%quer%';
+----------------------------------------+-------------------------------+
| Variable_name | Value                         | +----------------------------------------+-------------------------------+ | binlog_rows_query_log_events           | OFF |
| ft_query_expansion_limit | 20                            | | have_query_cache                       | YES |
| log_queries_not_using_indexes | ON                            | | log_throttle_queries_not_using_indexes | 0 |
| long_query_time | 10.000000                     | | query_alloc_block_size                 | 8192 |
| query_cache_limit | 1048576                       | | query_cache_min_res_unit               | 4096 |
| query_cache_size | 1048576                       | | query_cache_type                       | OFF |
| query_cache_wlock_invalidate | OFF                           | | query_prealloc_size                    | 8192 |
| slow_query_log | ON                            | | slow_query_log_file                    | /var/log/mysql/mysql_slow.log |
+----------------------------------------+-------------------------------+
15 rows in set (0.00 sec)

主要掌握如下的幾個參數：
（1）slow_query_log 的值爲ON爲開啓慢查詢日誌，OFF則爲關閉慢查詢日誌。
（2）slow_query_log_file 的值是記錄的慢查詢日誌到文件中（注意：默認名爲主機名.log，慢查詢日誌是否寫入指定文件中，須要指定慢查詢的輸出日誌格式爲文件，相關命令爲：show variables like ‘%log_output%’；去查看輸出的格式）。
（3）long_query_time 指定了慢查詢的閾值，即若是執行語句的時間超過該閾值則爲慢查詢語句，默認值爲10秒。
（4）log_queries_not_using_indexes 若是值設置爲ON，則會記錄全部沒有利用索引的查詢（注意：若是隻是將log_queries_not_using_indexes設置爲ON，而將slow_query_log設置爲OFF，此時該設置也不會生效，即該設置生效的前提是slow_query_log的值設置爲ON），通常在性能調優的時候會暫時開啓。
問題：設置MySQL慢查詢的輸出日誌格式爲文件仍是表，或者二者都有？
經過命令：show variables like ‘%log_output%’;

mysql> show variables like '%log_output%';
+---------------+------------+
| Variable_name | Value      | +---------------+------------+ | log_output    | FILE,TABLE |
+---------------+------------+
1 row in set (0.00 sec)

經過log_output的值能夠查看到輸出的格式，上面的值爲FILE,TABLE。固然，咱們也能夠設置輸出的格式爲文本，或者同時記錄文本和數據庫表中，設置的命令以下：

#慢查詢日誌輸出到表中（即mysql.slow_log）

set globallog_output=’TABLE’;

#慢查詢日誌僅輸出到文本中(即：slow_query_log_file指定的文件)

setglobal log_output=’FILE’;

#慢查詢日誌同時輸出到文本和表中

setglobal log_output=’FILE,TABLE’;

關於慢查詢日誌的表中的數據個文本中的數據格式分析：
慢查詢的日誌記錄myql.slow_log表中，格式以下：

mysql> mysql> select * from mysql.slow_log limit 1;
+---------------------+--------------------------------+------------+-----------+-----------+---------------+------------+----------------+-----------+-----------+----------------------------------------------------------------------------------------+-----------+
| start_time | user_host                      | query_time | lock_time | rows_sent | rows_examined | db | last_insert_id | insert_id | server_id | sql_text | thread_id | +---------------------+--------------------------------+------------+-----------+-----------+---------------+------------+----------------+-----------+-----------+----------------------------------------------------------------------------------------+-----------+ | 2018-02-07 11:16:55 | root[root] @ [121.196.203.51] | 00:00:00   | 00:00:00 |        13 | 40 | jp_core_db | 0 |         0 | 0 | select pd.lastAuction from Product pd where pd.status = 'O' and pd.auctionStatus = 'A' | 1621 |
+---------------------+--------------------------------+------------+-----------+-----------+---------------+------------+----------------+-----------+-----------+----------------------------------------------------------------------------------------+-----------+
1 row in set (0.00 sec)

慢查詢的日誌記錄到mysql_slow.log文件中，格式以下：

# Time: 180118 14:58:37
# User@Host: root[root] @ localhost [] Id: 150
# Query_time: 0.000270 Lock_time: 0.000109 Rows_sent: 0 Rows_examined: 6
SET timestamp=1516258717;
delete from user where User='app';

能夠看到，無論是表仍是文件，都具體記錄了：是那條語句致使慢查詢（sql_text），該慢查詢語句的查詢時間（query_time），鎖表時間（Lock_time），以及掃描過的行數（rows_examined）等信息。
問題：如何查詢當前慢查詢的語句的個數？
在MySQL中有一個變量專門記錄當前慢查詢語句的個數：
輸入命令：show global status like ‘%slow%’;

mysql> show global status like '%slow%';
+---------------------+-------+
| Variable_name | Value | +---------------------+-------+ | Slow_launch_threads | 132 |
| Slow_queries | 1772  | +---------------------+-------+ 2 rows in set (0.00 sec)

（注意：上述全部命令，若是都是經過MySQL的shell將參數設置進去，若是重啓MySQL，全部設置好的參數將失效，若是想要永久的生效，須要將配置參數寫入my.cnf文件中）。
補充知識點：如何利用MySQL自帶的慢查詢日誌分析工具mysqldumpslow分析日誌？

mysqldumpslow –s c –t 10 slow-query.log

具體參數設置以下：
-s 表示按何種方式排序，c、t、l、r分別是按照記錄次數、時間、查詢時間、返回的記錄數來排序，ac、at、al、ar，表示相應的倒敘；
-t 表示top的意思，後面跟着的數據表示返回前面多少條；
-g 後面能夠寫正則表達式匹配，大小寫不敏感。

[root@nginx-test /var/log/mysql]# mysqldumpslow -s c -t 2 /var/log/mysql/mysql_slow.log 

Reading mysql slow query log from /var/log/mysql/mysql_slow.log
Count: 125448  Time=0.00s (131s)  Lock=0.00s (3s)  Rows=2.2 (272835), 2users@2hosts
  select productauc0_.productAuctionId as productA1_12_, productauc0_.auctionIndex as auctionI2_12_, productauc0_.bidCoins as bidCoins3_12_, productauc0_.bidPrice as bidPrice4_12_, productauc0_.bidStep as bidStep5_12_, productauc0_.bidTime as bidTime6_12_, productauc0_.bidder as bidder7_12_, productauc0_.buyFlag as buyFlag8_12_, productauc0_.categoryCode as category9_12_, productauc0_.createTime as createT10_12_, productauc0_.currentAuctionDetailId as current11_12_, productauc0_.currentBidPrice as current12_12_, productauc0_.currentBidTime as current13_12_, productauc0_.currentBidder as current14_12_, productauc0_.effectCoin as effectC15_12_, productauc0_.effetcPoint as effetcP16_12_, productauc0_.endTime as endTime17_12_, productauc0_.newUserFlag as newUser18_12_, productauc0_.productCode as product19_12_, productauc0_.productCost as product20_12_, productauc0_.productName as product21_12_, productauc0_.productPrice as product22_12_, productauc0_.refundRate as refundR23_12_, productauc0_.startPrice as startPr24_12_, productauc0_.startTime as startTi25_12_, productauc0_.status as status26_12_, productauc0_.updateTime as updateT27_12_ from ProductAuction productauc0_ where productauc0_.status='S'

Count: 66216  Time=0.00s (127s)  Lock=0.00s (2s)  Rows=1.7 (115074), root[root]@[121.196.203.51]
  select productauc0_.productAuctionId as productA1_12_, productauc0_.auctionIndex as auctionI2_12_, productauc0_.bidCoins as bidCoins3_12_, productauc0_.bidPrice as bidPrice4_12_, productauc0_.bidStep as bidStep5_12_, productauc0_.bidTime as bidTime6_12_, productauc0_.bidder as bidder7_12_, productauc0_.buyFlag as buyFlag8_12_, productauc0_.categoryCode as category9_12_, productauc0_.createTime as createT10_12_, productauc0_.currentAuctionDetailId as current11_12_, productauc0_.currentBidPrice as current12_12_, productauc0_.currentBidTime as current13_12_, productauc0_.currentBidder as current14_12_, productauc0_.effectCoin as effectC15_12_, productauc0_.effetcPoint as effetcP16_12_, productauc0_.endTime as endTime17_12_, productauc0_.firstBidTime as firstBi18_12_, productauc0_.newUserFlag as newUser19_12_, productauc0_.noviceReturnFlag as noviceR20_12_, productauc0_.productCode as product21_12_, productauc0_.productCost as product22_12_, productauc0_.productName as product23_12_, productauc0_.productPrice as product24_12_, productauc0_.refundRate as refundR25_12_, productauc0_.startPrice as startPr26_12_, productauc0_.startTime as startTi27_12_, productauc0_.status as status28_12_, productauc0_.updateTime as updateT29_12_ from ProductAuction productauc0_ where productauc0_.status='S'

上述中的參數含義以下：

Count:125448 語句出現了125448次；

Time=0.00s（131s）  執行最長時間爲0.00s，累計總耗費時間131s；

Lock=0.0s（3s）           等待鎖最長時間爲0s，累計等待鎖耗費時間爲3s；

Rows=2.2（272835） 發送給客戶端最多的行數爲2.2，累計發送給客戶端的函數爲272835

http://blog.csdn.net/a600423444/article/details/6854289（注意：mysqldumpslow腳本是用perl語言寫的，具體mysqldumpslow的用法後期再講）問題：實際在學習過程當中，如何得知設置的慢查詢是有效的？很簡單，咱們能夠手動產生一條慢查詢語句，好比，若是咱們的慢查詢log_query_time的值設置爲1，則咱們能夠執行以下語句：select sleep(1);該條語句便是慢查詢語句，以後，即可以在相應的日誌輸出文件或表中去查看是否有該條語句。