安基網 首頁 系統 數據庫 查看內容

一個詭異的MySQL慢日志問題

2020-1-13 09:15| 投稿: xiaotiger |來自: 互聯網


免責聲明:本站系公益性非盈利IT技術普及網,本文由投稿者轉載自互聯網的公開文章,文末均已注明出處,其內容和圖片版權歸原網站或作者所有,文中所述不代表本站觀點,若有無意侵權或轉載不當之處請從網站右下角聯系我們處理,謝謝合作!

摘要: 這是學習筆記的第 2186篇文章讀完需要分鐘速讀僅需1分鐘今天和同事處理了一個MySQL慢日志的問題,從這兩天開始頻繁收到一些報警信息,但是查看數據庫端卻沒有任何異常。經過了幾輪排查,最后結果刷新我對于問題的理解。從產生這些報警開始,報警就一直非常頻繁,頻繁到我想盡快解決這個問題。最開始定 ...

今天和同事處理了一個MySQL慢日志的問題,從這兩天開始頻繁收到一些報警信息,但是查看數據庫端卻沒有任何異常。

經過了幾輪排查,最后結果刷新我對于問題的理解。

從產生這些報警開始,報警就一直非常頻繁,頻繁到我想盡快解決這個問題。

最開始定位問題的方向是有一些業務的SQL沒有使用索引,但是執行時間很短,可能導致被判別為慢查詢,可以通過修改參數 log_queries_not_using_indexes 進行調整。

調整之后從慢日志來看,已經幾乎沒有慢日志了,但是從監控來看梳理依舊很大,是3萬多個。

以下是打開和關閉log_queries_not_using_indexes前后,這個環境中的慢日志數量統計,就算按照已有的評判標準,慢日志個數最多也不會超過100個,但是報警卻顯示是3萬多個。

查看全局變量slow_queries的結果可以看到,這個環境中的全局變量值為30118

>show global status like '%slow%';

+---------------------+-------+

| Variable_name | Value |

+---------------------+-------+

| Slow_launch_threads | 0 |

| Slow_queries | 30118 |

+---------------------+-------+

2 rows in set (0.00 sec)

但是查看會話狀態卻發現這個值始終是0

>show status like '%slow%';

+---------------------+-------+

| Variable_name | Value |

+---------------------+-------+

| Slow_launch_threads | 0 |

| Slow_queries | 0 |

+---------------------+--

這個問題的瓶頸其實不在于show global status和 show status的差異,還是簡單說下,show global status得到的是數據庫啟動以來的累計狀態值,要得到某一個時間點的數據,那么就需要對上一次的狀態進行對比,比如現在的全局狀態是3000,而一個小時前是2000,那么在這一個小時內的增量就是1000,所以哪怕會話層存在局限性,但是show global status反復檢查都是穩定不變,也足以說明這個問題的奇怪。

我甚至懷疑,是不是MySQL的一個bug導致了這種奇怪的抖動現象。

從這個業務來看,本身的訪問頻率其實是不高的,數據寫入也不多。

所以排除了這個層面的原因之后,我開始關注于監控層面,我抓取了本機的監控層面的一些數據,發現監控層面是按照時間來提取數據,

類似:

時間1,slow_queries值 30000

時間2,slow_queries值 30000

從日志來看顯然也是沒有問題的,增量明顯是0,就算有的話也應該是個位數的抖動,但是為什么監控系統會識別異常呢。

我們繼續進行分析,突然同事提醒了一句說,是不是上傳的數據IP存在異常,讓我們恍然大悟,比如本機上傳的監控數據是沒錯的,但是如果另外一個客戶端也上傳了監控數據,但是把客戶端IP的信息寫錯了,在監控服務端是會收到兩份上傳的數據,就可能觸發如下的邏輯:

時間1:服務器1,slow_queries值 30000

時間2:服務器2,slow_queries值 2

時間3:服務器1,slow_queries值 30000

時間4:服務器2,slow_queries值 1

這種情況下,在服務端來看就是慢日志的增量在30000->2->30000->1之間進行頻繁的變換。

所以這個問題就充分說明盡管你已經做得很好了,但是還是可能有其他環節會嚴重影響到你,記的第 2186 篇文章

讀完需要

2分鐘

