Troubleshooting Query Plan Regressions guide #20893
Conversation
✅ Deploy Preview for cockroachdb-api-docs canceled.
|
✅ Deploy Preview for cockroachdb-interactivetutorials-docs canceled.
|
Files changed:
|
✅ Netlify Preview
To edit notification comments on pull requests, go to your Netlify project configuration. |
rytaft
left a comment
rytaft
left a comment
There was a problem hiding this comment.
This is really great! Thank you for doing this! I left a few suggestions, and I bet @yuzefovich may have some more.
|
|
||
| - [Understand how the cost-based optimizer chooses query plans]({% link {{page.version.version}}/cost-based-optimizer.md %}) based on table statistics, and how those statistics are refreshed. | ||
|
|
||
| ## Query plan regressions vs. suboptimal plans |
There was a problem hiding this comment.
This section seems a bit too focused on the technicality of what the Insights page currently supports. I think it's worth mentioning that the Insights page can help, but I'm not sure you need to distinguish between plan regressions v suboptimal plans.
There was a problem hiding this comment.
I agree with Becca on this. This section seems confusing to me in the current form. "Slow execution" and "suboptimal plan" insights might be good starting points for troubleshooting an unsatisfactory latency for a given query, yet neither necessarily confirms / disproves that this query has experienced a query plan regression.
Perhaps a better way to include the information about the insights would be to have just a single sentence in "Before you begin" section to indicate that "suboptimal plan" insight might help with identifying / understanding the query plan regression. I'd probably omit the mention of "slow execution" insight altogether since it doesn't give much useful signal with query plan regressions - after all, the execution time exceeding the threshold controlled via the cluster setting could be the best we can do.
| 2. If you've already identified specific time intervals in Step 1, you can use the time interval selector to create a custom time interval. Click **Apply**. | ||
| 3. If there is only one plan in the resulting table, there was only one plan used for this statement fingerprint during this time interval, and therefore a query plan regression could not have occurred. If there are multiple plans listed in the resulting table, the query plan changed within the given time interval. By default, the table is sorted from most recent to least recent query plan. Compare the **Average Execution Time** of the different plans. | ||
|
|
||
| If a plan in the table has a significantly higher average execution time than the one that preceded it, it's possible that this is a query plan regression. It's also possible that the increase in latency is coincidental, or that the plan change was not the actual cause. For example, if the average execution time of the latest query plan is significantly higher than the average execution time of the previous query plan, this could be explained by a significant increase in the **Average Rows Read** column. |
There was a problem hiding this comment.
An increase in Average Rows Read could indicate a query plan regression, since it's possible that the bad query plan is scanning more rows than it should.
But as I think you're intending to show, an increase in Average Rows Read could also indicate that more data was added to the table. It's probably worth mentioning both possibilities here.
There was a problem hiding this comment.
To me it seems more likely that a significant increase (like an order of magnitude growth) in Average Rows Read is actually due to a plan regression, rather than due to the table size growth, since we're comparing two plans for the given query fingerprint that presumably were executed close - time-wise - to each other. I agree though that both are possibilities.
|
|
||
| 1. In the **Explain Plans** tab, click on the Plan Gist of the more recent plan to see it in more detail. | ||
| 2. Click on **All Plans** above to return to the list of plans. | ||
| 3. Click on the Plan Gist of the previous plan to see it in more detail. Compare the two plans to understand what changed. Do the plans use different indexes? Are they scanning the different portions of the table? Do they use different join strategies? |
There was a problem hiding this comment.
nit: the different portions -> different portions
|
|
||
| #### Determine if a literal in the SQL statement has changed | ||
|
|
||
| [NOTE FROM BRANDON: I need more information on this case, mainly how to identify that this is the case, and what to do about it.] |
There was a problem hiding this comment.
I'm not sure there is a good way to determine this without collecting a conditional statement bundle for a slow execution of the statement fingerprint (unless the DB operator happens to know that the application is using a new value for a particular placeholder). Maybe @yuzefovich has another idea?
There was a problem hiding this comment.
Oof, yeah, this is hard one. The tutorial so far assumes that there is a single good plan for a query fingerprint that might have regressed, but it's actually possible that multiple plans are good, depending on the values of placeholders ("literals").
Here is an example of two different optimal plans (although they do look similar):
CREATE TABLE small (k INT PRIMARY KEY, v INT);
CREATE TABLE large (k INT PRIMARY KEY, v INT, INDEX (v));
INSERT INTO small SELECT i, i FROM generate_series(1, 10) AS g(i);
INSERT INTO large SELECT i, 1 FROM generate_series(1, 10000) AS g(i);
ANALYZE small;
ANALYZE large;
-- this scans `large` on the _left_ side of merge join
EXPLAIN SELECT * FROM small INNER JOIN large ON small.v = large.v AND small.v = 1;
-- this scans `large` on the _right_ side of merge join
EXPLAIN SELECT * FROM small INNER JOIN large ON small.v = large.v AND small.v = 2;Complicating things is that we deal with query fingerprints internally, so all such constants are removed from our observability tooling. If there was an escalation saying that a particular query fingerprint is occasionally slow, similar to Becca I'd have asked for a conditional statement bundle, and then I'd play around locally with different values of placeholders to see whether multiple plans could be chosen based on concrete placeholder values. But so far we've used statement bundles mostly as internal (to Queries team in particular and Cockroach Labs support in general) tooling, so I'd probably not mention going down this route.
Instead, I'd consider suggesting looking into application side to see whether the literal has changed or something like that.
|
|
||
| [NOTE FROM BRANDON: I need more information on this case, mainly how to identify that this is the case, and what to do about it.] | ||
|
|
||
| If you suspect that the query plan change is the cause of the latency increase, and you suspect that the query plan changed due to a changed query literal, [what should you do] |
There was a problem hiding this comment.
what should you do
The likely problem is that the query stats don't accurately reflect how this value is represented in the data. This can be fixed by running ANALYZE <table> to refresh the stats for the table. It's also possible that a good index isn't available, which could be fixed by checking the index recommendations displayed by EXPLAIN-ing the query or on the insights page. If none of these options fixes the issue, a more drastic redesign of the schema/application may be needed.
yuzefovich
left a comment
yuzefovich
left a comment
There was a problem hiding this comment.
Nice, glad to see this work!
|
|
||
| - [Understand how the cost-based optimizer chooses query plans]({% link {{page.version.version}}/cost-based-optimizer.md %}) based on table statistics, and how those statistics are refreshed. | ||
|
|
||
| ## Query plan regressions vs. suboptimal plans |
There was a problem hiding this comment.
I agree with Becca on this. This section seems confusing to me in the current form. "Slow execution" and "suboptimal plan" insights might be good starting points for troubleshooting an unsatisfactory latency for a given query, yet neither necessarily confirms / disproves that this query has experienced a query plan regression.
Perhaps a better way to include the information about the insights would be to have just a single sentence in "Before you begin" section to indicate that "suboptimal plan" insight might help with identifying / understanding the query plan regression. I'd probably omit the mention of "slow execution" insight altogether since it doesn't give much useful signal with query plan regressions - after all, the execution time exceeding the threshold controlled via the cluster setting could be the best we can do.
|
|
||
| One way of tracking down query plan regressions is to identify SQL statements whose executions are relatively high in latency. Use one or both of the following methods to identify queries that might be associated with a latency increase. | ||
|
|
||
| #### Use workload insights |
There was a problem hiding this comment.
As I mentioned in another comment, my understanding of "slow execution" and "suboptimal plan" insights is that they cannot really be used to find or troubleshoot query plan regressions, so I'd remove "Use workload insights" approach altogether.
That said, it might be worth reaching out to TSEs / EEs to check whether their experience matches my understanding.
| 3. Among the resulting Statement Fingerprints, look for those with high latency. Click on the column headers to sort the results by **Statement Time** or **Max Latency**. | ||
| 4. Click on the Statement Fingerprint to go to the page that details the statement and its executions. | ||
| {{site.data.alerts.callout_success}} | ||
| Look for statements whose **Execution Count** is high. Statements that are run once, such as import statements, aren't likely to be the cause of increased latency due to query plan regressions. |
There was a problem hiding this comment.
nit: capitalize IMPORT and perhaps link to the IMPORT docs page.
| 2. If you've already identified specific time intervals in Step 1, you can use the time interval selector to create a custom time interval. Click **Apply**. | ||
| 3. If there is only one plan in the resulting table, there was only one plan used for this statement fingerprint during this time interval, and therefore a query plan regression could not have occurred. If there are multiple plans listed in the resulting table, the query plan changed within the given time interval. By default, the table is sorted from most recent to least recent query plan. Compare the **Average Execution Time** of the different plans. | ||
|
|
||
| If a plan in the table has a significantly higher average execution time than the one that preceded it, it's possible that this is a query plan regression. It's also possible that the increase in latency is coincidental, or that the plan change was not the actual cause. For example, if the average execution time of the latest query plan is significantly higher than the average execution time of the previous query plan, this could be explained by a significant increase in the **Average Rows Read** column. |
There was a problem hiding this comment.
To me it seems more likely that a significant increase (like an order of magnitude growth) in Average Rows Read is actually due to a plan regression, rather than due to the table size growth, since we're comparing two plans for the given query fingerprint that presumably were executed close - time-wise - to each other. I agree though that both are possibilities.
| #### Determine if the table indexes changed | ||
|
|
||
| 1. Look at the **Used Indexes** column for the older and the newer query plans. If these aren't the same, it's likely that the creation or deletion of an index resulted in a change to the statement's query plan. | ||
| 2. In the **Explain Plans** tab, click on the Plan Gist of the more recent plan to see it in more detail. Identify the table used in the initial "scan" step of the plan. |
There was a problem hiding this comment.
nit: s/table/tables/ - it's possible that we have initial scans of multiple tables.
|
|
||
| #### Determine if a literal in the SQL statement has changed | ||
|
|
||
| [NOTE FROM BRANDON: I need more information on this case, mainly how to identify that this is the case, and what to do about it.] |
There was a problem hiding this comment.
Oof, yeah, this is hard one. The tutorial so far assumes that there is a single good plan for a query fingerprint that might have regressed, but it's actually possible that multiple plans are good, depending on the values of placeholders ("literals").
Here is an example of two different optimal plans (although they do look similar):
CREATE TABLE small (k INT PRIMARY KEY, v INT);
CREATE TABLE large (k INT PRIMARY KEY, v INT, INDEX (v));
INSERT INTO small SELECT i, i FROM generate_series(1, 10) AS g(i);
INSERT INTO large SELECT i, 1 FROM generate_series(1, 10000) AS g(i);
ANALYZE small;
ANALYZE large;
-- this scans `large` on the _left_ side of merge join
EXPLAIN SELECT * FROM small INNER JOIN large ON small.v = large.v AND small.v = 1;
-- this scans `large` on the _right_ side of merge join
EXPLAIN SELECT * FROM small INNER JOIN large ON small.v = large.v AND small.v = 2;Complicating things is that we deal with query fingerprints internally, so all such constants are removed from our observability tooling. If there was an escalation saying that a particular query fingerprint is occasionally slow, similar to Becca I'd have asked for a conditional statement bundle, and then I'd play around locally with different values of placeholders to see whether multiple plans could be chosen based on concrete placeholder values. But so far we've used statement bundles mostly as internal (to Queries team in particular and Cockroach Labs support in general) tooling, so I'd probably not mention going down this route.
Instead, I'd consider suggesting looking into application side to see whether the literal has changed or something like that.
yuzefovich
left a comment
yuzefovich
left a comment
There was a problem hiding this comment.
Nice! This generally looks good to me now.
bsanchez-the-roach
requested review from
florence-crl,
rytaft and
yuzefovich
rytaft
left a comment
rytaft
left a comment
There was a problem hiding this comment.
Looks great! Just a couple small suggestions.
florence-crl
left a comment
florence-crl
left a comment
There was a problem hiding this comment.
Great work structuring this content! I was very nit-picky with making the text more clear and concise. Please let me know if you have any questions.
|
|
||
| ## What to look out for | ||
|
|
||
| Query plan regressions only increase the execution time of SQL statements that use that plan. This means that the overall service latency of the cluster will only be affected during the execution of statements that are run with the problematic query plan. |
There was a problem hiding this comment.
| Query plan regressions only increase the execution time of SQL statements that use that plan. This means that the overall service latency of the cluster will only be affected during the execution of statements that are run with the problematic query plan. | |
| Query plan regressions increase the execution time only for SQL statements that use the affected plan. This means that the overall service latency of the cluster will only be affected during the execution of statements that are run with the problematic query plan. |
There was a problem hiding this comment.
Query plan regressions only increase the execution time of SQL statements that use the affected plan. This means that the overall service latency of the cluster will only be affected during the execution of statements that are run with the problematic query plan.
|
|
||
| Query plan regressions only increase the execution time of SQL statements that use that plan. This means that the overall service latency of the cluster will only be affected during the execution of statements that are run with the problematic query plan. | ||
|
|
||
| This might make those latency spikes harder to identify. For example, if the problematic plan only affects a query that's run on an infrequent, ad-hoc basis, it might be difficult to notice a pattern among the graphs on the [**Metrics** page]({% link {{page.version.version}}/ui-overview.md %}#metrics). |
There was a problem hiding this comment.
| This might make those latency spikes harder to identify. For example, if the problematic plan only affects a query that's run on an infrequent, ad-hoc basis, it might be difficult to notice a pattern among the graphs on the [**Metrics** page]({% link {{page.version.version}}/ui-overview.md %}#metrics). | |
| As a result, these latency spikes can be harder to identify. For example, if the problematic plan only affects a query that's run on an infrequent, ad-hoc basis, it might be difficult to notice a pattern among the graphs on the [**Metrics** page]({% link {{page.version.version}}/ui-overview.md %}#metrics). |
There was a problem hiding this comment.
As a result, these latency spikes can be hard to identify. For example, if the problematic plan only affects a query that's run on an infrequent, ad-hoc basis, it might be difficult to notice a pattern among the graphs on the [Metrics page]({% link {{page.version.version}}/ui-overview.md %}#metrics).
|
|
||
| Inspect your application to see if the literals being used within the query executions are changing. | ||
|
|
||
| If you suspect that the query plan change is the cause of the latency increase, and you suspect that the query plan changed due to a changed query literal, it's possible that the table statistics don't accurately reflect how the literal values are represented in the data. You may want to [manually refresh the statistics for the table]({% link {{ page.version.version }}/create-statistics.md %}#examples). It's also possible that the table indexes are not helpful for queries with the newer literal value, in which case you may want to [check the **Insights** page for index recommendations]({% link {{ page.version.version }}/ui-insights-page.md %}#suboptimal-plan). |
There was a problem hiding this comment.
| If you suspect that the query plan change is the cause of the latency increase, and you suspect that the query plan changed due to a changed query literal, it's possible that the table statistics don't accurately reflect how the literal values are represented in the data. You may want to [manually refresh the statistics for the table]({% link {{ page.version.version }}/create-statistics.md %}#examples). It's also possible that the table indexes are not helpful for queries with the newer literal value, in which case you may want to [check the **Insights** page for index recommendations]({% link {{ page.version.version }}/ui-insights-page.md %}#suboptimal-plan). | |
| If you suspect the plan change caused the latency increase and was triggered by a changed query literal, table statistics may not accurately reflect how those values appear in the data. You may want to [manually refresh the statistics for the table]({% link {{ page.version.version }}/create-statistics.md %}#examples). It’s also possible that the current indexes aren’t effective for queries with the new literal value. In that case, [check the **Insights** page for index recommendations]({% link {{ page.version.version }}/ui-insights-page.md %}#suboptimal-plan). |
|
|
||
| If you suspect that the query plan change is the cause of the latency increase, and you suspect that the query plan changed due to a changed query literal, it's possible that the table statistics don't accurately reflect how the literal values are represented in the data. You may want to [manually refresh the statistics for the table]({% link {{ page.version.version }}/create-statistics.md %}#examples). It's also possible that the table indexes are not helpful for queries with the newer literal value, in which case you may want to [check the **Insights** page for index recommendations]({% link {{ page.version.version }}/ui-insights-page.md %}#suboptimal-plan). | ||
|
|
||
| If this does not fix the issue, a more drastic redesign of the schema or application may be needed. |
There was a problem hiding this comment.
| If this does not fix the issue, a more drastic redesign of the schema or application may be needed. | |
| If the issue persists, a more substantial redesign of the schema or application may be required. |
| #### View all events | ||
|
|
||
| 1. Go to the [**Metrics** page]({% link {{page.version.version}}/ui-overview.md %}#metrics). | ||
| 2. Go the [**Events** panel]({% link {{page.version.version}}/ui-runtime-dashboard.md %}#events-panel) on the right. Scroll to the bottom, and click **View All Events**. |
There was a problem hiding this comment.
| 2. Go the [**Events** panel]({% link {{page.version.version}}/ui-runtime-dashboard.md %}#events-panel) on the right. Scroll to the bottom, and click **View All Events**. | |
| 2. Go to the [**Events** panel]({% link {{page.version.version}}/ui-runtime-dashboard.md %}#events-panel) on the right. Scroll to the bottom, and click **View All Events**. |
| 2. Go the [**Events** panel]({% link {{page.version.version}}/ui-runtime-dashboard.md %}#events-panel) on the right. Scroll to the bottom, and click **View All Events**. | ||
| 3. Scroll down to the approximate time when the latency increase began. | ||
|
|
||
| See if any events occured around that time that may have contributed to a query plan regression. These might include schema changes that affect tables involved in the suspect SQL queries, [changed cluster settings]({% link {{ page.version.version }}/set-cluster-setting.md %}), created or dropped indexes, and more. |
There was a problem hiding this comment.
| See if any events occured around that time that may have contributed to a query plan regression. These might include schema changes that affect tables involved in the suspect SQL queries, [changed cluster settings]({% link {{ page.version.version }}/set-cluster-setting.md %}), created or dropped indexes, and more. | |
| Check for any events around that time that may have contributed to a query plan regression. These may include schema changes affecting tables in suspect SQL queries, [modified cluster settings]({% link {{ page.version.version }}/set-cluster-setting.md %}), created or dropped indexes, and more. |
|
|
||
| See if any events occured around that time that may have contributed to a query plan regression. These might include schema changes that affect tables involved in the suspect SQL queries, [changed cluster settings]({% link {{ page.version.version }}/set-cluster-setting.md %}), created or dropped indexes, and more. | ||
|
|
||
| A consequential event around the time of the latency increase may have affected the way that the optimizer chose query plans. Inspect changed cluster settings, or [determine if the table indexes changed](#determine-if-the-table-indexes-changed). |
There was a problem hiding this comment.
| A consequential event around the time of the latency increase may have affected the way that the optimizer chose query plans. Inspect changed cluster settings, or [determine if the table indexes changed](#determine-if-the-table-indexes-changed). | |
| An event around the time of the latency increase may have influenced how the optimizer selected query plans. Inspect changed cluster settings, or [determine if the table indexes changed](#determine-if-the-table-indexes-changed). |
florence-crl
left a comment
florence-crl
left a comment
There was a problem hiding this comment.
Great work structuring this content! I was very nit-picky with making the text more clear and concise. Please let me know if you have any questions.
Co-authored-by: Florence Morris <[email protected]>
florence-crl
left a comment
florence-crl
left a comment
There was a problem hiding this comment.
LGTM pending non-blocking nits
Co-authored-by: Florence Morris <[email protected]>
4 participants
DOC-15152
This is a first draft, I definitely want a review for accuracy since I'm still pretty new to this product.
There's an unfinished section at the very bottom, I've left a note there and am looking for some guidance.
Happy to iterate on this more, I just want to get eyes on it.
Rendered preview: