From: Tom Lane <tgl@sss.pgh.pa.us>
To: Thomas Munro <thomas.munro@enterprisedb.com>
cc: Andres Freund <andres@anarazel.de>,
        pgsql-committers <pgsql-committers@postgresql.org>
Subject: Re: pgsql: Add parallel-aware hash joins.
In-reply-to: 
 <CAEepm=3GL7H3vxQb0LTJ9KnKhpnvaqOK=yn9p-O8zyjxRgXntA@mail.gmail.com>
References: <E1eRwXy-0004IK-TO@gemulon.postgresql.org>
 <20171221092940.gbxcszbzsr5khsfr@alap3.anarazel.de>
 <20171221095550.d3e7xhoakcowhu5b@alap3.anarazel.de>
 <CAEepm=3eS6ra8oBCYsYYjPNsPqb2R_TaGQK8SGRFq_7gbP8RUg@mail.gmail.com>
 <CAEepm=0WxwzpHVHt3PcWHBV=L3k3FDb6dvMq1A2Li49LGBa7TA@mail.gmail.com>
 <20171222082203.fl6rpzlqnm4h7h6h@alap3.anarazel.de>
 <CAEepm=04WhyY65BpE2g_8E==ayhBXjV9JbyR-+9N4McmY3SQkQ@mail.gmail.com>
 <30219.1514428346@sss.pgh.pa.us>
 <CAEepm=1OyZcCAxAEWYhmeg0qmWyYF2O2yW7s7A4uVTt-dgRRyQ@mail.gmail.com>
 <CAEepm=2H80cY=DncWKjoSiwaX=xbLcW7dqee+1H5-CQ6pJJnAQ@mail.gmail.com>
 <CAEepm=3GL7H3vxQb0LTJ9KnKhpnvaqOK=yn9p-O8zyjxRgXntA@mail.gmail.com>
Comments: In-reply-to Thomas Munro <thomas.munro@enterprisedb.com>
	message dated "Sun, 31 Dec 2017 02:51:26 +1300"
MIME-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-ID: <30654.1514673257.1@sss.pgh.pa.us>
Content-Transfer-Encoding: quoted-printable
Date: Sat, 30 Dec 2017 17:34:17 -0500
Message-ID: <30655.1514673257@sss.pgh.pa.us>
Precedence: bulk

Thomas Munro <thomas.munro@enterprisedb.com> writes:
>> This is explained by the early exit case in
>> ExecParallelHashEnsureBatchAccessors().  With just the right timing,
>> it finishes up not reporting the true nbatch number, and never calling
>> ExecParallelHashUpdateSpacePeak().

> Hi Tom,

> You mentioned that prairiedog sees the problem about one time in
> thirty.  Would you mind checking if it goes away with this patch
> applied?

I've run 55 cycles of "make installcheck" without seeing a failure
with this patch installed.  That's not enough to be totally sure
of course, but I think this probably fixes it.

However ... I noticed that my other dinosaur gaur shows the other failure
mode we see in the buildfarm, the "increased_batches =3D t" diff, and
I can report that this patch does *not* help that.  The underlying
EXPLAIN output goes from something like

!  Finalize Aggregate  (cost=3D823.85..823.86 rows=3D1 width=3D8) (actual =
time=3D1378.102..1378.105 rows=3D1 loops=3D1)
!    ->  Gather  (cost=3D823.63..823.84 rows=3D2 width=3D8) (actual time=3D=
1377.909..1378.006 rows=3D3 loops=3D1)
!          Workers Planned: 2
!          Workers Launched: 2
!          ->  Partial Aggregate  (cost=3D823.63..823.64 rows=3D1 width=3D=
8) (actual time=3D1280.298..1280.302 rows=3D1 loops=3D3)
!                ->  Parallel Hash Join  (cost=3D387.50..802.80 rows=3D833=
3 width=3D0) (actual time=3D1070.179..1249.142 rows=3D6667 loops=3D3)
!                      Hash Cond: (r.id =3D s.id)
!                      ->  Parallel Seq Scan on simple r  (cost=3D0.00..25=
0.33 rows=3D8333 width=3D4) (actual time=3D0.173..62.063 rows=3D6667 loops=
=3D3)
!                      ->  Parallel Hash  (cost=3D250.33..250.33 rows=3D83=
33 width=3D4) (actual time=3D454.305..454.305 rows=3D6667 loops=3D3)
!                            Buckets: 4096  Batches: 8  Memory Usage: 208k=
B
!                            ->  Parallel Seq Scan on simple s  (cost=3D0.=
00..250.33 rows=3D8333 width=3D4) (actual time=3D0.178..67.115 rows=3D6667=
 loops=3D3)
!  Planning time: 1.861 ms
!  Execution time: 1687.311 ms

to something like

!  Finalize Aggregate  (cost=3D823.85..823.86 rows=3D1 width=3D8) (actual =
time=3D1588.733..1588.737 rows=3D1 loops=3D1)
!    ->  Gather  (cost=3D823.63..823.84 rows=3D2 width=3D8) (actual time=3D=
1588.529..1588.634 rows=3D3 loops=3D1)
!          Workers Planned: 2
!          Workers Launched: 2
!          ->  Partial Aggregate  (cost=3D823.63..823.64 rows=3D1 width=3D=
8) (actual time=3D1492.631..1492.635 rows=3D1 loops=3D3)
!                ->  Parallel Hash Join  (cost=3D387.50..802.80 rows=3D833=
3 width=3D0) (actual time=3D1270.309..1451.501 rows=3D6667 loops=3D3)
!                      Hash Cond: (r.id =3D s.id)
!                      ->  Parallel Seq Scan on simple r  (cost=3D0.00..25=
0.33 rows=3D8333 width=3D4) (actual time=3D0.219..158.144 rows=3D6667 loop=
s=3D3)
!                      ->  Parallel Hash  (cost=3D250.33..250.33 rows=3D83=
33 width=3D4) (actual time=3D634.614..634.614 rows=3D6667 loops=3D3)
!                            Buckets: 4096 (originally 4096)  Batches: 16 =
(originally 8)  Memory Usage: 176kB
!                            ->  Parallel Seq Scan on simple s  (cost=3D0.=
00..250.33 rows=3D8333 width=3D4) (actual time=3D0.182..120.074 rows=3D666=
7 loops=3D3)
!  Planning time: 1.931 ms
!  Execution time: 2219.417 ms

so again we have a case where the plan didn't change but the execution
behavior did.  This isn't quite 100% reproducible on gaur/pademelon,
but it fails more often than not seems like, so I can poke into it
if you can say what info would be helpful.

			regards, tom lane