LoginSignup
17
17

More than 5 years have passed since last update.

@koshilife(Kenji Koshikawa)

MongoDB v4 explain 結果をちゃんと理解してクエリ改善 (前半:explain結果の見方)

Last updated at Posted at 2019-04-30

@koshi_life です。

MongoDBのクエリ高速化に興味があり、Explain Results を理解したく調べたことの備忘です。

前提

  • MongoDB v4.0.3
  • シャードなし
  • 参考リンクは2019年4月末時点のものを参考にしています。

事前に確認したもの

mongoDB - Indexes

クエリ改善するに当たり、MongoDBのインデックス概要ページは必読。
とても読みやすい 日本語訳 もQiitaにありました。

テストデータ

Qiitaサービスインの2011年〜2019年4月のある断面までの全記事 396,416件 をv2 APIで取得しました。以下が保存した 1docの中身です。

{
    "_id": ObjectID("5cbb36d11fc6a6c823466a06"),
    "item_id": "634799bb57872ce0a169",
    "user_id": "koshilife",
    "title": "Node.js StreamAPI から逃げちゃダメだ。逃げちゃダメだ。。",
    "url": "https://qiita.com/koshilife/items/634799bb57872ce0a169",
    "likes_count": "131",
    "tags": [
        "Node.js",
        "StreamAPI"
    ],
    "created_at": ISODate("2015-06-22T00:46:48.000Z"),
    "month": "201506",
    "day": "20150622"
}

参考： Qiita記事取得は以下の過去エントリーで挙げたプログラムで取得しています。
Qiita API v2 で記事取得する (Ruby)

index状態

mongo> db.qiita_items.getIndexes()
[
    {
        "v" : 2,
        "key" : {
            "_id" : 1
        },
        "name" : "_id_",
        "ns" : "qiita_api_development.qiita_items"
    }
]

対象のクエリ

ありがちな1ユーザの最新投稿３件を取得するクエリを改善対象とします。

mongo> db.qiita_items.find({'user_id':'koshilife'},{'_id':0,'created_at':1,'title':1,'url':1}).sort({'created_at':-1}).limit(3)
{ "title" : "MongoDB Aggregation 100本ノック 前半 (group, sort, limit, project)", "url" : "https://qiita.com/koshilife/items/422070ee6aa636fb75fc", "created_at" : ISODate("2019-04-15T11:52:57Z") }
{ "title" : "Mongoid 特定Collectionにのみインデックスを作る", "url" : "https://qiita.com/koshilife/items/140b5a66d5fa6d1e7ee1", "created_at" : ISODate("2019-04-14T15:06:26Z") }
{ "title" : "Google Sheets API v4「1セル 50000文字までの制限あるよ」", "url" : "https://qiita.com/koshilife/items/5aff56c1bb9e5d31067f", "created_at" : ISODate("2019-04-08T01:31:04Z") }

explain 結果について

対象クエリの explain 結果を確認してみます。
対象クエリにexplain()をつけるだけで確認できます。
引数 executionStats はより詳細な内容を表示してくれるオプションです。

