QueryCache聯(lián)動(dòng)內(nèi)容:http://blog.itpub.net/29510932/viewspace-1694922/
-------------------------------------------------------------------------------------------------正文---------------------------------------------------------------------------------------------------------------
案例發(fā)生于生產(chǎn)環(huán)境，由于是臨時(shí)的技術(shù)支持，截圖沒(méi)有了.....

場(chǎng)景:
MySQL-5.5.47, 隔離級(jí)別RR
背景:
業(yè)務(wù)人員反應(yīng)數(shù)據(jù)庫(kù)操作時(shí)不時(shí)出現(xiàn)非常明顯的卡頓, 與此同時(shí)慢日志中出現(xiàn)大量的SQL;
問(wèn)題的現(xiàn)象&排查:
1.先看監(jiān)控圖表: 發(fā)現(xiàn)CPU使用率,IO吞吐量, IO Utils, 網(wǎng)卡in/out流量, 內(nèi)存的使用率都沒(méi)有異常現(xiàn)象----應(yīng)該不是服務(wù)器資源造成的;
2.登錄到生產(chǎn)庫(kù),看一下processlist的情況,并沒(méi)有明顯的長(zhǎng)連接或者長(zhǎng)事務(wù),咨詢了開(kāi)發(fā)人員,在應(yīng)用層也沒(méi)有手動(dòng)開(kāi)啟長(zhǎng)事務(wù)----應(yīng)該和特殊的SQL或者事務(wù)沒(méi)什么關(guān)系;
3.開(kāi)發(fā)人員反饋并沒(méi)有觸發(fā)器/存儲(chǔ)過(guò)程/定時(shí)任務(wù)----又排除幾個(gè)影響因素;
4.查看了一下當(dāng)天的慢日志,在某一個(gè)隨機(jī)的時(shí)間點(diǎn), 會(huì)出現(xiàn)很多的慢查詢, 而且慢查詢都是成片成片出現(xiàn)的, 成片出現(xiàn)的慢查詢都有相同的TIMESTAMP----隨機(jī)事件,可能是非人為的;
5.這種成片出現(xiàn)的慢查詢, 全部是以Insert, Update這種DML作為前N條;

問(wèn)題分析:
在排查過(guò)程中,初步得出的結(jié)論:
可能是SQL的問(wèn)題; 而且設(shè)置的隔離級(jí)別是RR, 結(jié)合排查的第五點(diǎn),感覺(jué)可能會(huì)是鎖等待導(dǎo)致的;
在生產(chǎn)環(huán)境查看了一下這些DML表的結(jié)構(gòu),發(fā)現(xiàn)相關(guān)的索引都有, 也在測(cè)試環(huán)境試了一下, 發(fā)現(xiàn)這些DML并沒(méi)有出現(xiàn)鎖等待的現(xiàn)象;

用mysqldumpslow給某個(gè)時(shí)間點(diǎn)的近300條慢查詢語(yǔ)句做了個(gè)統(tǒng)計(jì), 發(fā)現(xiàn)DML語(yǔ)句大約只有10%多一點(diǎn)的樣子,絕大多數(shù)還是select;
之后粗略看了一下這些select語(yǔ)句, explain的結(jié)果基本都是const, 說(shuō)明這些語(yǔ)句本身并沒(méi)有問(wèn)題;

在這個(gè)過(guò)程中,發(fā)現(xiàn)一個(gè)現(xiàn)象:
這些select語(yǔ)句,約70%都是DML的那幾張表, 而且不論什么類型select語(yǔ)句,記錄下來(lái)的時(shí)間都是基本一致的,2.78-2.80秒之間;
疑點(diǎn)1:雖然不是很確定這種現(xiàn)象是不是有什么意義, 不過(guò)看上去像是由于這幾張表進(jìn)行了DML, 結(jié)果堵住了很多對(duì)這幾張表的查詢;
疑點(diǎn)2:除非是IO出現(xiàn)了波動(dòng)或者峰值/沒(méi)有索引/鎖等待, 否則DML語(yǔ)句應(yīng)該很少會(huì)出現(xiàn)在慢查詢?nèi)罩纠锩?

猜測(cè)是cache或者是buffer的設(shè)置問(wèn)題, 于是去my.cnf檢查一下配置, 然后看到了query_cache_size的設(shè)置;query_cache_size=256M
參考聯(lián)動(dòng)內(nèi)容，其實(shí)Query Cache遠(yuǎn)沒(méi)有發(fā)揮想象中作用,不過(guò)>=5.6.8和5.7的版本中,query_cache_type默認(rèn)都是關(guān)閉的, 5.5并不太清楚, 難道是這個(gè)Query_cache的問(wèn)題?
翻了一下5.5的文檔,發(fā)現(xiàn)query_cache_type的默認(rèn)值是開(kāi)啟的, 但是size的默認(rèn)值是0, 意味著如果什么都不動(dòng),那就是屏蔽了Query Cache,
然而配置文件里面修改了size, 所以Query Cache就開(kāi)啟了;

Query Cache的缺陷,在另一篇博文里面有描述, 對(duì)應(yīng)到這次案例中的疑點(diǎn)1和疑點(diǎn)2， 做出幾個(gè)推斷:
在某個(gè)時(shí)間點(diǎn)內(nèi),應(yīng)用層發(fā)起較多的DML,這些DML會(huì)嘗試獲取cache中某幾張表的mutex,所以在慢查詢中,在每個(gè)時(shí)間點(diǎn),都是最先出現(xiàn)了Insert和Update（互相等待mutex）;
由于Query Cache中,由于相關(guān)表的數(shù)據(jù)被清理，select會(huì)重新生成對(duì)應(yīng)的result寫(xiě)入到Query Cache， 并且還存在并發(fā)的DML語(yǔ)句，導(dǎo)致頻繁的在清空和寫(xiě)入Query Cache;
由于Query Cache設(shè)置得比較大,如果保存了大量的數(shù)據(jù),那么在獲取mutex, 并清理數(shù)據(jù)的時(shí)候, 也會(huì)消耗更多的時(shí)間;

聯(lián)系運(yùn)維人員,查看了一下生產(chǎn)庫(kù)的Qcache的status，如下圖

可以看到在mysql啟動(dòng)之后，Qcache觸發(fā)了約1.2億次的insert，但是只有約870萬(wàn)次的緩存命中;
這一組統(tǒng)計(jì)數(shù)據(jù)也基本驗(yàn)證了Query Cache不好用這一事實(shí);

處理方式:
考慮到Qcache的統(tǒng)計(jì)結(jié)果,在線上庫(kù)關(guān)掉應(yīng)該也不會(huì)有什么問(wèn)題,所以和相關(guān)運(yùn)維人員說(shuō)明了情況,在最近的維護(hù)時(shí)間內(nèi)關(guān)掉這個(gè)Query Cache,然后觀察一段時(shí)間;
反饋結(jié)果:
卡頓現(xiàn)象暫時(shí)消失了,慢日志也不再出現(xiàn);
PS:Query Cache的問(wèn)題多多,除非幾乎沒(méi)有DML,否則還是盡量不要開(kāi)啟的比較好

總結(jié)

以上是生活随笔為你收集整理的MySQL案例分析--QueryCache的全部?jī)?nèi)容，希望文章能夠幫你解決所遇到的問(wèn)題。

如果覺(jué)得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。