MongoDBクエリー最適化:10 sから10 ms
30946 ワード
【要旨】本文は私の前の同僚の付秋雷が最近モンゴDBの実行計画の選択に関する問題に出会ったので、とても面白くて、ソースコードを探求した後、彼は全体の問題を理解して整理して分かち合いました.付秋雷はTair(アリ内部で非常に広く使われているKVストレージシステム)の核心開発メンバーであり、現在キノコ街に就職している.
蘇さんのフィードバックラインのあるクエリーは遅い(10+seconds)、文は以下に相当します.
myCollというcollectionの記録内容は、次のようなものです.
関連するインデックスは次のとおりです.
スロークエリは、myCollで[14920247000、149258800000)という時間範囲に合致するすべてのレコードを検索し、以下の説明ではbad queryと呼ぶ.
以下の説明では、このクエリを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文の後に
good queryのexplain文の実行結果は、詳細に関係なく
結果は,queryPlanner,executionStats,serverInfo,okの4つの部分に分けられ,queryPlanner,executionStatsの2つの部分のみに注目した.
executionStatsはqueryPlannerを実行します.winningPlanという計画時の統計では、indexBoundsからgood queryがインデックススキャン(IXSCAN)段階で使用されているインデックスが
同じexplain文を使用してbad queryが使用するインデックスを見てみましょう.
bad queryで使用されているインデックスは複合インデックス(Compound Indexes)であり、good queryで使用されているインデックスとは確かに違います.同様にIXSCANのこの段階のkeysExamined統計から3124535件のデータがスキャンされていることがわかり、実行時間が長くなります.
問題B
2つのクエリーで選択されたインデックスが異なる場合、なぜこの違いがあるのでしょうか.この2つのクエリーは似ています.
Mongodbは、クエリーに適切なインデックスをどのように選択しますか?
大まかに言えば、いくつかの候補のクエリー・プランを選択し、これらのクエリー・プランをルールに従って採点します.点数が最も高いクエリー・プランは適切なクエリー・プランで、このクエリー・プランで使用されるインデックスは適切なインデックスです.
はい、ざっと言って、今細かく言います(やはりその言葉:コードのない解釈はごろつきで、以下のすべてのコードは
まずスタックを見てみましょう.
これはlldbを使用してmongodをデバッグする際に、
scoreTreeでは、各クエリー・プランのスコアを計算します.
scoreTreeはクエリーを実行していません.既存の
問題C
bad queryがgood queryと同じインデックスを選択した場合、同じ問題が発生するのではないでしょうか.
MongoDBクエリーでは、hintコマンドでインデックスを強制的に選択してクエリーを行うことができます.たとえば、上記のbad queryに
しかし、それでもクエリは遅く、
32862524件の記録をスキャンしたが、依然として遅い.この現象は説明しやすいです.executionStatsから.executionStagesでは、hintを加えたクエリーがLIMIT=>FETCH=>IXSCANのいくつかの段階を経て、IXSCANのこの段階は32862524の記録を返し、FETCHの段階でフィルタリングされて1つしか残っていないので、32862523の無効なスキャンがあるのに、なぜこんなに多くの無効なスキャンがあるのでしょうか.
これはビジネスロジックに関連しており、requestTimeタイムスタンプは時間とともに増加し、プライマリ・キー
しかしながらbad queryの制約
蘇さんは
有効なオフラインデバッグ環境の構築は、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クラウドサービスを利用させることに力を入れている.
背景
蘇さんのフィードバックラインのあるクエリーは遅い(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と呼びます.
質問が来ました:
この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が時間内にクエリーを完了することもできます.まとめ
リファレンス
林青大神が調査の過程で提供した重要な助けに感謝します.
著者:張友東、花名林青、アリクラウドデータベースグループ技術専門家、主に分布式ストレージ、NoSQLデータベースなどの技術分野に注目し、現在は主にMongoDBクラウドデータベースの研究開発に参加し、開発者に最高のMongoDBクラウドサービスを利用させることに力を入れている.