mongo> db.qiita_items.find({'user_id':'koshilife'},{'_id':0,'created_at':1,'title':1,'url':1}).sort({'created_at':-1}).limit(3).explain('executionStats')
{
    "queryPlanner" : {
        "plannerVersion" : 1,
        "namespace" : "qiita_api_development.qiita_items",
        "indexFilterSet" : false,
        "parsedQuery" : {
            "user_id" : {
                "$eq" : "koshilife"
            }
        },
        "winningPlan" : {
            "stage" : "PROJECTION",
            "transformBy" : {
                "_id" : 0,
                "created_at" : 1,
                "title" : 1,
                "url" : 1
            },
            "inputStage" : {
                "stage" : "SORT",
                "sortPattern" : {
                    "created_at" : -1
                },
                "limitAmount" : 3,
                "inputStage" : {
                    "stage" : "SORT_KEY_GENERATOR",
                    "inputStage" : {
                        "stage" : "COLLSCAN",
                        "filter" : {
                            "user_id" : {
                                "$eq" : "koshilife"
                            }
                        },
                        "direction" : "forward"
                    }
                }
            }
        },
        "rejectedPlans" : [ ]
    },
    "executionStats" : {
        "executionSuccess" : true,
        "nReturned" : 3,
        "executionTimeMillis" : 965,
        "totalKeysExamined" : 0,
        "totalDocsExamined" : 396416,
        "executionStages" : {
            "stage" : "PROJECTION",
            "nReturned" : 3,
            "executionTimeMillisEstimate" : 712,
            "works" : 396423,
            "advanced" : 3,
            "needTime" : 396419,
            "needYield" : 0,
            "saveState" : 3105,
            "restoreState" : 3105,
            "isEOF" : 1,
            "invalidates" : 0,
            "transformBy" : {
                "_id" : 0,
                "created_at" : 1,
                "title" : 1,
                "url" : 1
            },
            "inputStage" : {
                "stage" : "SORT",
                "nReturned" : 3,
                "executionTimeMillisEstimate" : 712,
                "works" : 396423,
                "advanced" : 3,
                "needTime" : 396419,
                "needYield" : 0,
                "saveState" : 3105,
                "restoreState" : 3105,
                "isEOF" : 1,
                "invalidates" : 0,
                "sortPattern" : {
                    "created_at" : -1
                },
                "memUsage" : 1041,
                "memLimit" : 33554432,
                "limitAmount" : 3,
                "inputStage" : {
                    "stage" : "SORT_KEY_GENERATOR",
                    "nReturned" : 45,
                    "executionTimeMillisEstimate" : 694,
                    "works" : 396419,
                    "advanced" : 45,
                    "needTime" : 396373,
                    "needYield" : 0,
                    "saveState" : 3105,
                    "restoreState" : 3105,
                    "isEOF" : 1,
                    "invalidates" : 0,
                    "inputStage" : {
                        "stage" : "COLLSCAN",
                        "filter" : {
                            "user_id" : {
                                "$eq" : "koshilife"
                            }
                        },
                        "nReturned" : 45,
                        "executionTimeMillisEstimate" : 694,
                        "works" : 396418,
                        "advanced" : 45,
                        "needTime" : 396372,
                        "needYield" : 0,
                        "saveState" : 3105,
                        "restoreState" : 3105,
                        "isEOF" : 1,
                        "invalidates" : 0,
                        "direction" : "forward",
                        "docsExamined" : 396416
                    }
                }
            }
        }
    },
    "serverInfo" : {
        "host" : "KenjinoMacBook-Air.local",
        "port" : 27017,
        "version" : "4.0.3",
        "gitVersion" : "7ea530946fa7880364d88c8d8b6026bbc9ffa48c"
    },
    "ok" : 1
}

最初はさっぱりでしたが、公式ページと以下エントリーが大変参考になりました。

explain結果の見方 (実行計画 queryPlanner)

queryPlanner のブロックでは実行計画の内容が確認できます。
queryPlanner の構造は以下です。

"queryPlanner" : {
   "plannerVersion" : <int>,
   "namespace" : <string>,
   "indexFilterSet" : <boolean>,
   "parsedQuery" : {
      ...
   },
   "winningPlan" : {
      "stage" : <STAGE1>,
      ...
      "inputStage" : {
         "stage" : <STAGE2>,
         ...
         "inputStage" : {
            ...
         }
      }
   },
   "rejectedPlans" : [
      <candidate plan 1>,
      ...
   ]
}

インデックスが効いているかどうかを確認するには、query optimizerに選ばれた実行される計画の
winningPlan内のwinningPlan.stage もしくは winningPlan.inputStage.stage に着目します。

Stages種別の一部。

Stage種別 公式 意訳
COLLSCAN for a collection scan コレクション内をフルスキャン
IXSCAN for scanning index keys インデックスを使ってスキャン
FETCH for retrieving documents 検索
SHARD_MERGE for merging results from shards シャードの結果をマージ
SHARDING_FILTER for filtering out orphan documents from shards シャードの孤立したdocを除外

もしCOLLSCAN の記載があればコレクションのフルスキャンが発生しているので、
スロークエリの発生状況や、後述の実行計画(詳細版)を見てインデックス化を検討する等の改善アクションが見込まれます。

実行計画の詳細 executionStats

explain('executionStats')の引数指定でwinningPlanの完全な実行計画の内容が確認できます。

