背景介紹

• 線上系統(tǒng)收到不到接口查詢失敗的告警，均為mongo查詢，返回的錯誤狀態(tài)碼為-5，報錯日志如下所示：

2022-02-09 18:16:56.631 ERROR 1 --- [ask-scheduler-6] o.s.integration.handler.LoggingHandler : org.springframework.dao.DataAccessResourceFailureException: 
Query failed with error code -5 and error message 'Cursor 73973161000 not found on server <mongodb-server>' on server <mongodb-server>; 
nested exception is com.mongodb.MongoCursorNotFoundException: 
Query failed with error code -5 and error message 'Cursor 73973161000 not found on server <mongodb-server>' on server <mongodb-server> 

• 從上面的報錯信息來看，是查詢在執(zhí)行過程中游標找不到導致的?？赡苁潜换厥栈蜿P(guān)閉，也可能確實沒有。

故障排查及灰度測試

故障排查過程

• 首先確定是否為完全阻塞式故障，這將決定是否將要緊急修復(fù)(封網(wǎng)期發(fā)布是有限制的)。經(jīng)過獲取客戶端的請求參數(shù)進行模擬重試后(僅查詢)，發(fā)現(xiàn)是重試是可以成功的。確定不是必現(xiàn)bug。
• 由于客戶端一般是分不同的類型來進行批量查詢，發(fā)現(xiàn)出錯的查詢均為某一類的type，它們共有的特點就是查詢的數(shù)據(jù)量比較大。確定可能跟大數(shù)據(jù)量查詢有關(guān)。
• 獲取線上報錯的請求參數(shù)，在測試環(huán)境mock完數(shù)據(jù)后進行批量并發(fā)測試，并未能重現(xiàn)問題。確定可能跟部署環(huán)境有關(guān)。

灰度過程

• 測試環(huán)境復(fù)現(xiàn)不了問題，因此轉(zhuǎn)到線上環(huán)境。本次灰度過程采用就k8s pods的金絲雀發(fā)布，配置的線上流量為20%。
• 由于代碼中有構(gòu)建mongo線程池，最小的連接數(shù)為5，最大空閑時間為30s。一種猜測是可能請求線程在獲取到連接并將要查詢時，連接超時被回收導致查詢失敗，因此將線程池的min collection設(shè)置為1，確保不會取到將要被回收的連接線程。經(jīng)過灰度后，仍然會報錯。
• 考慮出錯的均為大數(shù)據(jù)量查詢，猜測可能與游標超時有關(guān)。將出錯的type的query設(shè)置為noCursorTimeout，經(jīng)過灰度后，仍然會報錯。
• 考慮到可能查詢數(shù)量超過了mongo的默認batch_size(101行)，當數(shù)據(jù)量太大導致分批迭代時間太長導致超時。因此可以在程序側(cè)修改batch_size大小，增加每次讀取的數(shù)量。將query的batch_size設(shè)置為1000，經(jīng)過灰度后，不會報錯了。
• 考慮可能連接的mongo地址是load balancer，可能mongo在分批加載數(shù)據(jù)時請求到不同的后端服務(wù)器，也即說游標可能由A服務(wù)器生成，但是代完數(shù)據(jù)繼續(xù)請求數(shù)據(jù)時訪問到 B 服務(wù)器，由于該游標不是 B 生成的，因此也會報錯。在結(jié)合比較測試和生產(chǎn)環(huán)境，發(fā)現(xiàn)生產(chǎn)連的確實的lb地址，而測試并不是，這就是測試環(huán)境重現(xiàn)不出的原因。經(jīng)過將lb地址改為直連mongos地址，經(jīng)過灰度后，不會報錯了。同時刪除掉設(shè)置的batch_size也不會再報錯。

核心原因

關(guān)于游標的概念

