MongoDB 臨時表橫空出現1萬+，這條語句執行前請準備好翻車的姿勢

解決問題之前，先在腦海中演繹一下當時場景

某日早上八點半，筆者接到客戶反饋，門戶首頁待辦訪問異常緩慢，經常出現“訪問異常，點擊重試”。當時直覺告訴我，應該是大量用戶高併發訪問 MongoDB 庫，導致 MongoDB 庫連接池出問題了，因為上線發版時，功能是正常的。

由於是上週五晚上發版驗證後，週六日使用門戶的用戶比較少，一直沒發現問題，直到下週一才集中爆發門戶訪問不可用。

請開始我的表演

一開始運維組認為是加了 MongoDB 審計日誌造成的，因為有大量針對 MongoDB 做寫審計日誌寫操作，確實會降低服務器性能。 通過查看服務日誌，也發現非常多的 MongoDB 訪問 timeout 異常信息。

<code>com.mongodb.MongoTimeoutException: Timed out after 30000 ms while waiting for a server that matches ReadPreferenceServerSelector{readPreference=primary}. Client view of cluster state is {type=UNKNOWN, servers=[{address=10.236.2.183:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused (Connection refused)}}, {address=10.236.2.184:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused (Connection refused)}}, {address=10.236.2.185:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused (Connection refused)}}]    at com.mongodb.connection.BaseCluster.createTimeoutException(BaseCluster.java:377) ~[mongodb-driver-core-3.4.2.jar!/:na]    at com.mongodb.connection.BaseCluster.selectServer(BaseCluster.java:104) ~[mongodb-driver-core-3.4.2.jar!/:na]    at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:75) ~[mongodb-driver-core-3.4.2.jar!/:na]    at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:71) ~[mongodb-driver-core-3.4.2.jar!/:na]    at com.mongodb.binding.ClusterBinding.getReadConnectionSource(ClusterBinding.java:63) ~[mongodb-driver-core-3.4.2.jar!/:na]    at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:402) ~[mongodb-driver-core-3.4.2.jar!/:na]    at com.mongodb.operation.MapReduceWithInlineResultsOperation.execute(MapReduceWithInlineResultsOperation.java:381) ~[mongodb-driver-core-3.4.2.jar!/:na]    at com.mongodb.operation.MapReduceWithInlineResultsOperation.execute(MapReduceWithInlineResultsOperation.java:70) ~[mongodb-driver-core-3.4.2.jar!/:na]    at com.mongodb.Mongo.execute(Mongo.java:836) ~[mongodb-driver-3.4.2.jar!/:na]    at com.mongodb.Mongo$2.execute(Mongo.java:823) ~[mongodb-driver-3.4.2.jar!/:na]    at com.mongodb.DBCollection.mapReduce(DBCollection.java:1278) ~[mongodb-driver-3.4.2.jar!/:na]    at org.springframework.data.mongodb.core.MongoTemplate.mapReduce(MongoTemplate.java:1406) ~[spring-data-mongodb-1.10.1.RELEASE.jar!/:na]    at org.springframework.data.mongodb.core.MongoTemplate.mapReduce(MongoTemplate.java:1383) ~[spring-data-mongodb-1.10.1.RELEASE.jar!/:na]    at com.unicom.portal.taskquery.common.TaskManager.selectPendingCountByType(TaskManager.java:1002) ~[classes!/:1.0.0]    at com.unicom.portal.taskquery.service.impl.TaskServiceImpl.getPendingInfo(TaskServiceImpl.java:233) ~[classes!/:1.0.0]    at com.unicom.portal.taskquery.controller.TaskPendController.getPendingInfo(TaskPendController.java:164) ~[classes!/:1.0.0]/<code>

同時運維人員通過監控告警發現 MongoDB 數據庫的連接數達到 10499（平時監控為幾百），而 MongoDB 數據庫憑空多出驚人的一萬多張臨時表記錄。

