MongoDBクエリー最適化:10 sから10 ms

30946 ワード

【要旨】本文は私の前の同僚の付秋雷が最近モンゴDBの実行計画の選択に関する問題に出会ったので、とても面白くて、ソースコードを探求した後、彼は全体の問題を理解して整理して分かち合いました.付秋雷はTair(アリ内部で非常に広く使われているKVストレージシステム)の核心開発メンバーであり、現在キノコ街に就職している.

背景


蘇さんのフィードバックラインのあるクエリーは遅い(10+seconds)、文は以下に相当します.db.myColl.find({app:"my_app",requestTime:{$gte:1492502247000,$lt:1492588800000}}).sort({_id:-1}).limit(1)
myCollというcollectionの記録内容は、次のようなものです.
{ "_id" : ObjectId("58fd895359cb8757d493ce60"), "app" : "my_app", "eventId" : 141761066, "requestTime" : NumberLong("1493010771753"), "scene" : "scene01" }
{ "_id" : ObjectId("58fd895359cb8757d493ce52"), "app" : "my_app", "eventId" : 141761052, "requestTime" : NumberLong("1493010771528"), "scene" : "scene02" }
{ "_id" : ObjectId("58fd895359cb8757d493ce36"), "app" : "my_app", "eventId" : 141761024, "requestTime" : NumberLong("1493010771348"), "scene" : "scene03" }
{ "_id" : ObjectId("58fd895359cb8757d493ce31"), "app" : "my_app", "eventId" : 141761019, "requestTime" : NumberLong("1493010771303"), "scene" : "scene01" }
{ "_id" : ObjectId("58fd895359cb8757d493ce2d"), "app" : "my_app", "eventId" : 141761015, "requestTime" : NumberLong("1493010771257"), "scene" : "scene01" }
{ "_id" : ObjectId("58fd895259cb8757d493ce10"), "app" : "my_app", "eventId" : 141760986, "requestTime" : NumberLong("1493010770866"), "scene" : "scene01" }
{ "_id" : ObjectId("58fd895259cb8757d493ce09"), "app" : "my_app", "eventId" : 141760979, "requestTime" : NumberLong("1493010770757"), "scene" : "scene01" }
{ "_id" : ObjectId("58fd895259cb8757d493ce02"), "app" : "my_app", "eventId" : 141760972, "requestTime" : NumberLong("1493010770614"), "scene" : "scene03" }
{ "_id" : ObjectId("58fd895259cb8757d493cdf1"), "app" : "my_app", "eventId" : 141760957, "requestTime" : NumberLong("1493010770342"), "scene" : "scene02" }
{ "_id" : ObjectId("58fd895259cb8757d493cde6"), "app" : "my_app", "eventId" : 141760946, "requestTime" : NumberLong("1493010770258"), "scene" : "scene01" }

関連するインデックスは次のとおりです.
[
    {
        "v" : 1,
        "key" : { "_id" : 1 },
        "name" : "_id_",
        "ns" : "myDatabase.myColl" },
    {
        "v" : 1,
        "key" : { "responseTime" : -1 },
        "name" : "idx_responseTime_-1",
        "ns" : "myDatabase.myColl" },
    {
        "v" : 1,
        "key" : { "app" : 1, "scene" : 1, "eventId" : -1, "requestTime" : -1 },
        "name" : "idx_app_1_scene_1_eventId_-1_requestTime_-1",
        "ns" : "myDatabase.myColl" }
]

