實戰-Mongo優化

背景

Mongo叢集CPU報警，檢視現象是那一小段突然有一個請求小高峰，經過分析把問題定位到一個新增的接口上，這個接口中有一個Mongo的慢查詢，這個慢查詢對應的相關資訊有:

集合總文檔數超過 6 億條

按條件查詢後擷取的資料也有幾萬條
之前已經加了幾個索引，但效果不是特别理想

基本資訊

總資料量:

> db.zwg_log.count()
[693090136]     // 6.9億

檢視文檔結構:

> db.zwg_log.find().limit(3)
{
    _id: "add6a2c545fb389a96fed19730772e24",
    source_id: "xxxx",
    user_id: "zhaoweiguo",
    is_delete: "0",
    is_read: "0",
    time_created: ISODate("2018-03-11T04:47:14.621Z"),
    time_updated: ISODate("2018-03-11T04:47:14.621Z")
    ...
},
{
    _id: "add93f066c0e3e4c07f2962884799da4",
    source_id: "xxxx",
    user_id: "zhaoweiguo",
    is_read: "0",
    is_delete: "0",
    time_created: ISODate("2017-03-29T23:40:50.485Z"),
    time_updated: ISODate("2017-03-29T23:40:50.485Z")
    ...
},

相關索引主要有:

[
    {
      v: 2,
        key: {
            source_id: 1.0,
            is_delete: 1.0,
            time_created: -1.0
        },
        name: "source_id_1.0_is_delete_1.0_time_created_-1.0"
    }
    {
        v: 2,
        key: {
            is_delete: 1.0,
            user_id: 1.0,
            time_created: -1.0
        },
        name: "is_delete_1_user_id_1_time_created_-1"
    },
    {
        v: 2,
        key: {
            source_id: 1,
            user_id: 1,
            is_delete: 1,
            is_read: 1
        },
        name: "source_id_1_user_id_1_is_delete_1_is_read_1"
    }
]

現象分析

使用預設索引

使用explain指令驗證慢查詢的請求，發現

預設使用的是is_delete_1_user_id_1_time_created_-1索引

執行語句:

> db.zwg_log.explain("executionStats").find({
            "source_id": "XXXXXXXX85877cc4ada3217c7dff2627e11064d8",
            "user_id": "XXXXXXXX79441a98e6952befe5db9148",
            "is_delete": "0",
            "is_read": "0"
        }).sort({"time_created":-1}).limit(3)

執行結果:

executionStages: {
    stage: "SINGLE_SHARD",
    nReturned: 3,
    executionTimeMillis: 180,
    totalKeysExamined: 22387,
    totalDocsExamined: 22387,
    totalChildMillis: NumberLong(175),
    shards: [
        {
            shardName: "d-XXXXXXXXe0a5c484",
            executionSuccess: true,
            executionStages: {
                stage: "LIMIT",
                nReturned: 3,
                executionTimeMillisEstimate: 117,
                works: 22388,
                inputStage: {
                    stage: "FETCH",
                    nReturned: 3,
                    executionTimeMillisEstimate: 117,
                    works: 22387,
                    docsExamined: 22387,
                    inputStage: {
                        stage: "IXSCAN",
                        nReturned: 22387,
                        executionTimeMillisEstimate: 12,
                        works: 22387,
                        indexName: "is_delete_1_user_id_1_time_created_-1",
                        isMultiKey: true,
                        multiKeyPaths: {
                            is_delete: [
                            ],
                            user_id: [
                                "user_id"
                            ],
                            time_created: [
                            ]
                        },
                        keysExamined: 22387,
                    }
                }
            }
        }
    ]
}

使用指定索引 `source_id_1_user_id_1_is_delete_1_is_read_1`

指定使用使用source_id_1_user_id_1_is_delete_1_is_read_1索引