查看 K8s 容器平臺服務器資源情況，發現待辦服務 CPU 資源使用高達 7G 多，內存使用高達 12G。平常待辦服務的CPU 資源使用都是 0.00 幾，明顯感覺不正常。

這似乎更加驗證了是加了審計日誌造成的，於是運維組開始了非常耗時的 Mongos 停止並重啟操作，但很遺憾的是“ Mongos 重啟後不久又自動停止了”（ 後來跟運維組溝通，加的審計日誌跟 MongoDB 半毛錢關係都沒有）。 由於這個誤導，導致門戶大概四十分鐘不可用。筆者沒辦法，只能仔細分析 docker 容器日誌，發現大部分錯誤由同一個方法造成的。

<code>com.unicom.portal.taskquery.common.TaskManager.selectPendingCountByType(TaskManager.java:1002)/<code>

通過代碼走讀發現 TaskManager.selectPendingCountByType 這個方法用到了 MongoDB 的 mapReduce 方法。

<code>org.springframework.data.mongodb.core.MongoTemplate.mapReduce/<code>

通過查閱 MongoDB 官方文檔知悉， mapReduce 方法類似於 MySQL 中的 group by 語句，非常適合做表字段聚合（分組）分類統計功能。 瞭解 Hadoop 的同學知道，Hadoop 中的 Map 和 Reduce 會拆成多個子任務進行後臺跑批計算的。而 MongoDB 的 mapReduce 方法同樣如此，不同的是 mapReduce 方法會把子任務發送到不同的分片（sharding）服務器上去執行，而這個過程是非常耗時的。 平常幾十個人使用這個功能不會覺察到訪問有問題，但是門戶每天近 12W 的用戶同時在八點半之後訪問這個功能，後果就不堪設想了。 結果是“ 修改後的待辦待閱查詢服務在讀取/存儲過程中會創建大量臨時表，高併發時會造成待辦 MongoDB 數據庫頻繁執行建和刪表操作，致使服務器資源異常佔滿，MongoDB 數據庫進程異常關閉。”

筆者初步定位是這個 TaskManager.selectPendingCountByType 統計方法出問題後，果斷要求運維組把後臺服務恢復到上一個版本後，門戶訪問正常，待辦數據能夠正常顯示，問題解決！

查看待辦服務容器資源使用情況，CPU 使用率明顯下降近 7 倍。

心中預案，處理泰然

08:20 運維人員通過監控告警發現 MongoDB 數據庫的連接數達到 10499（平時監控為幾百），開始檢查處理。

08:31 運維人員檢查發現 Mongos 進程停止，嘗試重新啟動，發現重啟後不久又自動停止了。

08:37 運維人員分析可能因5月9日晚後臺開啟了門戶 MongoDB 審計日誌導致數據庫開銷較大，故開始回退 6 臺 mongoDB 上的審計日誌功能。

08:50 回退審計日誌操作完成，再次啟動 Mongos 進程發現不久又自動停止。

09:06 嘗試先停止待辦查詢應用服務，阻斷應用 Mongos的調用，再啟動 Mongos 進程。

09:20 西鹹機房維護人員配合檢查 MongoDB 的服務器資源使用情況後反饋無問題。同時數據庫運維人員複查關閉 MongoDB 審計日誌回退操作是確認已經回退成功。

09:31 項目組分析5月9日晚上發版的“待辦待閱數量查詢接口優化”功能可以與此故障有關，因此開始嘗試回退待辦查詢應用代碼。

09:36 待辦查詢應用代碼服務回退成功，同時測試發現門戶待辦業務恢復正常。

16:00 聯繫 17 個全國應用系統完成 9 位一級 VIP 和信息化 3 位領導的待辦待閱差異比對，共處理 3 條待辦差異。

知其然也要知其所以然

Mongodb 官網對 MapReduce 函數介紹：