速讀僅需1分鐘

今天和同事處理了一個MySQL慢日志的問題,從這兩天開始頻繁收到一些報警信息,但是查看數據庫端卻沒有任何異常。

經過了幾輪排查,最后結果刷新我對于問題的理解。

從產生這些報警開始,報警就一直非常頻繁,頻繁到我想盡快解決這個問題。

最開始定位問題的方向是有一些業務的SQL沒有使用索引,但是執行時間很短,可能導致被判別為慢查詢,可以通過修改參數 log_queries_not_using_indexes 進行調整。

調整之后從慢日志來看,已經幾乎沒有慢日志了,但是從監控來看梳理依舊很大,是3萬多個。

以下是打開和關閉log_queries_not_using_indexes前后,這個環境中的慢日志數量統計,就算按照已有的評判標準,慢日志個數最多也不會超過100個,但是報警卻顯示是3萬多個。

查看全局變量slow_queries的結果可以看到,這個環境中的全局變量值為30118

>show global status like '%slow%';

+---------------------+-------+

| Variable_name | Value |

+---------------------+-------+

| Slow_launch_threads | 0 |

| Slow_queries | 30118 |

+---------------------+-------+

2 rows in set (0.00 sec)

但是查看會話狀態卻發現這個值始終是0

>show status like '%slow%';

+---------------------+-------+

| Variable_name | Value |

+---------------------+-------+

| Slow_launch_threads | 0 |

| Slow_queries | 0 |

+---------------------+--

這個問題的瓶頸其實不在于show global status和 show status的差異,還是簡單說下,show global status得到的是數據庫啟動以來的累計狀態值,要得到某一個時間點的數據,那么就需要對上一次的狀態進行對比,比如現在的全局狀態是3000,而一個小時前是2000,那么在這一個小時內的增量就是1000,所以哪怕會話層存在局限性,但是show global status反復檢查都是穩定不變,也足以說明這個問題的奇怪。

我甚至懷疑,是不是MySQL的一個bug導致了這種奇怪的抖動現象。

從這個業務來看,本身的訪問頻率其實是不高的,數據寫入也不多。

所以排除了這個層面的原因之后,我開始關注于監控層面,我抓取了本機的監控層面的一些數據,發現監控層面是按照時間來提取數據,

類似:

時間1,slow_queries值 30000

時間2,slow_queries值 30000

從日志來看顯然也是沒有問題的,增量明顯是0,就算有的話也應該是個位數的抖動,但是為什么監控系統會識別異常呢。

我們繼續進行分析,突然同事提醒了一句說,是不是上傳的數據IP存在異常,讓我們恍然大悟,比如本機上傳的監控數據是沒錯的,但是如果另外一個客戶端也上傳了監控數據,但是把客戶端IP的信息寫錯了,在監控服務端是會收到兩份上傳的數據,就可能觸發如下的邏輯:

時間1:服務器1,slow_queries值 30000

時間2:服務器2,slow_queries值 2

時間3:服務器1,slow_queries值 30000

時間4:服務器2,slow_queries值 1

這種情況下,在服務端來看就是慢日志的增量在30000->2->30000->1之間進行頻繁的變換。

所以這個問題就充分說明盡管你已經做zhen得很好了,但是還是可能有其他環節會嚴重影響到你,真可謂:人在公司忙,鍋從天上來。

要修復這個問題,也相對比較簡單,我提取了近幾天的服務變更情況,就很快縮小了范圍,很快定位到了這臺服務器。



小編推薦:欲學習電腦技術、系統維護、網絡管理、編程開發和安全攻防等高端IT技術,請 點擊這里 注冊賬號,公開課頻道價值萬元IT培訓教程免費學,讓您少走彎路、事半功倍,好工作升職加薪!

本文出自:https://www.toutiao.com/a6780809955961209352/

免責聲明:本站系公益性非盈利IT技術普及網,本文由投稿者轉載自互聯網的公開文章,文末均已注明出處,其內容和圖片版權歸原網站或作者所有,文中所述不代表本站觀點,若有無意侵權或轉載不當之處請從網站右下角聯系我們處理,謝謝合作!


鮮花

握手

雷人

路過

雞蛋

相關閱讀

最新評論

 最新
返回頂部
创业如何赚钱