> db.zwg_log.explain("executionStats").find({
            "source_id": "XXXXXXXX85877cc4ada3217c7dff2627e11064d8",
            "user_id": "XXXXXXXX79441a98e6952befe5db9148",
            "is_delete": "0",
            "is_read": "0"
        }).sort({"time_created":-1}).limit(3).hint({
            "source_id": 1,
            "user_id": 1,
            "is_delete": 1,
            "is_read": 1
        })

傳回結果:

executionStages: {
    stage: "SINGLE_SHARD",
    nReturned: 3,
    executionTimeMillis: 1272,
    totalKeysExamined: 5856,
    totalDocsExamined: 5856,
    totalChildMillis: NumberLong(1263),
    shards: [
        {
            shardName: "d-XXXXXXXXe0a5c484",
            executionSuccess: false,
            executionStages: {
                stage: "SORT",
                nReturned: 0,
                executionTimeMillisEstimate: 1290,
                works: 5858,
                sortPattern: {
                    time_created: -1
                },
                memUsage: 5806,
                memLimit: 33554432,
                inputStage: {
                    stage: "SORT_KEY_GENERATOR",
                    nReturned: 5856,
                    executionTimeMillisEstimate: 1266,
                    works: 5857,
                    inputStage: {
                        stage: "FETCH",
                        nReturned: 5856,
                        executionTimeMillisEstimate: 1209,
                        works: 5856,
                        inputStage: {
                            stage: "IXSCAN",
                            nReturned: 5856,
                            executionTimeMillisEstimate: 26,
                            works: 5856,
                            indexName: "source_id_1_user_id_1_is_delete_1_is_read_1",
                            keysExamined: 5856,
                        }
                    }
                }
            }
        }
    ]
}

結論

使用索引 is_delete_1_user_id_1_time_created_-1 請求時間是180；而使用索引 source_id_1_user_id_1_is_delete_1_is_read_1 的請求時間是1272ms。是以Mongo使用這個索引作為最佳索引沒有問題。第2個索引時間主要消耗在排序上面了。

如果不按時間排序，則使用

source_id_1_user_id_1_is_delete_1_is_read_1

索引隻需要掃描3條記錄，時間會是幾毫秒。參見:

> db.zwg_log.explain("executionStats").find({
            "source_id": "XXXXXXXX85877cc4ada3217c7dff2627e11064d8",
            "user_id": "XXXXXXXX79441a98e6952befe5db9148",
            "is_delete": "0",
            "is_read": "0"
        }).limit(3).hint({
            "source_id": 1,
            "user_id": 1,
            "is_delete": 1,
            "is_read": 1
        })

結果:

executionStats: {
    nReturned: 3,
    executionTimeMillis: 2,
    totalKeysExamined: 3,
    totalDocsExamined: 3,
    executionStages: {
        stage: "SINGLE_SHARD",
        nReturned: 3,
        executionTimeMillis: 2,
        totalKeysExamined: 3,
        totalDocsExamined: 3,
        totalChildMillis: NumberLong(1),
        shards: [
            {
                shardName: "d-2ze07ec75d921fa4",
                executionSuccess: true,
                executionStages: {
                    stage: "LIMIT",
                    nReturned: 3,
                    executionTimeMillisEstimate: 0,
                    limitAmount: 3,
                    inputStage: {
                        stage: "FETCH",
                        nReturned: 3,
                        executionTimeMillisEstimate: 0,
                        docsExamined: 3,
                        inputStage: {
                            stage: "IXSCAN",
                            nReturned: 3,
                            executionTimeMillisEstimate: 0,
                            works: 3,
                            indexName: "source_id_1_user_id_1_is_read_1_is_delete_1"
                        }
                    }
                }
            }
        ]
    }
}

優化

原因找到了，優化就比較容易了。

根據上面分析，優化方法就顯而易見了：增加一個聯合索引

db.zwg_log.createIndex({
    "source_id": 1, 
    "user_id": 1,
    "is_delete": 1, 
    "is_read": 1,
    time_created:-1
},  {background: true})

