一次elasticsearch 查詢瞬間超時案例分析

藍胖子的程式設計夢發表於2023-12-04

大家好,我是藍胖子,有段時間沒有做效能分析案例講解了,正好前兩天碰到一個效能問題,今天就來對它探討探討。

問題背景

在晚上9點左右,剛從外面逛街回到家,就接到了電話報警(幸好前不久剛好把電話報警機制加上,不然可能我就要去洗澡了👻),電話告警告知線上業務存在大量請求失敗的情況。於是趕緊開啟電腦,排查了起來。

錯誤日誌我們都是直接打到了釘釘上,發現大量的報警都是elasticsearch 訪問超時發生的。緊接著看了下線上業務網站是否正常,各項介面也是正常返回的,檢視錯誤日誌發現,錯誤僅僅是在那一瞬間出現。之後便正常了。下面是在kibana上的錯誤日誌圖表。

Pasted image 20231129173021.png

好在系統現在是正常的,我可以慢慢的排查為啥會出現大量超時的情況,下面是我的排查思路。

排查思路

服務監控實踐那個專題裡 我有提到 ,監控是分層的,分層的好處也容易定位問題出現的根本原因。一般把整個監控範圍劃分為機器監控,元件監控,應用監控,業務監控。由於目前線上主要是elasticsearch訪問超時了,所以我首先檢視了elasticsearch的元件的相關情況。

排查elasticsearch 元件

想到訪問超時,會不會是由於elasticsearch叢集在那段時間承載了過多的訪問流量,如下圖所示,是當時elasticsearch的訪問情況。

Pasted image 20231129180559.png
我們生產上是3臺機器組成的叢集,其餘兩臺機器流量情況也和這個類似,可以看到整個叢集的qps並不高,也就幾百的樣子。

既然不是流量問題,那會不會是es在執行一些耗時的操作,因為es中執行請求是線上程池中排隊請求的,如果其中某些請求比較耗時會造成請求排隊的情況。所以緊接著又看了es的執行緒池的情況。

機器1
Pasted image 20231129182133.png

機器2

Pasted image 20231129182212.png
還有一臺機器3的執行緒池執行緒池情況,不過它和機器1類似,我這裡就不貼上出來了,可以看到很明顯的是機器2中有較多的排隊請求,不過沒有出現拒絕請求的情況,那應用服務的es客戶端為啥會觸發超時呢?這是因為我們部門使用es客戶端的時候都會加上超時時間(出現超時的請求設定的3s超時),雖然es服務端沒有拒絕請求,但是在3s內客戶端把請求取消了。

不過看到這裡,能夠想到,機器2這臺機器很大可能是在執行什麼比較耗時的查詢,導致發往它的請求都在排隊了。

耗時的查詢原因又可以分為以下兩種情況,

1,es執行的查詢語句的確足夠慢,效能不佳。

2,是由於機器的原因導致es的查詢慢,比如同一臺機器上有其他磁碟吞吐比較大的服務在執行。

程式服務與機器監控

基於上述分析,我先看了出現問題的機器2上的程式服務讀寫磁碟的情況,發現對磁碟讀寫最頻繁的仍然是es服務,所以應該是es的dsl語句導致的。

這裡再插入一個當時觀察到的異常監控指標,機器2上的tcp連線個數在異常時出現激增,並且出現了tcp over flow的錯誤。如下是機器2當時的tcp連線狀態的監控。

Pasted image 20231204152236.png

Pasted image 20231204152312.png
如果單看這兩個指標,可能會認為是tcp的等待佇列設定小了,但經過排查,等待佇列的長度已經設定的足夠大。結合前面對elasticsearch的監控,可以很好的解釋這兩個指標為啥出現。

原因在於elasticsearch此時執行語句比較慢,導致大量的連線沒有被釋放,而後續仍然會有新的請求過來,最終導致tcp連線異常了。

好了,基於上述分析,最後定位到了elasticsearch的慢查詢導致的問題。

elasticsearch 慢查詢日誌排查

透過檢視慢查詢日誌,發現當時的確有這樣一個耗時16s的查詢。是個數量達到上千的terms查詢。該查詢剛好是最近上線的一個定時任務在執行的語句。

Pasted image 20231204153053.png

elasticsearch 對於單term的精準查詢是很迅速的,但是對terms的查詢效能會出現效能急劇下降的情況,multi terms查詢會將每個term的倒排列表讀取出來進行合併,這個合併過程是非常耗時的(可以透過profile dsl語句驗證這一點),特別是查詢的term值對應很多文件的時候,開銷會更大。並且這條查詢直接讀取了10000條資料。分析下來,這個查詢對cpu,磁碟,還是記憶體都具有很大壓力。

解決辦法

針對上述慢查詢,由於是後臺定時任務,對查詢時間沒有要求,最直接的最佳化方法 可以採用分批的方法,將上千terms的查詢分成小批次的terms查詢,比如100個terms,一批批的查詢。同時採用scroll滾動查詢的方式,每次只查詢1000條資料出來,減小對記憶體的壓力。

總結

其實,你可以看到,整個排查過程是比較順暢的,但是要完成這一系列比較順暢的排查動作前提是要有比較完善的監控機制。無論是對元件還是機器乃至應用服務的監控,我們都設有比較完善的監控圖表用於保留問題現場。對於慢查詢日誌則是直接發往了釘釘群,這也有利於快速對慢查詢進行發現和修改以及對慢查詢進行檢索。

有了這些監控機制,當問題發生時,只需要分層的去觀察不同層的監控情況,問題便能迎刃而解了。對於如何落地一個能用於生產環境的監控機制,歡迎收看我直接的服務監控實踐系列結合對公司監控系統的建設,我完整的介紹瞭如何構建一套比較完備的監控系統。