There is some problem with the last patch, I have removed the `ExplainOpenWorker` call to fix.
And also, I have added a test case in explain.sql according to the code change. ________________________________ From: Jian Guo <gj...@vmware.com> Sent: Monday, March 21, 2022 11:36 To: pgsql-hackers@lists.postgresql.org <pgsql-hackers@lists.postgresql.org> Cc: Zhenghua Lyu <z...@vmware.com> Subject: Summary Sort workers Stats in EXPLAIN ANALYZE In current EXPLAIN ANALYZE implementation, the Sort Node stats from each workers are not summarized: https://github.com/postgres/postgres/blob/d4ba8b51c76300f06cc23f4d8a41d9f7210c4866/src/backend/commands/explain.c#L2762<https://nam04.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fpostgres%2Fpostgres%2Fblob%2Fd4ba8b51c76300f06cc23f4d8a41d9f7210c4866%2Fsrc%2Fbackend%2Fcommands%2Fexplain.c%23L2762&data=04%7C01%7Cgjian%40vmware.com%7C0f2c3df25e8a46bdd84f08da0aebff59%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C0%7C0%7C637834305971955895%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=RXY0uDuK7cFraHJqwU%2FQv%2BXhq3n%2F2cO6nv%2BoxHTbmCM%3D&reserved=0> When the worker number is large, it will print out huge amount of node details in the plan. I have created this patch to summarize the tuplesort stats by AverageSpaceUsed / PeakSpaceUsed, make it behave just like in `show_incremental_sort_group_info()`: https://github.com/postgres/postgres/blob/d4ba8b51c76300f06cc23f4d8a41d9f7210c4866/src/backend/commands/explain.c#L2890<https://nam04.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fpostgres%2Fpostgres%2Fblob%2Fd4ba8b51c76300f06cc23f4d8a41d9f7210c4866%2Fsrc%2Fbackend%2Fcommands%2Fexplain.c%23L2890&data=04%7C01%7Cgjian%40vmware.com%7C0f2c3df25e8a46bdd84f08da0aebff59%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C0%7C0%7C637834305971955895%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=NotrZFufFycTmlVy3SKioUSWGzLalSu9SWCOccMXGCI%3D&reserved=0>
From 5b044523ee16bdae7b998ddd31fca92434e5028a Mon Sep 17 00:00:00 2001 From: Aegeaner Guo <xih...@gmail.com> Date: Mon, 21 Mar 2022 11:19:46 +0800 Subject: [PATCH] Summary Sort workers Stats. Signed-off-by: Jian Guo <gj...@vmware.com> --- src/backend/commands/explain.c | 44 +-- src/test/regress/expected/explain.out | 523 ++++++++++++++++++-------- src/test/regress/sql/explain.sql | 13 +- 3 files changed, 392 insertions(+), 188 deletions(-) diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 9f632285b6..57409bdea2 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -2758,40 +2758,42 @@ show_sort_info(SortState *sortstate, ExplainState *es) if (sortstate->shared_info != NULL) { int n; + const char *sortMethod; + const char *spaceType; + int64 peakSpaceUsed = 0; + int64 totalSpaceUsed = 0; for (n = 0; n < sortstate->shared_info->num_workers; n++) { TuplesortInstrumentation *sinstrument; - const char *sortMethod; - const char *spaceType; - int64 spaceUsed; sinstrument = &sortstate->shared_info->sinstrument[n]; if (sinstrument->sortMethod == SORT_TYPE_STILL_IN_PROGRESS) continue; /* ignore any unfilled slots */ sortMethod = tuplesort_method_name(sinstrument->sortMethod); spaceType = tuplesort_space_type_name(sinstrument->spaceType); - spaceUsed = sinstrument->spaceUsed; + peakSpaceUsed = Max(peakSpaceUsed, sinstrument->spaceUsed); + totalSpaceUsed += sinstrument->spaceUsed; + } - if (es->workers_state) - ExplainOpenWorker(n, es); + int64 avgSpaceUsed = sortstate->shared_info->num_workers > 0 ? + totalSpaceUsed / sortstate->shared_info->num_workers : 0; - if (es->format == EXPLAIN_FORMAT_TEXT) - { - ExplainIndentText(es); - appendStringInfo(es->str, - "Sort Method: %s %s: " INT64_FORMAT "kB\n", - sortMethod, spaceType, spaceUsed); - } - else - { - ExplainPropertyText("Sort Method", sortMethod, es); - ExplainPropertyInteger("Sort Space Used", "kB", spaceUsed, es); - ExplainPropertyText("Sort Space Type", spaceType, es); - } + ExplainPropertyInteger("Workers planned", NULL, sortstate->shared_info->num_workers, es); - if (es->workers_state) - ExplainCloseWorker(n, es); + if (es->format == EXPLAIN_FORMAT_TEXT) + { + ExplainIndentText(es); + appendStringInfo(es->str, + "Sort Method: %s %s: " INT64_FORMAT INT64_FORMAT "kB\n", + sortMethod, spaceType, avgSpaceUsed, peakSpaceUsed); + } + else + { + ExplainPropertyText("Sort Method", sortMethod, es); + ExplainPropertyInteger("Average Sort Space Used", "kB", avgSpaceUsed, es); + ExplainPropertyInteger("Peak Sort Space Used", "kB", peakSpaceUsed, es); + ExplainPropertyText("Sort Space Type", spaceType, es); } } } diff --git a/src/test/regress/expected/explain.out b/src/test/regress/expected/explain.out index bc36175921..25a5744a30 100644 --- a/src/test/regress/expected/explain.out +++ b/src/test/regress/expected/explain.out @@ -312,173 +312,315 @@ set max_parallel_workers_per_gather=4; select jsonb_pretty( explain_filter_to_json('explain (analyze, verbose, buffers, format json) select * from tenk1 order by tenthous') - -- remove "Workers" node of the Seq Scan plan node - #- '{0,Plan,Plans,0,Plans,0,Workers}' - -- remove "Workers" node of the Sort plan node - #- '{0,Plan,Plans,0,Workers}' + -- remove "Workers planned" node of the Seq Scan plan node + #- '{0,Plan,Plans,0,Plans,0,Workers planned}' + -- remove "Sort Space" node of the Sort plan node + #- '{0,Plan,Plans,0,Average Sort Space Used}' + #- '{0,Plan,Plans,0,Peak Sort Space Used}' -- Also remove its sort-type fields, as those aren't 100% stable #- '{0,Plan,Plans,0,Sort Method}' #- '{0,Plan,Plans,0,Sort Space Type}' ); - jsonb_pretty -------------------------------------------------------------- - [ + - { + - "Plan": { + - "Plans": [ + - { + - "Plans": [ + - { + - "Alias": "tenk1", + - "Output": [ + - "unique1", + - "unique2", + - "two", + - "four", + - "ten", + - "twenty", + - "hundred", + - "thousand", + - "twothousand", + - "fivethous", + - "tenthous", + - "odd", + - "even", + - "stringu1", + - "stringu2", + - "string4" + - ], + - "Schema": "public", + - "Node Type": "Seq Scan", + - "Plan Rows": 0, + - "Plan Width": 0, + - "Total Cost": 0.0, + - "Actual Rows": 0, + - "Actual Loops": 0, + - "Startup Cost": 0.0, + - "Async Capable": false, + - "Relation Name": "tenk1", + - "Parallel Aware": true, + - "Local Hit Blocks": 0, + - "Temp Read Blocks": 0, + - "Actual Total Time": 0.0, + - "Local Read Blocks": 0, + - "Shared Hit Blocks": 0, + - "Shared Read Blocks": 0, + - "Actual Startup Time": 0.0, + - "Parent Relationship": "Outer",+ - "Temp Written Blocks": 0, + - "Local Dirtied Blocks": 0, + - "Local Written Blocks": 0, + - "Shared Dirtied Blocks": 0, + - "Shared Written Blocks": 0 + - } + - ], + - "Output": [ + - "unique1", + - "unique2", + - "two", + - "four", + - "ten", + - "twenty", + - "hundred", + - "thousand", + - "twothousand", + - "fivethous", + - "tenthous", + - "odd", + - "even", + - "stringu1", + - "stringu2", + - "string4" + - ], + - "Sort Key": [ + - "tenk1.tenthous" + - ], + - "Node Type": "Sort", + - "Plan Rows": 0, + - "Plan Width": 0, + - "Total Cost": 0.0, + - "Actual Rows": 0, + - "Actual Loops": 0, + - "Startup Cost": 0.0, + - "Async Capable": false, + - "Parallel Aware": false, + - "Sort Space Used": 0, + - "Local Hit Blocks": 0, + - "Temp Read Blocks": 0, + - "Actual Total Time": 0.0, + - "Local Read Blocks": 0, + - "Shared Hit Blocks": 0, + - "Shared Read Blocks": 0, + - "Actual Startup Time": 0.0, + - "Parent Relationship": "Outer", + - "Temp Written Blocks": 0, + - "Local Dirtied Blocks": 0, + - "Local Written Blocks": 0, + - "Shared Dirtied Blocks": 0, + - "Shared Written Blocks": 0 + - } + - ], + - "Output": [ + - "unique1", + - "unique2", + - "two", + - "four", + - "ten", + - "twenty", + - "hundred", + - "thousand", + - "twothousand", + - "fivethous", + - "tenthous", + - "odd", + - "even", + - "stringu1", + - "stringu2", + - "string4" + - ], + - "Node Type": "Gather Merge", + - "Plan Rows": 0, + - "Plan Width": 0, + - "Total Cost": 0.0, + - "Actual Rows": 0, + - "Actual Loops": 0, + - "Startup Cost": 0.0, + - "Async Capable": false, + - "Parallel Aware": false, + - "Workers Planned": 0, + - "Local Hit Blocks": 0, + - "Temp Read Blocks": 0, + - "Workers Launched": 0, + - "Actual Total Time": 0.0, + - "Local Read Blocks": 0, + - "Shared Hit Blocks": 0, + - "Shared Read Blocks": 0, + - "Actual Startup Time": 0.0, + - "Temp Written Blocks": 0, + - "Local Dirtied Blocks": 0, + - "Local Written Blocks": 0, + - "Shared Dirtied Blocks": 0, + - "Shared Written Blocks": 0 + - }, + - "Planning": { + - "Local Hit Blocks": 0, + - "Temp Read Blocks": 0, + - "Local Read Blocks": 0, + - "Shared Hit Blocks": 0, + - "Shared Read Blocks": 0, + - "Temp Written Blocks": 0, + - "Local Dirtied Blocks": 0, + - "Local Written Blocks": 0, + - "Shared Dirtied Blocks": 0, + - "Shared Written Blocks": 0 + - }, + - "Triggers": [ + - ], + - "Planning Time": 0.0, + - "Execution Time": 0.0 + - } + + jsonb_pretty +----------------------------------------------------------------- + [ + + { + + "Plan": { + + "Plans": [ + + { + + "Plans": [ + + { + + "Alias": "tenk1", + + "Output": [ + + "unique1", + + "unique2", + + "two", + + "four", + + "ten", + + "twenty", + + "hundred", + + "thousand", + + "twothousand", + + "fivethous", + + "tenthous", + + "odd", + + "even", + + "stringu1", + + "stringu2", + + "string4" + + ], + + "Schema": "public", + + "Workers": [ + + { + + "Actual Rows": 0, + + "Actual Loops": 0, + + "Worker Number": 0, + + "Local Hit Blocks": 0, + + "Temp Read Blocks": 0, + + "Actual Total Time": 0.0, + + "Local Read Blocks": 0, + + "Shared Hit Blocks": 0, + + "Shared Read Blocks": 0, + + "Actual Startup Time": 0.0,+ + "Temp Written Blocks": 0, + + "Local Dirtied Blocks": 0, + + "Local Written Blocks": 0, + + "Shared Dirtied Blocks": 0,+ + "Shared Written Blocks": 0 + + }, + + { + + "Actual Rows": 0, + + "Actual Loops": 0, + + "Worker Number": 0, + + "Local Hit Blocks": 0, + + "Temp Read Blocks": 0, + + "Actual Total Time": 0.0, + + "Local Read Blocks": 0, + + "Shared Hit Blocks": 0, + + "Shared Read Blocks": 0, + + "Actual Startup Time": 0.0,+ + "Temp Written Blocks": 0, + + "Local Dirtied Blocks": 0, + + "Local Written Blocks": 0, + + "Shared Dirtied Blocks": 0,+ + "Shared Written Blocks": 0 + + }, + + { + + "Actual Rows": 0, + + "Actual Loops": 0, + + "Worker Number": 0, + + "Local Hit Blocks": 0, + + "Temp Read Blocks": 0, + + "Actual Total Time": 0.0, + + "Local Read Blocks": 0, + + "Shared Hit Blocks": 0, + + "Shared Read Blocks": 0, + + "Actual Startup Time": 0.0,+ + "Temp Written Blocks": 0, + + "Local Dirtied Blocks": 0, + + "Local Written Blocks": 0, + + "Shared Dirtied Blocks": 0,+ + "Shared Written Blocks": 0 + + }, + + { + + "Actual Rows": 0, + + "Actual Loops": 0, + + "Worker Number": 0, + + "Local Hit Blocks": 0, + + "Temp Read Blocks": 0, + + "Actual Total Time": 0.0, + + "Local Read Blocks": 0, + + "Shared Hit Blocks": 0, + + "Shared Read Blocks": 0, + + "Actual Startup Time": 0.0,+ + "Temp Written Blocks": 0, + + "Local Dirtied Blocks": 0, + + "Local Written Blocks": 0, + + "Shared Dirtied Blocks": 0,+ + "Shared Written Blocks": 0 + + } + + ], + + "Node Type": "Seq Scan", + + "Plan Rows": 0, + + "Plan Width": 0, + + "Total Cost": 0.0, + + "Actual Rows": 0, + + "Actual Loops": 0, + + "Startup Cost": 0.0, + + "Async Capable": false, + + "Relation Name": "tenk1", + + "Parallel Aware": true, + + "Local Hit Blocks": 0, + + "Temp Read Blocks": 0, + + "Actual Total Time": 0.0, + + "Local Read Blocks": 0, + + "Shared Hit Blocks": 0, + + "Shared Read Blocks": 0, + + "Actual Startup Time": 0.0, + + "Parent Relationship": "Outer", + + "Temp Written Blocks": 0, + + "Local Dirtied Blocks": 0, + + "Local Written Blocks": 0, + + "Shared Dirtied Blocks": 0, + + "Shared Written Blocks": 0 + + } + + ], + + "Output": [ + + "unique1", + + "unique2", + + "two", + + "four", + + "ten", + + "twenty", + + "hundred", + + "thousand", + + "twothousand", + + "fivethous", + + "tenthous", + + "odd", + + "even", + + "stringu1", + + "stringu2", + + "string4" + + ], + + "Workers": [ + + { + + "Actual Rows": 0, + + "Actual Loops": 0, + + "Worker Number": 0, + + "Local Hit Blocks": 0, + + "Temp Read Blocks": 0, + + "Actual Total Time": 0.0, + + "Local Read Blocks": 0, + + "Shared Hit Blocks": 0, + + "Shared Read Blocks": 0, + + "Actual Startup Time": 0.0, + + "Temp Written Blocks": 0, + + "Local Dirtied Blocks": 0, + + "Local Written Blocks": 0, + + "Shared Dirtied Blocks": 0, + + "Shared Written Blocks": 0 + + }, + + { + + "Actual Rows": 0, + + "Actual Loops": 0, + + "Worker Number": 0, + + "Local Hit Blocks": 0, + + "Temp Read Blocks": 0, + + "Actual Total Time": 0.0, + + "Local Read Blocks": 0, + + "Shared Hit Blocks": 0, + + "Shared Read Blocks": 0, + + "Actual Startup Time": 0.0, + + "Temp Written Blocks": 0, + + "Local Dirtied Blocks": 0, + + "Local Written Blocks": 0, + + "Shared Dirtied Blocks": 0, + + "Shared Written Blocks": 0 + + }, + + { + + "Actual Rows": 0, + + "Actual Loops": 0, + + "Worker Number": 0, + + "Local Hit Blocks": 0, + + "Temp Read Blocks": 0, + + "Actual Total Time": 0.0, + + "Local Read Blocks": 0, + + "Shared Hit Blocks": 0, + + "Shared Read Blocks": 0, + + "Actual Startup Time": 0.0, + + "Temp Written Blocks": 0, + + "Local Dirtied Blocks": 0, + + "Local Written Blocks": 0, + + "Shared Dirtied Blocks": 0, + + "Shared Written Blocks": 0 + + }, + + { + + "Actual Rows": 0, + + "Actual Loops": 0, + + "Worker Number": 0, + + "Local Hit Blocks": 0, + + "Temp Read Blocks": 0, + + "Actual Total Time": 0.0, + + "Local Read Blocks": 0, + + "Shared Hit Blocks": 0, + + "Shared Read Blocks": 0, + + "Actual Startup Time": 0.0, + + "Temp Written Blocks": 0, + + "Local Dirtied Blocks": 0, + + "Local Written Blocks": 0, + + "Shared Dirtied Blocks": 0, + + "Shared Written Blocks": 0 + + } + + ], + + "Sort Key": [ + + "tenk1.tenthous" + + ], + + "Node Type": "Sort", + + "Plan Rows": 0, + + "Plan Width": 0, + + "Total Cost": 0.0, + + "Actual Rows": 0, + + "Actual Loops": 0, + + "Startup Cost": 0.0, + + "Async Capable": false, + + "Parallel Aware": false, + + "Sort Space Used": 0, + + "Workers planned": 0, + + "Local Hit Blocks": 0, + + "Temp Read Blocks": 0, + + "Actual Total Time": 0.0, + + "Local Read Blocks": 0, + + "Shared Hit Blocks": 0, + + "Shared Read Blocks": 0, + + "Actual Startup Time": 0.0, + + "Parent Relationship": "Outer", + + "Temp Written Blocks": 0, + + "Local Dirtied Blocks": 0, + + "Local Written Blocks": 0, + + "Shared Dirtied Blocks": 0, + + "Shared Written Blocks": 0 + + } + + ], + + "Output": [ + + "unique1", + + "unique2", + + "two", + + "four", + + "ten", + + "twenty", + + "hundred", + + "thousand", + + "twothousand", + + "fivethous", + + "tenthous", + + "odd", + + "even", + + "stringu1", + + "stringu2", + + "string4" + + ], + + "Node Type": "Gather Merge", + + "Plan Rows": 0, + + "Plan Width": 0, + + "Total Cost": 0.0, + + "Actual Rows": 0, + + "Actual Loops": 0, + + "Startup Cost": 0.0, + + "Async Capable": false, + + "Parallel Aware": false, + + "Workers Planned": 0, + + "Local Hit Blocks": 0, + + "Temp Read Blocks": 0, + + "Workers Launched": 0, + + "Actual Total Time": 0.0, + + "Local Read Blocks": 0, + + "Shared Hit Blocks": 0, + + "Shared Read Blocks": 0, + + "Actual Startup Time": 0.0, + + "Temp Written Blocks": 0, + + "Local Dirtied Blocks": 0, + + "Local Written Blocks": 0, + + "Shared Dirtied Blocks": 0, + + "Shared Written Blocks": 0 + + }, + + "Planning": { + + "Local Hit Blocks": 0, + + "Temp Read Blocks": 0, + + "Local Read Blocks": 0, + + "Shared Hit Blocks": 0, + + "Shared Read Blocks": 0, + + "Temp Written Blocks": 0, + + "Local Dirtied Blocks": 0, + + "Local Written Blocks": 0, + + "Shared Dirtied Blocks": 0, + + "Shared Written Blocks": 0 + + }, + + "Triggers": [ + + ], + + "Planning Time": 0.0, + + "Execution Time": 0.0 + + } + ] (1 row) @@ -505,3 +647,58 @@ select explain_filter('explain (verbose) select * from int8_tbl i8'); Query Identifier: N (3 rows) +-- Test sort stats summary +set force_parallel_mode=on; +select explain_filter('explain (analyze, summary off, timing off, costs off, format json) select * from tenk1 order by unique1'); + explain_filter +----------------------------------------------- + [ + + { + + "Plan": { + + "Node Type": "Gather", + + "Parallel Aware": false, + + "Async Capable": false, + + "Actual Rows": N, + + "Actual Loops": N, + + "Workers Planned": N, + + "Workers Launched": N, + + "Single Copy": true, + + "Plans": [ + + { + + "Node Type": "Sort", + + "Parent Relationship": "Outer", + + "Parallel Aware": false, + + "Async Capable": false, + + "Actual Rows": N, + + "Actual Loops": N, + + "Sort Key": ["unique1"], + + "Workers planned": N, + + "Sort Method": "external merge", + + "Average Sort Space Used": N, + + "Peak Sort Space Used": N, + + "Sort Space Type": "Disk", + + "Workers": [ + + ], + + "Plans": [ + + { + + "Node Type": "Seq Scan", + + "Parent Relationship": "Outer",+ + "Parallel Aware": false, + + "Async Capable": false, + + "Relation Name": "tenk1", + + "Alias": "tenk1", + + "Actual Rows": N, + + "Actual Loops": N, + + "Workers": [ + + ] + + } + + ] + + } + + ] + + }, + + "Triggers": [ + + ] + + } + + ] +(1 row) + diff --git a/src/test/regress/sql/explain.sql b/src/test/regress/sql/explain.sql index 5069fa8795..0306475910 100644 --- a/src/test/regress/sql/explain.sql +++ b/src/test/regress/sql/explain.sql @@ -101,10 +101,11 @@ set max_parallel_workers_per_gather=4; select jsonb_pretty( explain_filter_to_json('explain (analyze, verbose, buffers, format json) select * from tenk1 order by tenthous') - -- remove "Workers" node of the Seq Scan plan node - #- '{0,Plan,Plans,0,Plans,0,Workers}' - -- remove "Workers" node of the Sort plan node - #- '{0,Plan,Plans,0,Workers}' + -- remove "Workers planned" node of the Seq Scan plan node + #- '{0,Plan,Plans,0,Plans,0,Workers planned}' + -- remove "Sort Space" node of the Sort plan node + #- '{0,Plan,Plans,0,Average Sort Space Used}' + #- '{0,Plan,Plans,0,Peak Sort Space Used}' -- Also remove its sort-type fields, as those aren't 100% stable #- '{0,Plan,Plans,0,Sort Method}' #- '{0,Plan,Plans,0,Sort Space Type}' @@ -123,3 +124,7 @@ select explain_filter('explain (verbose) select * from t1 where pg_temp.mysin(f1 -- Test compute_query_id set compute_query_id = on; select explain_filter('explain (verbose) select * from int8_tbl i8'); + +-- Test sort stats summary +set force_parallel_mode=on; +select explain_filter('explain (analyze, summary off, timing off, costs off, format json) select * from tenk1 order by unique1'); \ No newline at end of file -- 2.35.1