優化後，執行:

> db.zwg_log.explain("executionStats").find({
            "source_id": "XXXXXXXX85877cc4ada3217c7dff2627e11064d8",
            "user_id": "XXXXXXXX79441a98e6952befe5db9148",
            "is_delete": "0",
            "is_read": "0"
        }).sort({"time_created":-1}).limit(3)

結果如下:

executionStats: {
    nReturned: 3,
    executionTimeMillis: 2,
    totalKeysExamined: 3,
    totalDocsExamined: 3,
    executionStages: {
        stage: "SINGLE_SHARD",
        nReturned: 3,
        executionTimeMillis: 2,
        totalKeysExamined: 3,
        totalDocsExamined: 3,
        totalChildMillis: NumberLong(2),
        shards: [
            {
                shardName: "d-XXXXXXXXe0a5c484",
                executionSuccess: true,
                executionStages: {
                    stage: "LIMIT",
                    nReturned: 3,
                    executionTimeMillisEstimate: 0,
                    inputStage: {
                        stage: "FETCH",
                        filter: {
                            is_read: {
                                $eq: "0"
                            }
                        },
                        nReturned: 3,
                        executionTimeMillisEstimate: 0,
                        inputStage: {
                            stage: "IXSCAN",
                            nReturned: 3,
                            executionTimeMillisEstimate: 0,
                            keyPattern: {
                                source_id: 1,
                                user_id: 1,
                                is_delete: 1,
                                time_created: -1
                            },
                            indexName: "source_id_1_user_id_1_is_delete_1_time_created_-1",
                            isMultiKey: true,
                        }
                    }
                }
            }
        ]
    }
},

就和不排序的請求使用索引

source_id_1_user_id_1_is_delete_1_is_read_1

效果一樣了。

小插曲-特殊資料可能會特别快

在優化完成後，高興之餘遇到下面這麼一個奇怪的問題:

在優化完成後強制指定使用索引 is_delete_1_user_id_1_time_created_-1 時，

發現它的執行效率居然和使用新增加的索引一樣，都是毫秒級

更詭異的是連文檔掃描數也一樣是3條

指定使用索引

is_delete_1_user_id_1_time_created_-1

> db.zwg_log.explain("allPlansExecution").find({
            "source_id": "XXXXXXXXdbf62d674a034e982586dcc85ecf4e78",
            "user_id": "XXXXXXXX79441a98e6952befe5db9148",
            "is_delete": "0",
            "is_read": "0"
        }).sort({"time_created":1}).limit(3).hint({
            is_delete: 1,
            user_id: 1,
            time_created: -1
        })

executionStages: {
    stage: "SINGLE_SHARD",
    nReturned: 3,
    executionTimeMillis: 0,
    totalKeysExamined: 3,
    totalDocsExamined: 3,
    totalChildMillis: NumberLong(0),
    shards: [
        {
            shardName: "d-XXXXXXXXe0a5c484",
            executionSuccess: true,
            executionStages: {
                stage: "LIMIT",
                nReturned: 3,
                inputStage: {
                    stage: "FETCH",
                    nReturned: 3,
                    executionTimeMillisEstimate: 0,
                    docsExamined: 3,
                    inputStage: {
                        stage: "IXSCAN",
                        nReturned: 3,
                        executionTimeMillisEstimate: 0,
                        indexName: "is_delete_1_user_id_1_time_created_-1",
                        keysExamined: 3,
                    }
                }
            }
        }
    ]
}

看到沒有和前面的最優解除了使用的索引不同外，其他幾乎完全一樣。是什麼原因造成的？是緩存嗎？是query plans嗎？當你對MongoDB不了解時，有很多的可能，你需要一點點排除。

query plans分析

首先不可能是query plans，因為我們使用的是指定索引。

緩存加速現象分析

