一個慢查詢報警的簡單處理

今天在做節後的一個基本檢查的時候，發現一個不太起眼的報警，報警內容為大體為：
MySQL 每秒慢查詢次數超過 <1>個on  xxxx
檢視zabbix的監控資料，發現每秒竟然有10個左右的慢查詢，按照這個量，這個資料庫得存在多大的問題啊。

所以覺得可能是在做一個全表掃描導致的sql影響。
這個資料庫算是一個核心業務，而且負載一直不高，沒有收到任何關於IO,CPU,記憶體,swap的任何報警，一直在穩定執行，所以這是疑點之一。
這個庫因為很穩定，平時就是檢查基本的備份和基本的空間管理和日常的基本資料維護，而且也接手時間不長，所以很少去關注更多的內容，當我找到對應的資料目錄，發現一個問題，那就是這個慢日誌檔案竟然有近60G
-rw-r--r-- 1 root  root  102M Feb  4 17:14 query.log
-rw-rw---- 1 mysql mysql  58G Feb 17 14:58 slow.log
一個慢日誌如此龐大，這得暗示多大的效能問題啊，這是疑點之二。
當然如此龐大的日誌檔案，我看看是從什麼時候積累起來的
# head -10 slow.log
# Time: 131114 13:41:59
# User@Host: app_new_bill[app_new_bill] @ xxxx_2.107 [xxxx]
# Thread_id: 131044  Schema: mobile_billing  Last_errno: 0  Killed: 0
# Query_time: 0.000648  Lock_time: 0.000129  Rows_sent: 28  Rows_examined: 58  Rows_affected: 0  Rows_read: 28
# Bytes_sent: 4235  Tmp_tables: 0  Tmp_disk_tables: 0  Tmp_table_sizes: 0
# InnoDB_trx_id: 1718382
SET timestamp=1384407719;
select app0_.id as id1_, app0_.appname as appname1_, app0_.appkey as appkey1_, app0_.appsecret as appsecret1_, app0_.iplist as iplist1_, app0_.isshow as isshow1_, app0_.flag as flag1_, app0_.test_version as test8_1_, app0_.create_date as create9_1_, app0_.game_type as game10_1_, app0_.callback_url as callback11_1_, app0_.iappay_id as iappay12_1_, app0_.isactivate as isactivate1_ from test_app app0_ where app0_.isshow=1 order by app0_.create_date desc;
# Time: 131114 13:42:01
# User@Host: app_new_bill[app_new_bill] @ xxxx_2.107 [xxxx]
看來這個日誌積累自2013年了，所以幾年下來一直積累到了如此龐大。
當然我們需要馬上使用新的日誌檔案，這個檔案就權當備份日誌吧。使用mv修改日誌名，然後使用mysqladmin flush-logs 重新整理日誌，這樣新的日誌內容就寫到slow.log裡面了。
切換之後的情況如下：
-rw-rw---- 1 mysql mysql    16195105 Feb 17 15:54 slow.log
-rw-rw---- 1 mysql mysql 61757873052 Feb 17 15:02 slow.log.bak
目前的慢查詢的配置是2秒的基線。
我們來看看慢查詢日誌中的sql
# InnoDB_trx_id: 1B5249A5
SET timestamp=1455695652;
select * from tb_version_update where appkey='1400140930701' and media_channel_id='2014142002'  and take_effect_date < '2016-02-17 15:54:12' and is_take_effect=1 and isshow=1;
# User@Host: app_sdk_hero[app_sdk_hero] @ xxxx_128.100 [xxxx]
# Thread_id: 4537955  Schema: mobile_billing  Last_errno: 0  Killed: 0
# Query_time: 0.000570  Lock_time: 0.000072  Rows_sent: 0  Rows_examined: 158  Rows_affected: 0  Rows_read: 0
# Bytes_sent: 1753  Tmp_tables: 0  Tmp_disk_tables: 0  Tmp_table_sizes: 0
# InnoDB_trx_id: 1B5249A6
SET timestamp=1455695652;
select * from tb_version_update where appkey='1400140930701' and media_channel_id='2010321003'  and take_effect_date < '2016-02-17 15:54:12' and is_take_effect=1 and isshow=1;
可以從這個日誌看出，其實這個查詢的執行時間很短，肯定沒有達到慢查詢的觸發條件，不過根據執行計劃來看，確實沒有走索引。
而且關鍵的是相關的表只有150多條記錄，實在也沒必要新增索引了吧，所以效能問題的可能性也不大。
這個時候有一個新的引數，也是跟同事那兒取經所得。log_queries_not_using_indexes
# mysqladmin var|grep index
| expand_fast_index_creation                        | OFF    |
| fast_index_creation                               | ON     |
| innodb_adaptive_hash_index                        | ON     |
| innodb_adaptive_hash_index_partitions             | 8      |
| log_queries_not_using_indexes                     | ON     |
如果查詢沒有做索引，也會記錄到慢查詢之中，所以需要修改為off， set global log_queries_not_using_indexes =OFF即可。
然後就再也沒有這類的報警記錄了。

對於這個引數，預設值是off,所以一般也不會觸發這個問題。
官方對於這個引數的解釋如下：

--log-queries-not-using-indexes

If you are using this option with the slow query log enabled, queries that are expected to retrieve all rows are logged. See Section 5.2.5, “The Slow Query Log”. This option does not necessarily mean that no index is used. For example, a query that uses a full index scan uses an index but would be logged because the index would not limit the number of rows.
關於慢查詢的解釋連結 http://dev.mysql.com/doc/refman/5.5/en/slow-query-log.html

來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/23718752/viewspace-1990312/，如需轉載，請註明出處，否則將追究法律責任。