スロークエリは、myCollで[14920247000、149258800000)という時間範囲に合致するすべてのレコードを検索し、以下の説明ではbad queryと呼ぶ.$lt:1492588800000という制約条件を外して[14920247000,+∞)という時間範囲を検索すると、すぐに(milliseconds)になります.db.myColl.find({app:"my_app",requestTime:{$gte:1492502247000}}).sort({_id:-1}).limit(1)
以下の説明では、このクエリをgood queryと呼びます.
質問が来ました:
  • [質問A]この2つのクエリは、どのようなインデックスを持っていますか?実行時間の差がこのように大きい
  • をもたらす.
  • [質問B]2つのクエリで選択されたインデックスが異なる場合、なぜこの違いがあるのでしょうか.この2つのクエリはよく似ています.
  • [問題C]bad queryがgood queryと同じインデックスを選択した場合、同じ問題が発生しますか
  • 問題A
    この2つのクエリは、どのようなインデックスを持っていますか?これにより、実行時間の差が大きくなります.
    Mysqlと同様に、Mongodbにはexplain文も用意されており、query文のクエリープラン(queryPlanner)、および実行中の統計(executionStats)を取得できます.
    違和感発散:Cassandraにも似たような機能があり、Hbaseでは現在見られません.
    mongo shellでの使用方法は、query文の後に.explain('executionStats')を付け、上記のgood queryに対して、対応するexplain文は次のとおりです.db.myColl.find({app:"my_app",requestTime:{$gte:1492502247000}}).sort({_id:-1}).limit(1).explain('executionStats')
    good queryのexplain文の実行結果は、詳細に関係なく...で省略されます.
    {
        "queryPlanner" : {
            "plannerVersion" : 1,
            "namespace" : "myDatabase.myColl",
            "indexFilterSet" : false,
            "parsedQuery" : ...
            "winningPlan" : {
                "stage" : "LIMIT",
                "limitAmount" : 1,
                "inputStage" : {
                    "stage" : "FETCH",
                    "filter" : ...,
                    "inputStage" : {
                        "stage" : "IXSCAN",
                        "keyPattern" : {
                            "_id" : 1
                        },
                        "indexName" : "_id_",
                        ...
                        "direction" : "backward",
                        "indexBounds" : {
                            "_id" : [
                                "[MaxKey, MinKey]"
                            ]
                        }
                    }
                }
            },
            "rejectedPlans" : ...,
        },
        "executionStats" : {
            "executionSuccess" : true,
            "nReturned" : 1,
            "executionTimeMillis" : 0,
            "totalKeysExamined" : 8,
            "totalDocsExamined" : 8,
            "executionStages" : {
                "stage" : "LIMIT",
                ...
                "inputStage" : {
                    "stage" : "FETCH",
                    ...
                    "inputStage" : {
                        "stage" : "IXSCAN",
                        ...
                        "direction" : "backward",
                        "indexBounds" : {
                            "_id" : [
                                "[MaxKey, MinKey]"
                            ]
                        },
                        "keysExamined" : 8,
                        ...
                    }
                }
            }
        },
        "serverInfo" : ...,
        "ok" : 1
    }

    結果は,queryPlanner,executionStats,serverInfo,okの4つの部分に分けられ,queryPlanner,executionStatsの2つの部分のみに注目した.
    executionStatsはqueryPlannerを実行します.winningPlanという計画時の統計では、indexBoundsからgood queryがインデックススキャン(IXSCAN)段階で使用されているインデックスが_idプライマリ・キー・インデックスであることがわかります.IXSCANのこの段階のkeysExamined統計から、なぜgood queryがこんなに速く実行され、8つのデータしかスキャンされていないのかを説明することができます.
    同じexplain文を使用してbad queryが使用するインデックスを見てみましょう.
    {
        "queryPlanner" : {
            ...
            "winningPlan" : {
                "stage" : "SORT",
                ...
                "inputStage" : {
                    "stage" : "SORT_KEY_GENERATOR",
                    "inputStage" : {
                        "stage" : "FETCH",
                        "inputStage" : {
                            "stage" : "IXSCAN",
                            "keyPattern" : {
                                "app" : 1,
                                "scene" : 1,
                                "eventId" : -1,
                                "requestTime" : -1
                            },
                            "indexName" : "idx_app_1_scene_1_eventId_-1_requestTime_-1",
                            ...
                            "direction" : "forward",
                            "indexBounds" : {
                                "app" : [
                                    "[\"my_app\", \"my_app\"]"
                                ],
                                "scene" : [
                                    "[MinKey, MaxKey]"
                                ],
                                "eventId" : [
                                    "[MaxKey, MinKey]"
                                ],
                                "requestTime" : [
                                    "(1492588800000.0, 1492502247000.0]"
                                ]
                            }
                        }
                    }
                }
            },
            "rejectedPlans" : ...,
        },
        "executionStats" : {
            "executionSuccess" : true,
            "nReturned" : 1,
            "executionTimeMillis" : 56414,
            "totalKeysExamined" : 3124535,
            "totalDocsExamined" : 275157,
            "executionStages" : {
                "stage" : "SORT",
                ...
                "inputStage" : {
                    "stage" : "SORT_KEY_GENERATOR",
                    ...
                    "inputStage" : {
                        "stage" : "FETCH",
                        ...
                        "inputStage" : {
                            "stage" : "IXSCAN",
                            ...
                            "direction" : "forward",
                            "indexBounds" : {
                                "app" : [
                                    "[\"my_app\", \"my_app\"]"
                                ],
                                "scene" : [
                                    "[MinKey, MaxKey]"
                                ],
                                "eventId" : [
                                    "[MaxKey, MinKey]"
                                ],
                                "requestTime" : [
                                    "(1492588800000.0, 1492502247000.0]"
                                ]
                            },
                            "keysExamined" : 3124535,
                            ...
                        }
                    }
                }
            }
        },
        "serverInfo" : ...,
        "ok" : 1
    }

    bad queryで使用されているインデックスは複合インデックス(Compound Indexes)であり、good queryで使用されているインデックスとは確かに違います.同様にIXSCANのこの段階のkeysExamined統計から3124535件のデータがスキャンされていることがわかり、実行時間が長くなります.
    問題B
    2つのクエリーで選択されたインデックスが異なる場合、なぜこの違いがあるのでしょうか.この2つのクエリーは似ています.
    Mongodbは、クエリーに適切なインデックスをどのように選択しますか?
    大まかに言えば、いくつかの候補のクエリー・プランを選択し、これらのクエリー・プランをルールに従って採点します.点数が最も高いクエリー・プランは適切なクエリー・プランで、このクエリー・プランで使用されるインデックスは適切なインデックスです.
    はい、ざっと言って、今細かく言います(やはりその言葉:コードのない解釈はごろつきで、以下のすべてのコードはmongodb-3.2.10に基づいています).
    まずスタックを見てみましょう.
    mongo::PlanRanker::scoreTree
    mongo::PlanRanker::pickBestPlan
    mongo::MultiPlanStage::pickBestPlan
    mongo::PlanExecutor::pickBestPlan
    mongo::PlanExecutor::make
    mongo::PlanExecutor::make
    mongo::getExecutor
    mongo::getExecutorFind
    mongo::FindCmd::explain

    これはlldbを使用してmongodをデバッグする際に、mongo::PlanRanker::scoreTree(コードがsrc/mongo/db/query/plan_ranker.cppにある)にブレークポイント印刷されたスタックを設定するものです.
    scoreTreeでは、各クエリー・プランのスコアを計算します.
        // We start all scores at 1. Our "no plan selected" score is 0 and we want all plans to
        // be greater than that.
        double baseScore = 1;
    
        // How many "units of work" did the plan perform. Each call to work(...)
        // counts as one unit.
        size_t workUnits = stats->common.works;
    
        // How much did a plan produce?
        // Range: [0, 1]
        double productivity =
            static_cast<double>(stats->common.advanced) / static_cast<double>(workUnits);
    
        ...
    
        double tieBreakers = noFetchBonus + noSortBonus + noIxisectBonus;
        double score = baseScore + productivity + tieBreakers;

    scoreTreeはクエリーを実行していません.既存のPlanStageStats* statsに基づいて計算されます.では、クエリー計画のPlanStageStats* statsを取得するためにクエリーを実行するのはいつですか?mongo::MultiPlanStage::pickBestPlan(コードはsrc/mongo/db/exec/multi_plan.cpp)では、workAllPlansがすべてのクエリー・プランを実行するために呼び出され、numWorksが最大2回呼び出されます.
        size_t numWorks = getTrialPeriodWorks(getOpCtx(), _collection);
        size_t numResults = getTrialPeriodNumToReturn(*_query);
    
        // Work the plans, stopping when a plan hits EOF or returns some
        // fixed number of results.
        for (size_t ix = 0; ix < numWorks; ++ix) {
            bool moreToDo = workAllPlans(numResults, yieldPolicy);
            if (!moreToDo) {
                break;
            }
        }

    問題C
    bad queryがgood queryと同じインデックスを選択した場合、同じ問題が発生するのではないでしょうか.
    MongoDBクエリーでは、hintコマンドでインデックスを強制的に選択してクエリーを行うことができます.たとえば、上記のbad queryに.hint({_id:1})を加えると、プライマリ・キー・インデックスを強制的に使用できます.db.myColl.find({app:"my_app",requestTime:{$gte:1492502247000,$lt:1492588800000}}).sort({_id:-1}).limit(1).hint({_id:1})
    しかし、それでもクエリは遅く、.explain('executionStats')を加えて実行状況を見てみると、問題Aを解く際にexplainの結果を説明しているので、今回はIXSCANフェーズのkeysExaminedに重点を置いてみましょう.
    {
    ...
            "executionStages" : {
                "stage" : "LIMIT",
                ...
                "inputStage" : {
                    "stage" : "FETCH",
                    "filter" : {
                        "$and" : [
                            {
                                "app" : {
                                    "$eq" : "my_app"
                                }
                            },
                            {
                                "requestTime" : {
                                    "$lt" : 1492588800000
                                }
                            },
                            {
                                "requestTime" : {
                                    "$gte" : 1492502247000
                                }
                            }
                        ]
                    },
                    "nReturned" : 1,
                    ...
                    "inputStage" : {
                        "stage" : "IXSCAN",
                        ...
                        "nReturned" : 32862524,
                        ...
                        "keysExamined" : 32862524,
                        ...
    ...
    }

    32862524件の記録をスキャンしたが、依然として遅い.この現象は説明しやすいです.executionStatsから.executionStagesでは、hintを加えたクエリーがLIMIT=>FETCH=>IXSCANのいくつかの段階を経て、IXSCANのこの段階は32862524の記録を返し、FETCHの段階でフィルタリングされて1つしか残っていないので、32862523の無効なスキャンがあるのに、なぜこんなに多くの無効なスキャンがあるのでしょうか.
    これはビジネスロジックに関連しており、requestTimeタイムスタンプは時間とともに増加し、プライマリ・キー_idも時間とともに増加していると考えられるので、プライマリ・キー・インデックスの逆順序に従って、最初にスキャンされたのは最新の記録であり、最新の記録は"requestTime" : {"$gte" : 1492502247000}という条件を満たしているので、good queryは"app" : {"$eq" : "my_app"}を満たすだけですぐに戻る.
    しかしながらbad queryの制約"requestTime" : {"$gte" : 1492502247000, "$lt" : 1492588800000}"$lt" : 1492588800000は満たされず、14925888800000というタイムスタンプよりも新しいレコードをすべてスキャンしてから返さなければならない.
    蘇さんは_idを用いてソートするのではなく、request_timeを用いてソートする完璧な解決策を提案した.これにより"requestTime" : -1というインデックスが使用され、"app" : {"$eq" : "my_app"}のフィルタリングを行うだけで、millisecondsが時間内にクエリーを完了することもできます.

    まとめ

  • 有効なオフラインデバッグ環境の構築は、zk問題を再現、解決するための重要な手段であり、例えば、以前にzk問題を再現する際にsaltを使用してローカルクラスタ
  • を迅速に構築する.
  • オープンソース製品を維持してソースコードを理解していないか、あるいは見る有効な入り口を見つけていないのは受動的で、位置決めが欠けて問題を解決する根本的な手段
  • である.
    リファレンス
  • https://docs.mongodb.com/manual/
  • http://www.cnblogs.com/xjk15082/archive/2011/09/18/2180792.html
  • https://lldb.llvm.org/lldb-gdb.html
  • https://github.com/mongodb/mongo/wiki/Build-Mongodb-From-Source

  • 林青大神が調査の過程で提供した重要な助けに感謝します.
    著者:張友東、花名林青、アリクラウドデータベースグループ技術専門家、主に分布式ストレージ、NoSQLデータベースなどの技術分野に注目し、現在は主にMongoDBクラウドデータベースの研究開発に参加し、開発者に最高のMongoDBクラウドサービスを利用させることに力を入れている.