100ms的SQL把伺服器搞崩潰了

Code綜藝圈發表於2022-04-29

前言

一個專案上線了兩個月,除了一些反饋的優化和小Bug之外,專案一切順利;前期是屬於推廣階段,可能使用人員沒那麼多,當然對於專案部署肯定提前想到併發量了,所以早就把叢集安排上,而且還在測試環境搞了一下壓測,絕對是沒得問題的;但是,就在兩個月後的一天,系統突然跑的比烏龜還慢,投訴開始就陸續反饋過來了。

經過排查,原來是頻繁執行一條耗時100ms的SQL導致,100ms感覺不長,但就是把系統搞崩了,具體細節如下。

正文

1. 專案概況

專案採用ABP進行開發,整合統一的認證中心(IDS4),部分資料對接第三方系統,拆分後的這個專案架構相對簡單。

考慮併發量不高,就算是高峰期也不會超過1000,於是就搞了個單臺的資料庫伺服器(MySQL),測試環境中經過壓測,完全能抗住。

上線時,由於線上資源的關係,DB伺服器的配置沒有按測試環境的標準來分配,相關人員想著後續看情況進行補配。上線推的比較緊,簡單評估了配置風險,初步判斷沒啥大問題,於是就推上線了。

相關技術棧:ABP、IdentityServer4、Autofac、AutoMapper、Quartz.NET、EF Core、Redis、MySQL等,這都不重要,重要的是100ms的SQL把系統搞崩了。

由於系統相對不大,並沒有把分散式日誌、排程監控,效能監控整合上去。

2. 問題排查

上線期間,前期處於使用推廣階段,一切正常。兩個月後的一天,系統處於使用高峰時段,突然陸續收到反饋:系統有點卡!!!於是趕緊進行排查。

由於系統已經是叢集部署的,慢這個問題首先懷疑是資料庫伺服器,於是讓DBA的同事排查了一下,沒有鎖,只是有大量事務等待提交(waiting for handler commit),通過如下命令可查的:

# 檢視正在執行的指令碼
select *  from information_schema.PROCESSLIST t where t.COMMAND != 'Sleep'  order by time desc;

看到都是插入審計日誌記錄導致,一看日誌記錄頻率,差不多一秒500條記錄。DBA同事說可能是記錄插入頻繁導致,此時CPU已經爆到100%了,為了快速解決問題,於是就趕緊關掉了一些不必要的日誌記錄。

這麼一改,稍微降了一點,沒有事務提交的記錄,系統勉強可以撐著用,但是CPU還是在85%~97%波動;

看到這種情況,當然還是不放心,繼續排查。 中間有對伺服器的配置產生過懷疑,但非常肯定的是這不是主要原因,於是和DBA的同事繼續排查。

系統雖然可以正常使用,但時不時的也看看監控屏,CPU一直處於高水位狀態,還是有點慌的,因為一有問題,資訊和電話都要爆。

突然DBA同事發現有一個單表查詢的SQL執行比較頻繁,於是單獨拿出來試了一下,查詢時間150ms左右,這個表的資料量不大,8萬左右,但沒有加任何索引,因為想著資料量不大,查詢時長還可接受,所以當時就沒有加相關索引。

定位到這條SQL後,想到的第一步就是增加索引,在測試環境上試了一把,執行效率直接飛速提高到1ms;效果如下:

所以和DBA同事達成一致意見,在生成環境上增加複合索引(建立索引一定要注意欄位順序),在中午時候,系統使用頻率不太高,於是就在生成上快速加了索引,我去,CPU一下降到了20%以內,意不意外;就算在使用高峰期,也沒超過20%,通過zabbix工具監控看到CPU的效果:

問題算是解決了,總算鬆了一口氣。

這裡有個問題: CPU都爆了為什麼沒有報警提醒,這塊DBA同事正在排查相關配置。這裡發現CPU爆了,還是無意的遠端到伺服器,發現很卡,一看CPU才知道爆了。

系統雖小,問題不大,但其實暴露的問題還是挺多。

總結

這次線上小事故暫時分享到這,因為專案不大,所以沒有做那麼多監控,但以下建議,小夥伴可以參考一下:

  • 頻繁執行的SQL語句,一定要保證其執行效率,不要小看ms級的優化,如果併發量上來也會是災難;
  • 對應伺服器要做好監控,指定預警範圍提醒,避免打個措手不及
  • 儘量避免頻繁的自動重新整理;引入實時通訊的方式,會減少不必要的訪問壓力。
  • 關於系統頻繁記錄的審計日誌,儘量不要和業務資料庫存放在一起;大量的日誌頻繁運算元據庫是很佔用IO的。
  • 對於拆分的專案,再加上叢集部署,分散式日誌管理必須安排上,不然分析日誌排查問題是個費時費腦的事

關注“Code綜藝圈”,和我一起學習吧。

相關文章