|
| 1 | +--- |
| 2 | +title: Get NoSQL query performance & execution metrics in Azure Cosmos DB using Python SDK |
| 3 | +description: Learn how to retrieve NoSQL query execution metrics and profile NoSQL query performance of Azure Cosmos DB requests. |
| 4 | +author: abhinavtrips |
| 5 | +ms.service: cosmos-db |
| 6 | +ms.subservice: nosql |
| 7 | +ms.topic: how-to |
| 8 | +ms.date: 1/5/2023 |
| 9 | +ms.author: abtripathi |
| 10 | +ms.custom: devx-track-python, devx-track-python-sdk |
| 11 | +--- |
| 12 | +# Get SQL query execution metrics and analyze query performance using .NET SDK |
| 13 | +[!INCLUDE[NoSQL](../includes/appliesto-nosql.md)] |
| 14 | + |
| 15 | +This article presents how to profile SQL query performance on Azure Cosmos DB using Query Execution Metrics. It contains cumulative metrics that are aggregated across all physical partitions for the request, a list of metrics for each physical partition, and the total request charge. These metrics are documented in more detail in the [Tune Query Performance](./query-metrics.md#query-execution-metrics) article. |
| 16 | + |
| 17 | +## Enable query metrics |
| 18 | + |
| 19 | +To get query metrics, you need to set the ```populate_query_metrics``` flag to ```True``` in your query parameters as below. You may be interested in enabling index metrics as well for debugging purposes and you can enable it by setting the ```populate_query_metrics``` flag to ```True```: |
| 20 | + |
| 21 | +```python |
| 22 | +results = container.query_items( |
| 23 | + query=queryText, |
| 24 | + enable_cross_partition_query=True, |
| 25 | + populate_index_metrics=True, |
| 26 | + populate_query_metrics=True |
| 27 | +) |
| 28 | +``` |
| 29 | + |
| 30 | + |
| 31 | +### Get Query Execution Metrics |
| 32 | +In python SDK, you can read the ```x-ms-documentdb-query-metrics``` header values from the container client to get the query execution metrics. The following code snippet shows how to read the query execution metrics: |
| 33 | + |
| 34 | +```python |
| 35 | +results = container.query_items( |
| 36 | + query=queryText, |
| 37 | + enable_cross_partition_query=True, |
| 38 | + populate_query_metrics=True |
| 39 | +) |
| 40 | + |
| 41 | +items = [item for item in results] |
| 42 | +''' |
| 43 | +Please note that the last_response_headers are available only after the first iteration of the results as the query execution starts only when result iteration begins |
| 44 | +''' |
| 45 | +print("Query Metrics: ",container.client_connection.last_response_headers['x-ms-documentdb-query-metrics']) |
| 46 | +``` |
| 47 | + |
| 48 | +The result will give you query execution related info as below: |
| 49 | +```python |
| 50 | +totalExecutionTimeInMs=0.27; |
| 51 | +queryCompileTimeInMs=0.04; |
| 52 | +queryLogicalPlanBuildTimeInMs=0.00; |
| 53 | +queryPhysicalPlanBuildTimeInMs=0.02; |
| 54 | +queryOptimizationTimeInMs=0.00; |
| 55 | +VMExecutionTimeInMs=0.02; |
| 56 | +indexLookupTimeInMs=0.00; |
| 57 | +instructionCount=17; |
| 58 | +documentLoadTimeInMs=0.01; |
| 59 | +systemFunctionExecuteTimeInMs=0.00; |
| 60 | +userFunctionExecuteTimeInMs=0.00; |
| 61 | +retrievedDocumentCount=3; |
| 62 | +retrievedDocumentSize=1005; |
| 63 | +outputDocumentCount=3; |
| 64 | +outputDocumentSize=1056; |
| 65 | +writeOutputTimeInMs=0.00; |
| 66 | +indexUtilizationRatio=1.00 |
| 67 | +``` |
| 68 | + |
| 69 | +The above results can give you insights on how efficient your query is. You can look at the totalExecutionTimeInMs to see how long the query took to execute. The indexUtilizationRatio can give you insights on how well your query is utilizing the index. |
| 70 | +To understand the metrics in detail, refer to the [Query Execution Metrics](./query-metrics.md#query-execution-metrics) article. |
| 71 | + |
| 72 | + |
| 73 | +## Get the query request charge |
| 74 | + |
| 75 | +You can capture the Total request Units (RUs) consumed by reading ```x-ms-request-charge``` value. You do not need to set any parameters explicitly to retrieve the request charge value. The following example shows how to get the request charge for each continuation of a query: |
| 76 | + |
| 77 | +```python |
| 78 | +items = [item for item in results] |
| 79 | +print("Request Units consumed: ",container.client_connection.last_response_headers['x-ms-request-charge']) |
| 80 | +``` |
| 81 | + |
| 82 | + |
| 83 | +## Get the index utilization |
| 84 | + |
| 85 | +Looking at the index utilization can help you debug slow queries. A good index utilization score must be close to 1. Queries that can't use the index, result in a full scan of all documents in a container before returning the result set. |
| 86 | + |
| 87 | +Here's an example of a scan query: |
| 88 | + |
| 89 | +```sql |
| 90 | +SELECT VALUE c.description |
| 91 | +FROM c |
| 92 | +WHERE UPPER(c.description) = "BABYFOOD, DESSERT, FRUIT DESSERT, WITHOUT ASCORBIC ACID, JUNIOR" |
| 93 | +``` |
| 94 | + |
| 95 | +This query's filter uses the system function UPPER, which isn't served from the index. Executing this query against a large collection produced the following query metrics for the first continuation: |
| 96 | + |
| 97 | +``` |
| 98 | +QueryMetrics |
| 99 | +
|
| 100 | +Retrieved Document Count : 60,951 |
| 101 | +Retrieved Document Size : 399,998,938 bytes |
| 102 | +Output Document Count : 7 |
| 103 | +Output Document Size : 510 bytes |
| 104 | +Index Utilization : 0.00 % |
| 105 | +Total Query Execution Time : 4,500.34 milliseconds |
| 106 | +Query Preparation Time : 0.2 milliseconds |
| 107 | +Index Lookup Time : 0.01 milliseconds |
| 108 | +Document Load Time : 4,177.66 milliseconds |
| 109 | +Runtime Execution Time : 407.9 milliseconds |
| 110 | +Document Write Time : 0.01 milliseconds |
| 111 | +``` |
| 112 | + |
| 113 | +Note the following values from the query metrics output: |
| 114 | + |
| 115 | +``` |
| 116 | +Retrieved Document Count : 60,951 |
| 117 | +Retrieved Document Size : 399,998,938 bytes |
| 118 | +``` |
| 119 | + |
| 120 | +This query loaded 60,951 documents, which totaled 399,998,938 bytes. Loading this many bytes results in high cost or request unit charge. It also takes a long time to execute the query, which is clear with the total time spent property: |
| 121 | + |
| 122 | +``` |
| 123 | +Total Query Execution Time : 4,500.34 milliseconds |
| 124 | +``` |
| 125 | + |
| 126 | +Meaning that the query took 4.5 seconds to execute (and this was only one continuation). |
| 127 | + |
| 128 | +To optimize this example query, avoid the use of UPPER in the filter. Instead, when documents are created or updated, the `c.description` values must be inserted in all uppercase characters. The query then becomes: |
| 129 | + |
| 130 | +```sql |
| 131 | +SELECT VALUE c.description |
| 132 | +FROM c |
| 133 | +WHERE c.description = "BABYFOOD, DESSERT, FRUIT DESSERT, WITHOUT ASCORBIC ACID, JUNIOR" |
| 134 | +``` |
| 135 | + |
| 136 | +This query is now able to be served from the index. Alternatively, you can use [computed properties](query/computed-properties.md) to index the results of system functions or complex calculations that would otherwise result in a full scan. |
| 137 | + |
| 138 | +To have a look at the potential index recommendations and to check which indexes have been utilized, you must set the ```populate_index_metrics``` parameter to ```True``` and then you can read the ```x-ms-documentdb-index-utilization``` header values from the container client. The following code snippet shows how to read the index utilization metrics: |
| 139 | + |
| 140 | +```python |
| 141 | +results = container.query_items( |
| 142 | + query=queryText, |
| 143 | + enable_cross_partition_query=True, |
| 144 | + populate_index_metrics = True |
| 145 | +) |
| 146 | +items = [item for item in results] |
| 147 | +print("Index Utilization Info: ",container.client_connection.last_response_headers['x-ms-cosmos-index-utilization']) |
| 148 | + |
| 149 | +``` |
| 150 | + |
| 151 | +To learn more about tuning query performance, see the [Tune Query Performance](./query-metrics.md) article. |
| 152 | + |
| 153 | +## <a id="References"></a>References |
| 154 | + |
| 155 | +- [Azure Cosmos DB SQL specification](query/getting-started.md) |
| 156 | + |
| 157 | + |
| 158 | +## Next steps |
| 159 | + |
| 160 | +- [Tune query performance](query-metrics.md) |
| 161 | +- [Indexing overview](../index-overview.md) |
| 162 | +- [Azure Cosmos DB Python SDK Best Practices](https://learn.microsoft.com/en-us/azure/cosmos-db/nosql/best-practice-python) |
| 163 | +- [Azure Cosmos DB Python SDK Performance Tips](https://learn.microsoft.com/en-us/azure/cosmos-db/nosql/performance-tips-python-sdk) |
0 commit comments