• 在springboot項目中，不管是使用java-mongo-driver或者springframework.data.mongodb.core依賴包，當使用 find() 相關(guān)函數(shù)從 mongo 獲取數(shù)據(jù)時，它返回的并不是數(shù)據(jù)本身，而是一個游標，且每一個游標都對應(yīng)一個 id，mongo 服務(wù)器會管理這個游標。真正獲取數(shù)據(jù)是用這個游標去 mongo 獲取數(shù)據(jù)；且為了提高 io 利用率，用游標獲取數(shù)據(jù)是批量返回，每一批的大小是由 batch_size 參數(shù)決定的，默認是 101 行。真正獲取數(shù)據(jù)的觸發(fā)時間是在調(diào)用 find() 相關(guān)函數(shù)拿到游標之后，在第一次用 iterator 迭代游標時，客戶端會將根據(jù)游標拿到的這一批數(shù)據(jù)放到內(nèi)存中，然后再用 iterator.next() 一條一條的讀取。當內(nèi)存中的這一批數(shù)據(jù)迭代完之后，客戶端會用這個游標去 mongo 服務(wù)器去取下一批數(shù)據(jù)。
• 游標是 mongo 服務(wù)器生成的，是一種系統(tǒng)資源，類似于線程。所以游標用完了需要及時回收。游標有個超時時間，默認為 10min。在超時時間內(nèi)，如果客戶端使用完游標，則會向服務(wù)器發(fā)送 close 命令，服務(wù)器接口到這個命令之后就會回收游標；另一種情況是，在超時時間內(nèi)，客戶端未使用完游標，則服務(wù)器會主動回收游標。在可以設(shè)置讓服務(wù)器永遠不回收掉游標。

游標為什么會找不到？

• 游標找不到通常有以下兩種情況：
  • 客戶端游標超時，被服務(wù)端回收，再用游標向服務(wù)器請求數(shù)據(jù)時就會出現(xiàn)游標找不到的情況。
  • 在 mongo 集群環(huán)境下，可能會出現(xiàn)游標找不到的情況。游標由 mongo 服務(wù)器生成，在集群環(huán)境下，當使用 find() 相關(guān)函數(shù)時返回一個游標，假設(shè)此時該游標由 A 服務(wù)器生成，迭代完數(shù)據(jù)繼續(xù)請求數(shù)據(jù)時，訪問到了 B 服務(wù)器，但是該游標不是 B 生成的，此時就會出現(xiàn)游標找不到的情況。正常情況下，在 mongo 集群時，會將 mongo 地址以 ip1:port1,ip2:port2,ip3:port3 形式傳給 mongo 驅(qū)動，然后驅(qū)動能夠自動完成負載均衡和保持會話轉(zhuǎn)發(fā)到同一臺服務(wù)器，此時不會出現(xiàn)游標找不到的情況。但當我們自己搭建了負載均衡層，且用load balancer地址來連接時，就會出現(xiàn)游標找不到的情況。

游標相關(guān)的設(shè)置(僅考慮超時情況)

• 在服務(wù)端增大 mongo 服務(wù)器的游標超時時間。參數(shù)是 cursorTimeoutMillis，其默認是 10 min。修改后需重啟 mongo 服務(wù)器。
• 在客戶端一次性獲取到全部符合條件的數(shù)據(jù)。也即將batch_size設(shè)置為很大的數(shù)，但次數(shù)若真的有很多數(shù)據(jù)的話，則對系統(tǒng)內(nèi)存要求較高，同時如果數(shù)據(jù)量過大或處理過程過慢依舊會出現(xiàn)游標超時的情況。所以batch_size的評估是一個技術(shù)活。
• 客戶端設(shè)置游標永不超時:
  • 這種方式的缺點是如果程序意外停止或異常，該游標永遠不會被釋放，除非重啟 mongo，否則會一直占用系統(tǒng)資源，屬于危險操作。經(jīng)過咨詢DBA，一般很少對游標的數(shù)量進行監(jiān)控，一般是由其引起的連鎖反應(yīng)如CPU/內(nèi)存過高才能引起關(guān)注，一般的處理方式也就是重啟mongo服務(wù)器，這樣影響就比較大了。
  • 經(jīng)過查詢，在mongo 3.6版本后，客戶端就算把游標設(shè)置為永不超時。服務(wù)端仍然會在閑置30分鐘后將其kill掉，所以大量查詢?nèi)舫^30分鐘的話需要手動執(zhí)行下refreshsession來防止超時。但在3.6以下版本則會一直存在。mongo文檔。