[[356516]]

前情提要

11月末我司商品服務(wù)的MongoDB主庫(kù)曾出現(xiàn)過(guò)嚴(yán)重抖動(dòng)、頻繁鎖庫(kù)等情況。

由于諸多業(yè)務(wù)存在插入MongoDB、然后立即查詢(xún)等邏輯，因此項(xiàng)目并未開(kāi)啟讀寫(xiě)分離。

最終定位問(wèn)題是由于：服務(wù)器自身磁盤(pán) + 大量慢查詢(xún)導(dǎo)致

基于上述情況，運(yùn)維同學(xué)后續(xù)著重增強(qiáng)了對(duì)MongoDB慢查詢(xún)的監(jiān)控和告警

幸運(yùn)的一點(diǎn)：在出事故之前剛好完成了緩存過(guò)期時(shí)間的升級(jí)且過(guò)期時(shí)間為一個(gè)月，C端查詢(xún)都落在緩存上，因此沒(méi)有造成P0級(jí)事故，僅僅阻塞了部分B端邏輯

事故回放

我司的各種監(jiān)控做的比較到位，當(dāng)天突然收到了數(shù)據(jù)庫(kù)服務(wù)器負(fù)載較高的告警通知，于是我和同事們就趕緊登錄了Zabbix監(jiān)控，如下圖所示，截圖的時(shí)候是正常狀態(tài)，當(dāng)時(shí)事故期間忘記留圖了，可以想象當(dāng)時(shí)的數(shù)據(jù)曲線(xiàn)反正是該高的很低，該低的很高就是了。

Zabbix 分布式監(jiān)控系統(tǒng)官網(wǎng):https://www.zabbix.com/

開(kāi)始分析

我們研發(fā)是沒(méi)有操控服務(wù)器權(quán)限的，因此委托運(yùn)維同學(xué)幫助我們抓取了部分查詢(xún)記錄，如下所示：

---------------------------------------------------------------------------------------------------------------------------+ 
Op          | Duration | Query                                                                                                                   ---------------------------------------------------------------------------------------------------------------------------+ 
query       | 5 s      | {"filter": {"orgCode": 350119, "fixedStatus": {"$in": [1, 2]}}, "sort": {"_id": -1}, "find": "sku_main"}                
query       | 5 s      | {"filter": {"orgCode": 350119, "fixedStatus": {"$in": [1, 2]}}, "sort": {"_id": -1}, "find": "sku_main"}               query       | 4 s      | {"filter": {"orgCode": 346814, "fixedStatus": {"$in": [1, 2]}}, "sort": {"_id": -1}, "find": "sku_main"}               query       | 4 s      | {"filter": {"orgCode": 346814, "fixedStatus": {"$in": [1, 2]}}, "sort": {"_id": -1}, "find": "sku_main"}              query       | 4 s      | {"filter": {"orgCode": 346814, "fixedStatus": {"$in": [1, 2]}}, "sort": {"_id": -1}, "find": "sku_main"} 
... 

查詢(xún)很慢的話(huà)所有研發(fā)應(yīng)該第一時(shí)間想到的就是索引的使用問(wèn)題，所以立即檢查了一遍索引，如下所示：

### 當(dāng)時(shí)的索引 
 
db.sku_main.ensureIndex({"orgCode": 1, "_id": -1},{background:true}); 
db.sku_main.ensureIndex({"orgCode": 1, "upcCode": 1},{background:true}); 
.... 

我屏蔽了干擾項(xiàng)，反正能很明顯的看出來(lái)，這個(gè)查詢(xún)是完全可以命中索引的，所以就需要直面第一個(gè)問(wèn)題：

上述查詢(xún)記錄中排首位的慢查詢(xún)到底是不是出問(wèn)題的根源?

我的判斷是：它應(yīng)該不是數(shù)據(jù)庫(kù)整體緩慢的根源，因?yàn)榈谝凰牟樵?xún)條件足夠簡(jiǎn)單暴力，完全命中索引，在索引之上有一點(diǎn)其他的查詢(xún)條件而已，第二在查詢(xún)記錄中也存在相同結(jié)構(gòu)不同條件的查詢(xún)，耗時(shí)非常短。

在運(yùn)維同學(xué)繼續(xù)排查查詢(xún)?nèi)罩緯r(shí)，發(fā)現(xiàn)了另一個(gè)比較驚爆的查詢(xún)，如下：

### 當(dāng)時(shí)場(chǎng)景日志 
 
query: { $query: { shopCategories.0: { $exists: false }, orgCode: 337451, fixedStatus: { $in: [ 1, 2 ] }, _id: { $lt: 2038092587 } }, $orderby: { _id: -1 } } planSummary: IXSCAN { _id: 1 } ntoreturn:1000 ntoskip:0 keysExamined:37567133 docsExamined:37567133 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:293501 nreturned:659 reslen:2469894 locks:{ Global: { acquireCount: { r: 587004 } }, Database: { acquireCount: { r: 293502 } }, Collection: { acquireCount: { r: 293502 } } }  
 
