しばやん雑記

Azure とメイドさんが大好きなフリーランスのプログラマーのブログ

Cosmos DB の SQL クエリパフォーマンスを調査する

Azure Cosmos DB

仕事で Cosmos DB を使っていますが、最近は RU の消費が気になってきて、実際に投げたクエリがどのように実行されているのか知りたくなったので、例によっておーみさんに聞きました。

実行計画とはいかなくとも、非常に参考になるメトリックを返してくれるようになっているみたいです。

インデックスが本当に使われているのかどうかも、このメトリックから読み取れるようになってます。

ドキュメントを読めば大体わかりますが、FeedOptions で PopulateQueryMetrics = true とするとレスポンスにクエリの実行にかかった諸々の時間やデータサイズなどが返ってきます。

百聞は一見に如かずということで、適当なデータを作成して試してみました。まずは普通にインデックスが効いているであろうというケースです。

RDB でもインデックスを普通に作れば、Index Seek で引けるはずですね。

var feedOptions = new FeedOptions
{
    MaxItemCount = 1,
    EnableCrossPartitionQuery = true,
    PopulateQueryMetrics = true
};

var documentQuery = Client.CreateDocumentQuery<MemberDocument>(UriFactory.CreateDocumentCollectionUri(DatabaseId, CollectionId), feedOptions)
                            .Where(x => x.Email == "test-1@example.com")
                            .AsDocumentQuery();

var response = await documentQuery.ExecuteNextAsync<MemberDocument>();

foreach (var item in response.QueryMetrics)
{
    var data = JsonConvert.SerializeObject(item.Value, Formatting.Indented);
}

インデックスの作成ポリシーはデフォルトのままなので、当然ながら Email に対してもインデックスが作成されています。それではインデックスが実際に使われているのかを確認してみます。

QueryMetrics の中身を表示するのが面倒だったので、適当に JSON にしたものを貼り付けておきます。

{
  "TotalTime": "00:00:00.0006100",
  "RetrievedDocumentCount": 1,
  "RetrievedDocumentSize": 853,
  "OutputDocumentCount": 1,
  "IndexHitRatio": 1.0,
  "QueryPreparationTimes": {
    "CompileTime": "00:00:00.0000600",
    "LogicalPlanBuildTime": "00:00:00.0000200",
    "PhysicalPlanBuildTime": "00:00:00.0000300",
    "QueryOptimizationTime": "00:00:00"
  },
  "QueryEngineTimes": {
    "IndexLookupTime": "00:00:00.0003000",
    "DocumentLoadTime": "00:00:00.0000200",
    "WriteOutputTime": "00:00:00.0000200",
    "RuntimeExecutionTimes": {
      "TotalTime": "00:00:00.0000100",
      "SystemFunctionExecutionTime": "00:00:00",
      "UserDefinedFunctionExecutionTime": "00:00:00"
    }
  },
  "Retries": 0
}

データの意味はドキュメントとキー名を見ればわかると思います。インデックスが使われているかどうかは IndexHitRatio と IndexLookupTime の値を見れば良いです。それぞれが 1.0 と 0.3ms となっているので、インデックスはちゃんと使われています。

ちなみに Time で終わるキーの値が 00:00:00 の場合は実行されていない扱いです。なので今回の場合は QueryOptimizationTime や Function の呼び出しが該当します。

Cosmos DB のインデックス周りは優秀みたいで、効かないかと思った条件でも割とインデックスが使われていました。しかし、SQL で言う LIKE の場合はスキャンになるみたいなので試しました。

var feedOptions = new FeedOptions
{
    MaxItemCount = 1,
    EnableCrossPartitionQuery = true,
    PopulateQueryMetrics = true
};

var documentQuery = Client.CreateDocumentQuery<MemberDocument>(UriFactory.CreateDocumentCollectionUri(DatabaseId, CollectionId), feedOptions)
                            .Where(x => x.FirstName.Contains("kazuakix98"))
                            .AsDocumentQuery();

var response = await documentQuery.ExecuteNextAsync<MemberDocument>();

foreach (var item in response.QueryMetrics)
{
    var data = JsonConvert.SerializeObject(item.Value, Formatting.Indented);
}

こういう条件の場合は Azure Search を使えといわれそうですが、適当に試した感じではこれぐらいしかスキャンにならなかったので勘弁してください。

そして QueryMetrics の中身は以下の通りです。IndexHitRatio と IndexLookupTime に注目。

{
  "TotalTime": "00:00:00.0008900",
  "RetrievedDocumentCount": 100,
  "RetrievedDocumentSize": 85643,
  "OutputDocumentCount": 1,
  "IndexHitRatio": 0.01,
  "QueryPreparationTimes": {
    "CompileTime": "00:00:00.0000800",
    "LogicalPlanBuildTime": "00:00:00.0000400",
    "PhysicalPlanBuildTime": "00:00:00.0000300",
    "QueryOptimizationTime": "00:00:00"
  },
  "QueryEngineTimes": {
    "IndexLookupTime": "00:00:00",
    "DocumentLoadTime": "00:00:00.0003200",
    "WriteOutputTime": "00:00:00.0000200",
    "RuntimeExecutionTimes": {
      "TotalTime": "00:00:00.0002100",
      "SystemFunctionExecutionTime": "00:00:00.0000400",
      "UserDefinedFunctionExecutionTime": "00:00:00"
    }
  },
  "Retries": 0
}

全くインデックスが使われていないことが分かります。その代わりにスキャンが行われているので、DocumentLoadTime に割と時間がかかっていることも見て取れますね。

RetrievedDocumentCount が 100 となっているので、1 件を返すために 100 件をスキャンしていることも分かります。これだと RU も消費するし、時間もかかってくるので改善が必要となります。

RU と同じように Application Insights に送りたいのですが、PopulateQueryMetrics のオーバーヘッドがどのくらいなのかわからないため、ちょっとローカルのみで検証して様子見です。