I have updated the patch addressing the review comments, but I didn't moved this code block into VERBOSE mode, to keep consistency with `show_incremental_sort_info`:
https://github.com/postgres/postgres/blob/d4ba8b51c76300f06cc23f4d8a41d9f7210c4866/src/backend/commands/explain.c#L2890 Please review, thanks. ________________________________ From: Julien Rouhaud <rjuju...@gmail.com> Sent: Friday, March 25, 2022 17:04 To: Jian Guo <gj...@vmware.com> Cc: pgsql-hackers@lists.postgresql.org <pgsql-hackers@lists.postgresql.org>; Zhenghua Lyu <z...@vmware.com> Subject: Re: Summary Sort workers Stats in EXPLAIN ANALYZE ⚠ External Email Hi, On Thu, Mar 24, 2022 at 07:50:11AM +0000, Jian Guo wrote: > For a simple demo, with this explain statement: > > -- 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'); > > Before this patch, we got plan like this: > > > "Node Type": "Sort", + > "Parent Relationship": "Outer", + > "Parallel Aware": false, + > "Async Capable": false, + > "Actual Rows": 10000, + > "Actual Loops": 1, + > "Sort Key": ["unique1"], + > "Workers": [ + > { + > "Worker Number": 0, + > "Sort Method": "external merge",+ > "Sort Space Used": 2496, + > "Sort Space Type": "Disk" + > } + > ], + > After this patch, the effected plan is this: > > "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", + I think the idea is interesting, however there are a few problems in the patch. First, I think that it should only be done in the VERBOSE OFF mode. If you ask for a VERBOSE output you don't need both the details and the summarized version. Other minor problems: - why (only) emitting the number of workers planned and not the number of workers launched? - the textual format is missing details about what the numbers are, which is particularly obvious since avgSpaceUsed and peakSpaceUsed don't have any unit or even space between them: + "Sort Method: %s %s: " INT64_FORMAT INT64_FORMAT "kB\n", + sortMethod, spaceType, avgSpaceUsed, peakSpaceUsed); ________________________________ ⚠ External Email: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender.
From 578b9ce26c7ea1a13d6cf78d0848fa6a950bd82b 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 | 43 +-- src/test/regress/expected/explain.out | 522 ++++++++++++++++++-------- src/test/regress/sql/explain.sql | 13 +- 3 files changed, 390 insertions(+), 188 deletions(-) diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 9f632285b6..cdda0ac955 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -2758,40 +2758,41 @@ 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 Launched", 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 Average %s: " INT64_FORMAT "kB Peak %s: " INT64_FORMAT "kB\n", + sortMethod, spaceType, avgSpaceUsed, spaceType, 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..4f7431275e 100644 --- a/src/test/regress/expected/explain.out +++ b/src/test/regress/expected/explain.out @@ -312,173 +312,314 @@ 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 Launched" node of the Seq Scan plan node + #- '{0,Plan,Plans,0,Workers Launched}' + -- 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, + + "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 +646,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 Launched": 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..0a05787fe9 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 Launched" node of the Seq Scan plan node + #- '{0,Plan,Plans,0,Workers Launched}' + -- 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