轉載自 嚴陣以待 https://www.cnblogs.com/yanzhenyidai/p/13450965.html
上周客戶說系統突然變得很慢,而且時不時的蹦出一個 404
和 500
,弄得真的是很沒面子,而恰巧出問題的時候正在深圳出差,所以一直沒有時間
看問題,一直到今天,才算是把問題原因找到。
定位問題
剛開始得到是系統慢的反饋,沒有將問題點定位到數據庫上,查了半天服務是否正常(因為之前有一次Dubbo內存泄漏)。
在將應用服務日志查看了一遍后,沒有發現任何異常,只是打了幾個警告的日志。
於是又查看了業務運行時的日志,看到日志都提示了一個 Lock wait timeout exceeded; try restarting transaction
的異常。
這時還是沒有將重心放到數據庫上,認為是代碼的原因,導致事務一直沒有提交。
重新將代碼審閱了一遍,覺得應該不是代碼邏輯的問題,而這個時候, Lock wait timeout exceeded; try restarting transaction
這個異常的日志越來越多。
認為是數據庫層面出了問題,開始排查數據庫。
尋找原因
由於我們的數據庫不是用的 雲RDS版本,是在一台8核32G的AWS上的安裝版本。
使用 top 命令,查看到 Mysql 占用的 CPU 使用率高達 90% 左右。
心里一慌,感覺不妙,這樣子高負載的CPU使用率,搞不好服務器都要宕掉。
於是拿出了僅有的一點Mysql
基本知識,基本上這次只使用到了下面幾個語句:
查看當前Mysql所有的進程
show processlist
;
查看Mysql的最大緩存
show global variables like "global max_allowed_packet"
查看當前正在進行的事務
select * from information_schema.INNODB_TRX
查看當前Mysql的連接數
show status like 'thread%'
解決
按照上面的幾個語句,一步一步跟蹤定位下來。
show processlist; 下來,我們就可以查看出當前所有的進程,並且得到最耗時的進程。
在當前數據庫中,看到處於 Sleep
狀態的SQL非常多,而這也是占用CPU過高的重大原因,休眠線程太多,於是配置了一個 wait_time_out
為 600 秒的一個解決方案。
為什么配置600秒,因為我們應用超時時間配置的最大時間就是 600秒,10分鍾,這里的配置需要根據業務來具體配置。
select * from information_schema.INNODB_TRX
執行這個語句,看到Mysql中大部分處於 Lock 的SQL是一條 update
的SQL,而且還有一個單條件的SQL,查詢居然耗時4分鍾,很是驚訝。
於是查看了這張表。
剛一打開結構,差點沒忍住口吐芬芳,居然一個索引
都沒有,數據量超過300W
,沒有索引查詢基本上都要4分鍾往上走。
於是准備加上索引
,在一陣漫長的等待中,索引終於加上去了。
show status like 'thread%'
索引加上去了之后,查看了一下當前Mysql的連接數,似乎沒有之前那么高了,估計是擠壓的太多。
然后又查看了下服務器的CPU占用率,這次好了一點,從1%到80%來回跳動,沒有出現90&那么高的頻率。
總結
Mysql作為使用頻率非常高的數據庫,對於它的SQL調優真的是一門技術活,而且項目中的一些SQL看的也是想吐,這種調優起來真的難上加難。
其實 information_schema 這個數據庫,里面的Mysql日志看起來比業務日志順眼的很多。