From: Tom Lane <tgl@sss.pgh.pa.us>
To: Robert Haas <robertmhaas@gmail.com>
cc: pgsql-hackers@lists.postgresql.org
Subject: Re: force_parallel_mode = regress has a blind spot
In-reply-to: <18445.1576177309@sss.pgh.pa.us>
References: <18445.1576177309@sss.pgh.pa.us>
Comments: In-reply-to Tom Lane <tgl@sss.pgh.pa.us>
	message dated "Thu, 12 Dec 2019 14:01:49 -0500"
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="----- =_aaaaaaaaaa0"
Content-ID: <25789.1576437650.0@sss.pgh.pa.us>
Date: Sun, 15 Dec 2019 14:22:39 -0500
Message-ID: <25855.1576437759@sss.pgh.pa.us>
Precedence: bulk

------- =_aaaaaaaaaa0
Content-Type: text/plain; charset="us-ascii"
Content-ID: <25789.1576437650.1@sss.pgh.pa.us>

I wrote:
> I have just found out the hard way (cf commits 22864f6e0, 776a2c887)
> that if one uses EXPLAIN with both ANALYZE and VERBOSE selected,
> the output is not the same between force_parallel_mode = off and
> force_parallel_mode = regress.  This seems to me to be quite broken;
> what's the point of force_parallel_mode = regress if it doesn't
> produce the same output?
> The reason there's a problem is that ExplainNode() will show
> per-worker detail if both es->analyze and es->verbose are set,
> even when the only reason there's a worker process is that
> force_parallel_mode injected a supposedly-invisible Gather.
> I don't see any way to fix this that doesn't involve some sort
> of "action at a distance".  One could imagine hiding the per-worker
> detail if we're underneath a Gather that has invisible set to
> true, but it's not really clear to me that that would do the
> right things in a plan with multiple Gather nodes.  Any thoughts
> about that?

I took a closer look and decided that I was overthinking the problem.
The current implementation of hiding invisible Gathers only works for
a single Gather at the very top of the plan tree, so there's no need
for this adjustment to be smarter than that.  If we ever want to
relax that, it'll be time enough to consider the possibility of
hiding or not hiding workers in different parts of the tree.

For now, I propose the attached patch, which aside from fixing the
problem in 776a2c887 allows removal of a kluge in a different test case.

I'm not sure whether to back-patch this.  There seems no immediate
need to do so, but I wonder if someone might back-patch a test case
that depends on this fix.

			regards, tom lane


------- =_aaaaaaaaaa0
Content-Type: text/x-diff;
	name="ensure-invisible-Gathers-have-invisible-workers.patch";
	charset="us-ascii"
Content-ID: <25789.1576437650.2@sss.pgh.pa.us>
Content-Description: ensure-invisible-Gathers-have-invisible-workers.patch
Content-Transfer-Encoding: quoted-printable

diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain=
.c
index 7ae5a42..f763ba0 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -697,11 +697,15 @@ ExplainPrintPlan(ExplainState *es, QueryDesc *queryD=
esc)
 	 * Sometimes we mark a Gather node as "invisible", which means that it's
 	 * not displayed in EXPLAIN output.  The purpose of this is to allow
 	 * running regression tests with force_parallel_mode=3Dregress to get th=
e
-	 * same results as running the same tests with force_parallel_mode=3Doff=
.
+	 * same results as running the same tests with force_parallel_mode=3Doff=
. We
+	 * must also hide per-worker detail data further down in the plan tree.
 	 */
 	ps =3D queryDesc->planstate;
 	if (IsA(ps, GatherState) &&((Gather *) ps->plan)->invisible)
+	{
 		ps =3D outerPlanState(ps);
+		es->hide_workers =3D true;
+	}
 	ExplainNode(ps, NIL, NULL, NULL, es);
 =

 	/*
@@ -806,6 +810,10 @@ ExplainPrintJIT(ExplainState *es, int jit_flags,
 	if (!ji || ji->created_functions =3D=3D 0)
 		return;
 =

+	/* don't print per-worker info if we're supposed to hide that */
+	if (for_workers && es->hide_workers)
+		return;
+
 	/* calculate total time */
 	INSTR_TIME_SET_ZERO(total_time);
 	INSTR_TIME_ADD(total_time, ji->generation_counter);
@@ -1877,7 +1885,8 @@ ExplainNode(PlanState *planstate, List *ancestors,
 		show_buffer_usage(es, &planstate->instrument->bufusage);
 =

 	/* Show worker detail */
-	if (es->analyze && es->verbose && planstate->worker_instrument)
+	if (es->analyze && es->verbose && !es->hide_workers &&
+		planstate->worker_instrument)
 	{
 		WorkerInstrumentation *w =3D planstate->worker_instrument;
 		bool		opened_group =3D false;
@@ -2574,6 +2583,12 @@ show_sort_info(SortState *sortstate, ExplainState *=
es)
 		}
 	}
 =

+	/*
+	 * You might think we should just skip this stanza entirely when
+	 * es->hide_workers is true, but then we'd get no sort-method output at
+	 * all.  We have to make it look like worker 0's data is top-level data.
+	 * Currently, we only bother with that for text-format output.
+	 */
 	if (sortstate->shared_info !=3D NULL)
 	{
 		int			n;
@@ -2596,9 +2611,11 @@ show_sort_info(SortState *sortstate, ExplainState *=
es)
 			if (es->format =3D=3D EXPLAIN_FORMAT_TEXT)
 			{
 				appendStringInfoSpaces(es->str, es->indent * 2);
+				if (n > 0 || !es->hide_workers)
+					appendStringInfo(es->str, "Worker %d:  ", n);
 				appendStringInfo(es->str,
-								 "Worker %d:  Sort Method: %s  %s: %ldkB\n",
-								 n, sortMethod, spaceType, spaceUsed);
+								 "Sort Method: %s  %s: %ldkB\n",
+								 sortMethod, spaceType, spaceUsed);
 			}
 			else
 			{
diff --git a/src/include/commands/explain.h b/src/include/commands/explain=
.h
index 8639891..e4f4b70 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -46,6 +46,7 @@ typedef struct ExplainState
 	List	   *rtable_names;	/* alias names for RTEs */
 	List	   *deparse_cxt;	/* context list for deparsing expressions */
 	Bitmapset  *printed_subplans;	/* ids of SubPlans we've printed */
+	bool		hide_workers;	/* set if we find an invisible Gather */
 } ExplainState;
 =

 /* Hook for plugins to get control in ExplainOneQuery() */
diff --git a/src/test/regress/expected/partition_prune.out b/src/test/regr=
ess/expected/partition_prune.out
index 8219abc..424d51d 100644
--- a/src/test/regress/expected/partition_prune.out
+++ b/src/test/regress/expected/partition_prune.out
@@ -3163,12 +3163,12 @@ execute mt_q1(35);
 deallocate mt_q1;
 prepare mt_q2 (int) as select * from ma_test where a >=3D $1 order by b l=
imit 1;
 -- Ensure output list looks sane when the MergeAppend has no subplans.
-explain (verbose, costs off) execute mt_q2 (35);
-           QUERY PLAN           =

---------------------------------
- Limit
+explain (analyze, verbose, costs off, summary off, timing off) execute mt=
_q2 (35);
+                 QUERY PLAN                 =

+--------------------------------------------
+ Limit (actual rows=3D0 loops=3D1)
    Output: ma_test.a, ma_test.b
-   ->  Merge Append
+   ->  Merge Append (actual rows=3D0 loops=3D1)
          Sort Key: ma_test.b
          Subplans Removed: 3
 (5 rows)
diff --git a/src/test/regress/expected/subselect.out b/src/test/regress/ex=
pected/subselect.out
index ee9c5db..5476861 100644
--- a/src/test/regress/expected/subselect.out
+++ b/src/test/regress/expected/subselect.out
@@ -1166,8 +1166,6 @@ begin
         select * from (select pk,c2 from sq_limit order by c1,pk) as x li=
mit 3
     loop
         ln :=3D regexp_replace(ln, 'Memory: \S*',  'Memory: xxx');
-        -- this case might occur if force_parallel_mode is on:
-        ln :=3D regexp_replace(ln, 'Worker 0:  Sort Method',  'Sort Metho=
d');
         return next ln;
     end loop;
 end;
diff --git a/src/test/regress/sql/partition_prune.sql b/src/test/regress/s=
ql/partition_prune.sql
index 61ef6e6..d9daba3 100644
--- a/src/test/regress/sql/partition_prune.sql
+++ b/src/test/regress/sql/partition_prune.sql
@@ -841,7 +841,7 @@ deallocate mt_q1;
 prepare mt_q2 (int) as select * from ma_test where a >=3D $1 order by b l=
imit 1;
 =

 -- Ensure output list looks sane when the MergeAppend has no subplans.
-explain (verbose, costs off) execute mt_q2 (35);
+explain (analyze, verbose, costs off, summary off, timing off) execute mt=
_q2 (35);
 =

 deallocate mt_q2;
 =

diff --git a/src/test/regress/sql/subselect.sql b/src/test/regress/sql/sub=
select.sql
index 20c4f99..3e119ce 100644
--- a/src/test/regress/sql/subselect.sql
+++ b/src/test/regress/sql/subselect.sql
@@ -631,8 +631,6 @@ begin
         select * from (select pk,c2 from sq_limit order by c1,pk) as x li=
mit 3
     loop
         ln :=3D regexp_replace(ln, 'Memory: \S*',  'Memory: xxx');
-        -- this case might occur if force_parallel_mode is on:
-        ln :=3D regexp_replace(ln, 'Worker 0:  Sort Method',  'Sort Metho=
d');
         return next ln;
     end loop;
 end;

------- =_aaaaaaaaaa0--