是緩存造成的嗎？

緩存的确能加快查詢效率，但下面這種現象才真正是緩存造成的加速效果:

> db.zwg_log.explain("allPlansExecution").find({
            "source_id": "XXXXXXXX85877cc4ada3217c7dff2627e11064d8",
            "user_id": "XXXXXXXX79441a98e6952befe5db9148",
            "is_delete": "0",
            "is_read": "0"
        }).sort({"time_created":-1}).limit(3).hint({
            is_delete: 1,
            user_id: 1,
            time_created: -1
        })

第一次執行時效率如下:

executionStats: {
    nReturned: 3,
    executionTimeMillis: 1032,
    totalKeysExamined: 22387,
    totalDocsExamined: 22387,

第二次執行:

executionStats: {
    nReturned: 3,
    executionTimeMillis: 339,
    totalKeysExamined: 22387,
    totalDocsExamined: 22387,

第三次執行:

executionStats: {
    nReturned: 3,
    executionTimeMillis: 180,
    totalKeysExamined: 22387,
    totalDocsExamined: 22387,

我們看到，3次同樣的執行，雖然因為緩存原因，查詢速度越來越快，但文檔掃描是不變的。而上面的現象文檔掃描隻有3次，是以排除緩存造成這麼快。

真實原因

真實的原因其實是查詢這個資料就是隻需要掃描3條記錄就能得到想要的資料，因為你下面語句執行

db.zwg_log.find({
            "user_id": "XXXXXXXX79441a98e6952befe5db9148",
            "is_delete": "0"
        }).sort({time_created:-1}).limit(3)

得到的結果是:

[
    {
        _id: "b5cd1fd5382c403292714f7ceb13e7b9",
        source_id: "XXXXXXXXdbf62d674a034e982586dcc85ecf4e78",
        user_id: "XXXXXXXX79441a98e6952befe5db9148",
        is_delete: "0",
        is_read: "0",
        ...
    },{
        _id: "518cbb3e9fb6b5c0c53e0d99ef6e0bcf",
        source_id: "XXXXXXXXdbf62d674a034e982586dcc85ecf4e78",
        user_id: "XXXXXXXX79441a98e6952befe5db9148",
        is_delete: "0",
        is_read: "0",
        ...
    },{
        _id: "c3703d2139a1b2f381eb3690678d7985",
        source_id: "XXXXXXXXdbf62d674a034e982586dcc85ecf4e78",
        user_id: "XXXXXXXX79441a98e6952befe5db9148",
        is_delete: "0",
        is_read: "0",
        ...
    }
]

前3條就完全能滿足條件，是以這個查詢條件下使用索引 is_delete_1_user_id_1_time_created_-1 和使用索引 source_id_1_user_id_1_is_delete_1_is_read_1_time_created_-1 效率是一樣的。

使用其他資料證明

上面的原因是資料恰好合适，我使用其他

source_id

的值應該就不會這麼快了吧

速度超快的文檔掃描了3次:

用另一個source_id文檔掃描變成了2.2萬次:

這種隻有資料不同，其他都相同的，基本可以判斷為『就是資料比較特殊，并沒有代表性』

使用正序查詢證明

現在再看看如果排序按時間正序，效果如何:

> db.zwg_log.explain("allPlansExecution").find({
            "source_id": "XXXXXXXXdbf62d674a034e982586dcc85ecf4e78",
            "user_id": "XXXXXXXX79441a98e6952befe5db9148",
            "is_delete": "0",
            "is_read": "0"
        }).sort({"time_created":1}).limit(3).hint({
            is_delete: 1,
            user_id: 1,
            time_created: -1
        })

executionStages: {
    stage: "SINGLE_SHARD",
    nReturned: 3,
    executionTimeMillis: 1141,
    totalKeysExamined: 9433,
    totalDocsExamined: 9433,
    totalChildMillis: NumberLong(1138),
    shards: [
        {
            shardName: "d-XXXXXXXXe0a5c484",
            executionSuccess: true,
            executionStages: {
                stage: "LIMIT",
                nReturned: 3,
                executionTimeMillisEstimate: 1089,
                works: 9434,
                limitAmount: 3,
                inputStage: {
                    stage: "FETCH",
                    nReturned: 3,
                    executionTimeMillisEstimate: 1089,
                    works: 9433,
                    docsExamined: 9433,
                    inputStage: {
                        stage: "IXSCAN",
                        nReturned: 9433,
                        executionTimeMillisEstimate: 47,
                        works: 9433,
                        indexName: "is_delete_1_user_id_1_time_created_-1",
                        keysExamined: 9433,
                    }
                }
            }
        }
    ]
}

好了，我們看到，隻需把排序從倒序改為正序，時間就從毫秒級變成秒級。

為啥會有這種現象？為啥之前隻需要掃描3條記錄，現在需要掃描9433條了呢？

更深一步資料分析

> db.zwg_log.count({
            "user_id": "XXXXXXXX79441a98e6952befe5db9148",
            "is_delete": "0",
        })
[22410]   // 2.2萬條

> db.zwg_log.count({
            "source_id": "XXXXXXXXdbf62d674a034e982586dcc85ecf4e78",
            "user_id": "XXXXXXXX79441a98e6952befe5db9148",
            "is_delete": "0",
            "is_read": "0"
        })
[12918]    // 1.2萬條

> db.zwg_log.count({
            "source_id": "XXXXXXXX85877cc4ada3217c7dff2627e11064d8",
            "user_id": "XXXXXXXX79441a98e6952befe5db9148",
            "is_delete": "0",
            "is_read": "0"
        })
[5856]    // 5856條

這個表中有此使用者相關資料是2.2萬條，而滿足 source_id="XXXXXXXXdbf62d674a034e982586dcc85ecf4e78" 的資料大都是最新生成的，是以按時間倒序時能快速命中，而按時間正序時，由于前面的資料都不滿足 source_id="XXXXXXXXdbf62d674a034e982586dcc85ecf4e78" 這個條件，是以需要把前面的都掃描完成，才會命中所需要的資料。

如果在表

zwg_log

中按時間倒序前

條資料的

source_id

都等于

XXXXXXXXdbf62d674a034e982586dcc85ecf4e78

db.zwg_log.find({
            "user_id": "XXXXXXXX79441a98e6952befe5db9148",
            "is_delete": "0"
        }).sort({time_created:-1}).limit(12918)

那麼當按時間正序使用索引 is_delete_1_user_id_1_time_created_ 查詢時，需要的文檔掃描數為 22410-12918+3=9495 也就是這種情況需要掃描9495條。而上面的分析文檔掃描了9433次，這說明 source_id="XXXXXXXXdbf62d674a034e982586dcc85ecf4e78" 的資料并不完全是最新的，以上。

小插曲-排序與不排序的差別

現象

還有一個問題，如果我查詢不指定排序，正常不指定的話應該使用

source_id_1_user_id_1_is_delete_1_is_read_1

索引吧，但很奇怪的是有時使用

source_id_1.0_is_delete_1.0_time_created_-1

這個索引。

db.zwg_log.find({
            "source_id": "XXXXXXXXdbf62d674a034e982586dcc85ecf4e78",
            "user_id": "XXXXXXXX79441a98e6952befe5db9148",
            "is_delete": "0",
            "is_read": "0"
        }).limit(3).explain()

懷疑是與MongoDB的查詢計劃(Query Plans)有關

查詢計劃相關知識

Mongo 自帶了一個查詢優化器會為我們選擇最合适的查詢方案:

如果一個索引能夠精确比對一個查詢，那麼查詢優化器就會使用這個索引。

如果不能精确比對呢？可能會有幾個索引都适合你的查詢，那 MongoDB 是怎樣選擇的呢？

MongoDB 的查詢計劃會将多個索引并行的去執行，最先傳回第 101 個結果的就是勝者，

其他查詢計劃都會被終止，執行優勝的查詢計劃；

這個查詢計劃會被緩存，接下來相同的查詢條件都會使用它；

緩存的查詢計劃在以下條件下會清空并重新評估:

集合收到 1000 次寫操作

執行 reindex

添加或删除索引

mongod 程序重新開機

可能的原因

可能和上面一個小插曲一樣，因為資料原因。

因為

user_id

與

souce_id

是一對多的關系。是以按

souce_id

查詢與按

source_id + user_id

查詢得到的結果相同；并且

is_read

的值都為0。是以使用索引

source_id_1.0_is_delete_1.0_time_created_-1

source_id_1.0_is_delete_1.0_time_created_-1

都隻需要掃描3次。

但這兒和上面說的『如果一個索引能夠精确比對一個查詢，那麼查詢優化器就會使用這個索引。』相悖

現場如下：

1、is_read=1時，使用索引

source_id_1.0_is_delete_1.0_time_created_-1

2、is_read=0時，使用索引

source_id_1_user_id_1_is_delete_1_is_read_1

後續待研究确認……

擴充思考

這種表是否合适分片？分片後是否會提高查詢效率？

我們DB是分片DB，這個文檔目前還不是分片的

後續有時間會研究一下這個文檔是否應該分片？分片後是否能按所想提高效率？

參考文檔

你真的會用索引麼？[Mongo]: https://zhuanlan.zhihu.com/p/77971681
MongoDB 執行計劃擷取: https://blog.csdn.net/leshami/article/details/53521990
MongoDB 查詢優化：從 10s 到 10ms: https://developer.aliyun.com/article/74635

實戰-Mongo優化

背景

基本資訊

現象分析

使用預設索引

使用指定索引 `source_id_1_user_id_1_is_delete_1_is_read_1`

結論

優化

小插曲-特殊資料可能會特别快

query plans分析

緩存加速現象分析

真實原因

使用其他資料證明

使用正序查詢證明

更深一步資料分析

小插曲-排序與不排序的差別

現象

查詢計劃相關知識

可能的原因

擴充思考

參考文檔

繼續閱讀

anaconda安裝及使用小技巧anaconda使用小技巧

Anaconda環境配置

一、Python資料挖掘（環境篇——Anaconda與Jupyter Notebook）一、Python資料挖掘（環境篇——Anaconda與Jupyter Notebook）

Anaconda3安裝face_recognitionAnaconda3(python3.7.4)安裝face_recognition

資料挖掘中的隐私保護

資料挖掘研究内容和本質（轉）

資料挖掘分類技術

淺談資料挖掘評估技術

資料挖掘001

Error: couldn‘t connect to server 127.0.0.1:27017, connection attempt failed: SocketException: Error

Error: couldn't connect to server 127.0.0.1:27017, connection attempt failed: SocketException: Erro

couldn‘t connect to server 127.0.0.1:27017, connection attempt failed: SocketException: Error conne

從大資料看技術，為什麼天貓雙11是史上最大數字經濟節日

用Matlab搞計算機視覺是怎樣的體驗？

在weka中內建自己的算法

Ubuntu14.04 LTS下安裝mongodb

實戰-Mongo優化

背景

基本資訊

現象分析

使用預設索引

使用指定索引 source_id_1_user_id_1_is_delete_1_is_read_1

結論

優化

小插曲-特殊資料可能會特别快

query plans分析

緩存加速現象分析

真實原因

使用其他資料證明

使用正序查詢證明

更深一步資料分析

小插曲-排序與不排序的差別

現象

查詢計劃相關知識

可能的原因

擴充思考

參考文檔

繼續閱讀

使用指定索引 `source_id_1_user_id_1_is_delete_1_is_read_1`