# 耗時(shí) 
179530ms 

# 耗時(shí)耗時(shí)180秒且基于查詢(xún)的執(zhí)行計(jì)劃可以看出，它走的是_id_索引，進(jìn)行了全表掃描，掃描的數(shù)據(jù)總量為：37567133，不慢才怪。

迅速解決

定位到問(wèn)題后，沒(méi)辦法立即修改，第一要?jiǎng)?wù)是：止損

結(jié)合當(dāng)時(shí)的時(shí)間也比較晚了，因此我們發(fā)了公告，禁止了上述查詢(xún)的功能并短暫暫停了部分業(yè)務(wù)，，過(guò)了一會(huì)之后進(jìn)行了主從切換，再去看Zabbix監(jiān)控就一切安好了。

分析根源

我們回顧一下查詢(xún)的語(yǔ)句和我們預(yù)期的索引，如下所示：

### 原始Query 
db.getCollection("sku_main").find({  
        "orgCode" : NumberLong(337451),  
        "fixedStatus" : {  
            "$in" : [ 
                1.0,  
                2.0 
            ] 
        },  
        "shopCategories" : {  
            "$exists" : false 
        },  
        "_id" : {  
            "$lt" : NumberLong(2038092587) 
        } 
    } 
).sort( 
    {  
        "_id" : -1.0 
    } 
).skip(1000).limit(1000); 
 
### 期望的索引 
db.sku_main.ensureIndex({"orgCode": 1, "_id": -1},{background:true}); 

乍一看，好像一切都很Nice啊，字段orgCode等值查詢(xún)，字段_id按照創(chuàng)建索引的方向進(jìn)行倒序排序，為啥會(huì)這么慢?

但是，關(guān)鍵的一點(diǎn)就在 $lt 上

知識(shí)點(diǎn)一：索引、方向及排序

在MongoDB中，排序操作可以通過(guò)從索引中按照索引的順序獲取文檔的方式，來(lái)保證結(jié)果的有序性。

如果MongoDB的查詢(xún)計(jì)劃器沒(méi)法從索引中得到排序順序，那么它就需要在內(nèi)存中對(duì)結(jié)果排序。

注意：不用索引的排序操作，會(huì)在內(nèi)存超過(guò)32MB時(shí)終止，也就是說(shuō)MongoDB只能支持32MB以?xún)?nèi)的非索引排序

知識(shí)點(diǎn)二：?jiǎn)瘟兴饕辉诤醴较?/strong>

# 索引 
db.records.createIndex({a:1});  
 
# 查詢(xún) 
db.records.find().sort({a:-1}); 
 
# 索引為升序，但是我查詢(xún)要按降序，我只需要從右端開(kāi)始遍歷即可滿(mǎn)足需求，反之亦然 
MIN 0 1 2 3 4 5 6 7 MAX 

# 查詢(xún) 一 
db.getCollection("records").find({  
  "userid" : "ca2" 
}).sort({"score" : -1.0}); 
 
 
# 查詢(xún) 二 
db.getCollection("records").find({  
  "userid" : "ca2" 
}).sort({"score" : 1.0}); 

# 錯(cuò)誤示范 
db.getCollection("records").find({  
  "userid" : "ca2", 
  "score" : {  
    "$lt" : NumberLong(2038092587) 
  } 
}).sort({"score" : -1.0}); 

### 原始Query 
db.getCollection("sku_main").find({  
        "orgCode" : NumberLong(337451),  
        "fixedStatus" : {  
            "$in" : [ 
                1.0,  
                2.0 
            ] 
        },  
        "shopCategories" : {  
            "$exists" : false 
        },  
        "_id" : {  
            "$lt" : NumberLong(2038092587) 
        } 
    } 
).sort( 
    {  
        "_id" : -1.0 
    } 
).skip(1000).limit(1000); 
 
### 期望的索引 
db.sku_main.ensureIndex({"orgCode": 1, "_id": -1},{background:true}); 

# 原始查詢(xún) 
[TEMP INDEX] => lt: {"limit":1000,"queryObject":{"_id":{"$lt":2039180008},"categoryId":23372,"orgCode":351414,"fixedStatus":{"$in":[1,2]}},"restrictedTypes":[],"skip":0,"sortObject":{"_id":-1}} 
 
# 原始耗時(shí) 
[TEMP LT] => 超時(shí) （超時(shí)時(shí)間10s） 
 
# 優(yōu)化后查詢(xún) 
[TEMP INDEX] => gt: {"limit":1000,"queryObject":{"_id":{"$gt":2039180008},"categoryId":23372,"orgCode":351414,"fixedStatus":{"$in":[1,2]}},"restrictedTypes":[],"skip":0,"sortObject":{"_id":-1}} 
 
# 優(yōu)化后耗時(shí) 
[TEMP GT] => 耗時(shí): 383ms , List Size: 999