Map/reduce in MongoDB is useful for batch processing of data and aggregation operations. It is similar in spirit to using something like Hadoop with all input coming from a collection and output going to a collection. Often, in a situation where you would have used GROUP BY in SQL, map/reduce is the right tool in MongoDB.

大致意思：

Mongodb中的Map/reduce主要是用來對數據進行批量處理和聚合操作，有點類似於使用Hadoop對集合數據進行處理，所有輸入數據都是從集合中獲取，而MapReduce後輸出的數據也都會寫入到集合中。通常類似於我們在SQL中使用 Group By語句一樣。

MongoDB 有兩種數據計算 聚合操作，一種是 Pipeline，另一種是 MapReduce。 Pipeline 的優勢在於查詢速度比 MapReduce 要快，但是 MapReduce 的強大之處在於它能夠在多臺分片（Sharding）節點上並行執行復雜的聚合查詢邏輯。

那 MapReduce 有哪些優缺點呢？

• MapReduce 優點在於能夠充分利用 CPU 多核資源（多線程），併發執行 Sharding 分片任務，做分組統計。另外對於一些聚合函數，如 SUM、AVG、MIN、MAX，需要通過 mapper 和 reducer 函數來定製化實現。
• MapReduce 缺點在於非常耗 CPU 資源並且非常吃內存，其邏輯是首先執行分片查詢任務計算線程，計算結果先放內存（吃內存），然後把計算結果存放到 MongoDB 臨時表，最後由 finalize 方法統計結果並刪除臨時表記錄。

MapReduce 執行流程

MapReduce 工作分為兩步，一是映射，即 map，將數據按照某一個規則映射到一個數組裡，比如按照 type 或者 name映射，同一個 type 或者 name 的數據形成一個數組，二是規約，即 reduce，它接收映射規則和數組，然後計算。舉例如下：

使用 MapReduce 要實現兩個函數：Map 和 Reduce。 Map 函數調用 emit(key,value) 遍歷集合中所有的記錄，將 key與 value 傳給 Reduce 函數進行處理。Map 函數和 Reduce 函數是使用 JavaSript 編寫的，其內部也是基於 JavaSript V8 引擎解析並執行，並可以通過 db.runCommand 或 mapreduce 命令來執行 MapReduce 操作。

併發性

我們都知道，Mongodb 中所有的讀寫操作都會加鎖（意向鎖），MapReduce 也不例外。MapReduce 涉及到 mapper、reducer，中間過程還會將數據寫入臨時的 collection 中，最終將 finalize 數據寫入 output collection。

read 階段將會使用讀鎖（讀取 chunks 中的數據），每處理 100 條 documents 後重新獲取鎖（yields）。寫入臨時 collectin 使用寫鎖，這個不會涉及到鎖的競爭，因為臨時 collection 只對自己可見。

在創建 output collection 時會對 DB 加寫鎖，如果 output collection 已經存在，且 action 為 replace 時，則會獲取一個 global 級別的寫鎖，此時將會阻塞 mongod 上的所有操作（影響很大），主要是為了讓數據結果為 atomic ；如果 action 為 merge 或者 reduce，且 nonAtomic為 true 是，只會在每次寫入數據時才會獲取寫鎖，這對性能幾乎沒有影響。

來個覆盤吧

總的來說，還是對 Mongodb 的 MapReduce 方法瞭解不夠深入；同時代碼評審時沒有重視代碼評審的質量，服務器監控方面也待加強。另外對於高併發的地方沒有做必要的接口壓力測試。 所以，接下來需要加強項目組危機意識，不管是管理流程，代碼質量，還是服務器資源監控以及必要的性能測試等。上線發版前，做好事前控制，事中做好服務監控，事後做好覆盤，避免下次犯同樣的錯誤。

參考

https://www.csdn.net/article/2013-01-07/2813477-confused-about-mapreduce https://blog.csdn.net/iteye_19607/article/details/82644559

閱讀更多 猿芯 的文章

關鍵字: 翻車 語句 橫空