以下、出力結果から抜粋です。

{
 "executionStats" : {
   "executionSuccess" : true,    // クエリ成功可否
   "nReturned" : 3,              // 返却したドキュメント数
   "executionTimeMillis" : 965,  // 実行時間 (ミリ秒)
   "totalKeysExamined" : 0,      // インデックス利用後 絞ったエントリー数
   "totalDocsExamined" : 396416, // 走査したドキュメント数
   "executionStages" : { ... }   // 各ステージごとの統計情報 (後述)
 }
}

39万ドキュメントをフルスキャンして、965msかかっていることがわかります。

executionStagesの内容には、stageの親子関係、クエリ内容、走査したドキュメント数、途中時点の返却数等の内容が確認できます。公式ドキュメントに載っている範囲で表示項目を意訳してコメントしています。

    "executionStages": {
        "stage": "PROJECTION",
        "nReturned": 3,
        "executionTimeMillisEstimate": 712,
        "works": 396423,                    // stage実行によるwork unitsの数
        "advanced": 3,                      // 親ステージに返却された中間時点のstage返却数
        "needTime": 396419,                 // 親ステージに進むことができなかった中間結果の work cycles の数
        "needYield": 0,                     // stageが中断しロックを開放をストレージ層が要求した数
        "saveState": 3105,                  // stageが保存した処理を中断し保存した回数。例えばロック開放するための準備など。
        "restoreState": 3105,               // stageが保存した実行状態を保存したクエリ状態を復元した回数。例えば以前に開放したロックを回復した後など。
        "isEOF": 1,                         // stageがストリームの終わりに達したかどうか (true: 終わりに達した)
        "invalidates": 0,
        "transformBy": {
            "_id": 0,
            "created_at": 1,
            "title": 1,
            "url": 1
        },
        "inputStage": {
            "stage": "SORT",
            "nReturned": 3,
            "executionTimeMillisEstimate": 712,
            "works": 396423,
            "advanced": 3,
            "needTime": 396419,
            "needYield": 0,
            "saveState": 3105,
            "restoreState": 3105,
            "isEOF": 1,
            "invalidates": 0,
            "sortPattern": {
                "created_at": -1
            },
            "memUsage": 1041,
            "memLimit": 33554432,
            "limitAmount": 3,
            "inputStage": {
                "stage": "SORT_KEY_GENERATOR",
                "nReturned": 45,
                "executionTimeMillisEstimate": 694,
                "works": 396419,
                "advanced": 45,
                "needTime": 396373,
                "needYield": 0,
                "saveState": 3105,
                "restoreState": 3105,
                "isEOF": 1,
                "invalidates": 0,
                "inputStage": {
                    "stage": "COLLSCAN",
                    "filter": {
                        "user_id": {
                            "$eq": "koshilife"
                        }
                    },
                    "nReturned": 45,
                    "executionTimeMillisEstimate": 694,
                    "works": 396418,
                    "advanced": 45,
                    "needTime": 396372,
                    "needYield": 0,
                    "saveState": 3105,
                    "restoreState": 3105,
                    "isEOF": 1,
                    "invalidates": 0,
                    "direction": "forward",
                    "docsExamined": 396416  // stageが走査したドキュメント数
                }
            }
        }
    }

executionStages内容を読み解きstageの親子関係に注目して整理してみました。

StageNo stage stage内容 advanced docsExamined そのstageの executionTimeMillisEstimate
1 PROJECTION 射影(created_at/title/url) 3 - 0 (712-712)
2 SORT created_at降順でソートして3件返却 3 - 18 (712-694)
3 SORT_KEY_GENERATOR ? 45 - 0 (694-694)
4 COLLSCAN フルスキャンして user_id='koshilife'でフィルタ 45 396416 694

結果フルスキャンしている COLLSCAN の処理に全体の 97.4% (694/712) の時間が見込まれることがわかり、このフルスキャン処理に改善効果があることがわかりました。

改善は次回エントリーにて

長くなってしまったので、調査結果を元にした改善は次回エントリーにて。

(追記:2019/04/30) 続きを書きました

MongoDB v4 explain 結果をちゃんと理解してクエリ改善 (後半:クエリ改善)

17
17
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
17
17