Thread

Commits

Update obsolete sentence in README.parallel.
- 28e04155f17c 11.0 cited
Rewrite ConditionVariableBroadcast() to avoid live-lock.
- aced5a92bf46 11.0 cited
Tweak parallel hash join test case in hopes of improving stability.
- 934c7986f4a0 11.0 landed
Rename pg_rewind's copy_file_range() to avoid conflict with new linux syscall.
- 3e68686e2c55 11.0 cited
Fix some minor errors in new PHJ code.
- 6fcde2406304 11.0 landed
Fix EXPLAIN ANALYZE output for Parallel Hash.
- 93ea78b17c47 11.0 landed
Fix rare assertion failure in parallel hash join.
- f83040c62a78 11.0 landed
Cancel CV sleep during subtransaction abort.
- f3decdc94ea3 10.2 landed
- 59d1e2b95a82 11.0 landed
Add parallel-aware hash joins.
- 1804284042e6 11.0 cited
Fix EXPLAIN ANALYZE of hash join when the leader doesn't participate.
- 5bcf389ecfd4 11.0 cited
Add some regression tests that exercise hash join code.
- fa330f9adf4e 11.0 cited

pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2017-12-21T08:49:46Z

Add parallel-aware hash joins.

Introduce parallel-aware hash joins that appear in EXPLAIN plans as Parallel
Hash Join with Parallel Hash.  While hash joins could already appear in
parallel queries, they were previously always parallel-oblivious and had a
partial subplan only on the outer side, meaning that the work of the inner
subplan was duplicated in every worker.

After this commit, the planner will consider using a partial subplan on the
inner side too, using the Parallel Hash node to divide the work over the
available CPU cores and combine its results in shared memory.  If the join
needs to be split into multiple batches in order to respect work_mem, then
workers process different batches as much as possible and then work together
on the remaining batches.

The advantages of a parallel-aware hash join over a parallel-oblivious hash
join used in a parallel query are that it:

 * avoids wasting memory on duplicated hash tables
 * avoids wasting disk space on duplicated batch files
 * divides the work of building the hash table over the CPUs

One disadvantage is that there is some communication between the participating
CPUs which might outweigh the benefits of parallelism in the case of small
hash tables.  This is avoided by the planner's existing reluctance to supply
partial plans for small scans, but it may be necessary to estimate
synchronization costs in future if that situation changes.  Another is that
outer batch 0 must be written to disk if multiple batches are required.

A potential future advantage of parallel-aware hash joins is that right and
full outer joins could be supported, since there is a single set of matched
bits for each hashtable, but that is not yet implemented.

A new GUC enable_parallel_hash is defined to control the feature, defaulting
to on.

Author: Thomas Munro
Reviewed-By: Andres Freund, Robert Haas
Tested-By: Rafia Sabih, Prabhat Sahu
Discussion:
    https://postgr.es/m/CAEepm=2W=cOkiZxcg6qiFQP-dHUe09aqTrEMM7yJDrHMhDv_RA@mail.gmail.com
    https://postgr.es/m/CAEepm=37HKyJ4U6XOLi=JgfSHM3o6B-GaeO-6hkOmneTDkH+Uw@mail.gmail.com

Branch
------
master

Details
-------
https://git.postgresql.org/pg/commitdiff/1804284042e659e7d16904e7bbb0ad546394b6a3

Modified Files
--------------
doc/src/sgml/config.sgml                      |   15 +
doc/src/sgml/monitoring.sgml                  |   62 +-
src/backend/executor/execParallel.c           |   21 +
src/backend/executor/execProcnode.c           |    3 +
src/backend/executor/nodeHash.c               | 1659 +++++++++++++++++++++++--
src/backend/executor/nodeHashjoin.c           |  617 ++++++++-
src/backend/nodes/copyfuncs.c                 |    1 +
src/backend/nodes/outfuncs.c                  |    1 +
src/backend/nodes/readfuncs.c                 |    1 +
src/backend/optimizer/path/costsize.c         |   25 +-
src/backend/optimizer/path/joinpath.c         |   36 +-
src/backend/optimizer/plan/createplan.c       |   11 +
src/backend/optimizer/util/pathnode.c         |    5 +-
src/backend/postmaster/pgstat.c               |   45 +
src/backend/utils/misc/guc.c                  |   10 +-
src/backend/utils/misc/postgresql.conf.sample |    1 +
src/include/executor/hashjoin.h               |  175 ++-
src/include/executor/nodeHash.h               |   24 +-
src/include/executor/nodeHashjoin.h           |    6 +
src/include/nodes/execnodes.h                 |    6 +
src/include/nodes/plannodes.h                 |    1 +
src/include/nodes/relation.h                  |    2 +
src/include/optimizer/cost.h                  |    4 +-
src/include/optimizer/pathnode.h              |    1 +
src/include/pgstat.h                          |   15 +
src/include/storage/lwlock.h                  |    1 +
src/test/regress/expected/join.out            |  304 ++++-
src/test/regress/expected/sysviews.out        |    3 +-
src/test/regress/sql/join.sql                 |  148 ++-
src/tools/pgindent/typedefs.list              |    4 +
30 files changed, 3091 insertions(+), 116 deletions(-)

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2017-12-21T09:29:40Z

On 2017-12-21 08:49:46 +0000, Andres Freund wrote:
> Add parallel-aware hash joins.

There's to relatively mundane failures:
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=tern&dt=2017-12-21%2008%3A48%3A12
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=termite&dt=2017-12-21%2008%3A50%3A08

but also one that's a lot more interesting:
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=capybara&dt=2017-12-21%2008%3A50%3A08

which shows an assert failure:

#2  0x00000000008687d1 in ExceptionalCondition (conditionName=conditionName@entry=0xa76a98 "!(!accessor->sts->participants[i].writing)", errorType=errorType@entry=0x8b2c49 "FailedAssertion", fileName=fileName@entry=0xa76991 "sharedtuplestore.c", lineNumber=lineNumber@entry=273) at assert.c:54
#3  0x000000000089883e in sts_begin_parallel_scan (accessor=0xfaf780) at sharedtuplestore.c:273
#4  0x0000000000634de4 in ExecParallelHashRepartitionRest (hashtable=0xfaec18) at nodeHash.c:1369
#5  ExecParallelHashIncreaseNumBatches (hashtable=0xfaec18) at nodeHash.c:1198
#6  0x000000000063546b in ExecParallelHashTupleAlloc (hashtable=hashtable@entry=0xfaec18, size=40, shared=shared@entry=0x7ffee26a8868) at nodeHash.c:2778
#7  0x00000000006357c8 in ExecParallelHashTableInsert (hashtable=hashtable@entry=0xfaec18, slot=slot@entry=0xfa76f8, hashvalue=<optimized out>) at nodeHash.c:1696
#8  0x0000000000635b5f in MultiExecParallelHash (node=0xf7ebc8) at nodeHash.c:288
#9  MultiExecHash (node=node@entry=0xf7ebc8) at nodeHash.c:112

which seems to suggest that something in the state machine logic is
borked. ExecParallelHashIncreaseNumBatches() should've ensured that
everyone has called sts_end_write()...

Greetings,

Andres Freund

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2017-12-21T09:54:44Z

On Thu, Dec 21, 2017 at 10:29 PM, Andres Freund <andres@anarazel.de> wrote:
> On 2017-12-21 08:49:46 +0000, Andres Freund wrote:
>> Add parallel-aware hash joins.
>
> There's to relatively mundane failures:
> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=tern&dt=2017-12-21%2008%3A48%3A12
> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=termite&dt=2017-12-21%2008%3A50%3A08

Right, it looks like something takes more space on ppc systems causing
a batch increase that doesn't happen on amd64.  I'll come back to
that.

> but also one that's a lot more interesting:
> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=capybara&dt=2017-12-21%2008%3A50%3A08
>
> which shows an assert failure:
>
> #2  0x00000000008687d1 in ExceptionalCondition (conditionName=conditionName@entry=0xa76a98 "!(!accessor->sts->participants[i].writing)", errorType=errorType@entry=0x8b2c49 "FailedAssertion", fileName=fileName@entry=0xa76991 "sharedtuplestore.c", lineNumber=lineNumber@entry=273) at assert.c:54
> #3  0x000000000089883e in sts_begin_parallel_scan (accessor=0xfaf780) at sharedtuplestore.c:273
> #4  0x0000000000634de4 in ExecParallelHashRepartitionRest (hashtable=0xfaec18) at nodeHash.c:1369
> #5  ExecParallelHashIncreaseNumBatches (hashtable=0xfaec18) at nodeHash.c:1198
> #6  0x000000000063546b in ExecParallelHashTupleAlloc (hashtable=hashtable@entry=0xfaec18, size=40, shared=shared@entry=0x7ffee26a8868) at nodeHash.c:2778
> #7  0x00000000006357c8 in ExecParallelHashTableInsert (hashtable=hashtable@entry=0xfaec18, slot=slot@entry=0xfa76f8, hashvalue=<optimized out>) at nodeHash.c:1696
> #8  0x0000000000635b5f in MultiExecParallelHash (node=0xf7ebc8) at nodeHash.c:288
> #9  MultiExecHash (node=node@entry=0xf7ebc8) at nodeHash.c:112
>
> which seems to suggest that something in the state machine logic is
> borked. ExecParallelHashIncreaseNumBatches() should've ensured that
> everyone has called sts_end_write()...

Hmm.  This looks the same as the one-off single assertion failure that
I mentioned[1] and had not been able to reproduce.  Investigating.

[1] https://www.postgresql.org/message-id/CAEepm%3D0oE%3DyO0Kam86W1d-iJoasWByYkcrkDoJu6t5mRhFGHkQ%40mail.gmail.com

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2017-12-21T09:55:50Z

On 2017-12-21 01:29:40 -0800, Andres Freund wrote:
> On 2017-12-21 08:49:46 +0000, Andres Freund wrote:
> > Add parallel-aware hash joins.
> 
> There's to relatively mundane failures:
> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=tern&dt=2017-12-21%2008%3A48%3A12
> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=termite&dt=2017-12-21%2008%3A50%3A08
> 
> but also one that's a lot more interesting:
> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=capybara&dt=2017-12-21%2008%3A50%3A08
> 
> which shows an assert failure:
> 
> #2  0x00000000008687d1 in ExceptionalCondition (conditionName=conditionName@entry=0xa76a98 "!(!accessor->sts->participants[i].writing)", errorType=errorType@entry=0x8b2c49 "FailedAssertion", fileName=fileName@entry=0xa76991 "sharedtuplestore.c", lineNumber=lineNumber@entry=273) at assert.c:54
> #3  0x000000000089883e in sts_begin_parallel_scan (accessor=0xfaf780) at sharedtuplestore.c:273
> #4  0x0000000000634de4 in ExecParallelHashRepartitionRest (hashtable=0xfaec18) at nodeHash.c:1369
> #5  ExecParallelHashIncreaseNumBatches (hashtable=0xfaec18) at nodeHash.c:1198
> #6  0x000000000063546b in ExecParallelHashTupleAlloc (hashtable=hashtable@entry=0xfaec18, size=40, shared=shared@entry=0x7ffee26a8868) at nodeHash.c:2778
> #7  0x00000000006357c8 in ExecParallelHashTableInsert (hashtable=hashtable@entry=0xfaec18, slot=slot@entry=0xfa76f8, hashvalue=<optimized out>) at nodeHash.c:1696
> #8  0x0000000000635b5f in MultiExecParallelHash (node=0xf7ebc8) at nodeHash.c:288
> #9  MultiExecHash (node=node@entry=0xf7ebc8) at nodeHash.c:112
> 
> which seems to suggest that something in the state machine logic is
> borked. ExecParallelHashIncreaseNumBatches() should've ensured that
> everyone has called sts_end_write()...

Thomas, I wonder if the problem is that PHJ_GROW_BATCHES_ELECTING
updates, via ExecParallelHashJoinSetUpBatches(), HashJoinTable->nbatch,
while other backends also access ->nbatch in
ExecParallelHashCloseBatchAccessors(). Both happens after waiting for
the WAIT_EVENT_HASH_GROW_BATCHES_ELECTING phase.

That'd lead to ExecParallelHashCloseBatchAccessors() likely not finish
writing all batches (because nbatch < nbatch_old), which seems like it'd
explain this?

Greetings,

Andres Freund

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2017-12-21T10:42:25Z

On 2017-12-21 01:55:50 -0800, Andres Freund wrote:
> On 2017-12-21 01:29:40 -0800, Andres Freund wrote:
> > On 2017-12-21 08:49:46 +0000, Andres Freund wrote:
> > > Add parallel-aware hash joins.
> >
> > There's to relatively mundane failures:
> > https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=tern&dt=2017-12-21%2008%3A48%3A12
> > https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=termite&dt=2017-12-21%2008%3A50%3A08
> >
> > but also one that's a lot more interesting:
> > https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=capybara&dt=2017-12-21%2008%3A50%3A08
> >
> > which shows an assert failure:
> >
> > #2  0x00000000008687d1 in ExceptionalCondition (conditionName=conditionName@entry=0xa76a98 "!(!accessor->sts->participants[i].writing)", errorType=errorType@entry=0x8b2c49 "FailedAssertion", fileName=fileName@entry=0xa76991 "sharedtuplestore.c", lineNumber=lineNumber@entry=273) at assert.c:54
> > #3  0x000000000089883e in sts_begin_parallel_scan (accessor=0xfaf780) at sharedtuplestore.c:273
> > #4  0x0000000000634de4 in ExecParallelHashRepartitionRest (hashtable=0xfaec18) at nodeHash.c:1369
> > #5  ExecParallelHashIncreaseNumBatches (hashtable=0xfaec18) at nodeHash.c:1198
> > #6  0x000000000063546b in ExecParallelHashTupleAlloc (hashtable=hashtable@entry=0xfaec18, size=40, shared=shared@entry=0x7ffee26a8868) at nodeHash.c:2778
> > #7  0x00000000006357c8 in ExecParallelHashTableInsert (hashtable=hashtable@entry=0xfaec18, slot=slot@entry=0xfa76f8, hashvalue=<optimized out>) at nodeHash.c:1696
> > #8  0x0000000000635b5f in MultiExecParallelHash (node=0xf7ebc8) at nodeHash.c:288
> > #9  MultiExecHash (node=node@entry=0xf7ebc8) at nodeHash.c:112
> >
> > which seems to suggest that something in the state machine logic is
> > borked. ExecParallelHashIncreaseNumBatches() should've ensured that
> > everyone has called sts_end_write()...

> Thomas, I wonder if the problem is that PHJ_GROW_BATCHES_ELECTING
> updates, via ExecParallelHashJoinSetUpBatches(), HashJoinTable->nbatch,
> while other backends also access ->nbatch in
> ExecParallelHashCloseBatchAccessors(). Both happens after waiting for
> the WAIT_EVENT_HASH_GROW_BATCHES_ELECTING phase.
>
> That'd lead to ExecParallelHashCloseBatchAccessors() likely not finish
> writing all batches (because nbatch < nbatch_old), which seems like it'd
> explain this?

Trying to debug this I found another issue. I'd placed a sleep(10) in
ExecParallelHashCloseBatchAccessors() and then ctrl-c'ed the server for
some reason. Segfault time:

#0  0x000055bfbac42539 in tas (lock=0x7fcd82ae14ac <error: Cannot access memory at address 0x7fcd82ae14ac>) at /home/andres/src/postgresql/src/include/storage/s_lock.h:228
#1  0x000055bfbac42b4d in ConditionVariableCancelSleep () at /home/andres/src/postgresql/src/backend/storage/lmgr/condition_variable.c:173
#2  0x000055bfba8e24ae in AbortTransaction () at /home/andres/src/postgresql/src/backend/access/transam/xact.c:2478
#3  0x000055bfba8e4a2a in AbortOutOfAnyTransaction () at /home/andres/src/postgresql/src/backend/access/transam/xact.c:4387
#4  0x000055bfba91ed97 in RemoveTempRelationsCallback (code=1, arg=0) at /home/andres/src/postgresql/src/backend/catalog/namespace.c:4034
#5  0x000055bfbac1bc90 in shmem_exit (code=1) at /home/andres/src/postgresql/src/backend/storage/ipc/ipc.c:228
#6  0x000055bfbac1bb67 in proc_exit_prepare (code=1) at /home/andres/src/postgresql/src/backend/storage/ipc/ipc.c:185
#7  0x000055bfbac1bacf in proc_exit (code=1) at /home/andres/src/postgresql/src/backend/storage/ipc/ipc.c:102
#8  0x000055bfbadbccf0 in errfinish (dummy=0) at /home/andres/src/postgresql/src/backend/utils/error/elog.c:543
#9  0x000055bfbac4eda3 in ProcessInterrupts () at /home/andres/src/postgresql/src/backend/tcop/postgres.c:2917
#10 0x000055bfbac42a63 in ConditionVariableSleep (cv=0x7fcd82ae14ac, wait_event_info=134217742) at /home/andres/src/postgresql/src/backend/storage/lmgr/condition_variable.c:129
#11 0x000055bfbac18405 in BarrierArriveAndWait (barrier=0x7fcd82ae1494, wait_event_info=134217742) at /home/andres/src/postgresql/src/backend/storage/ipc/barrier.c:191
#12 0x000055bfbaa9361e in ExecParallelHashIncreaseNumBatches (hashtable=0x55bfbd0e11d0) at /home/andres/src/postgresql/src/backend/executor/nodeHash.c:1191
#13 0x000055bfbaa962ef in ExecParallelHashTupleAlloc (hashtable=0x55bfbd0e11d0, size=40, shared=0x7ffda8967050) at /home/andres/src/postgresql/src/backend/executor/nodeHash.c:2781
#14 0x000055bfbaa946e8 in ExecParallelHashTableInsert (hashtable=0x55bfbd0e11d0, slot=0x55bfbd089a80, hashvalue=3825063138) at /home/andres/src/postgresql/src/backend/executor/nodeHash.c:1699
#15 0x000055bfbaa91d90 in MultiExecParallelHash (node=0x55bfbd089610) at /home/andres/src/postgresql/src/backend/executor/nodeHash.c:288
#16 0x000055bfbaa919b9 in MultiExecHash (node=0x55bfbd089610) at /home/andres/src/postgresql/src/backend/executor/nodeHash.c:112
#17 0x000055bfbaa7a500 in MultiExecProcNode (node=0x55bfbd089610) at /home/andres/src/postgresql/src/backend/executor/execProcnode.c:502
#18 0x000055bfbaa98515 in ExecHashJoinImpl (parallel=1 '\001', pstate=0x55bfbd053d50) at /home/andres/src/postgresql/src/backend/executor/nodeHashjoin.c:291
#19 ExecParallelHashJoin (pstate=0x55bfbd053d50) at /home/andres/src/postgresql/src/backend/executor/nodeHashjoin.c:582
#20 0x000055bfbaa7a424 in ExecProcNodeFirst (node=0x55bfbd053d50) at /home/andres/src/postgresql/src/backend/executor/execProcnode.c:446
#21 0x000055bfbaa858c7 in ExecProcNode (node=0x55bfbd053d50) at /home/andres/src/postgresql/src/include/executor/executor.h:242
#22 0x000055bfbaa85d67 in fetch_input_tuple (aggstate=0x55bfbd053698) at /home/andres/src/postgresql/src/backend/executor/nodeAgg.c:699
#23 0x000055bfbaa889b5 in agg_retrieve_direct (aggstate=0x55bfbd053698) at /home/andres/src/postgresql/src/backend/executor/nodeAgg.c:2355
#24 0x000055bfbaa8858e in ExecAgg (pstate=0x55bfbd053698) at /home/andres/src/postgresql/src/backend/executor/nodeAgg.c:2166
#25 0x000055bfbaa7a424 in ExecProcNodeFirst (node=0x55bfbd053698) at /home/andres/src/postgresql/src/backend/executor/execProcnode.c:446
#26 0x000055bfbaa90a4e in ExecProcNode (node=0x55bfbd053698) at /home/andres/src/postgresql/src/include/executor/executor.h:242
#27 0x000055bfbaa910d5 in gather_getnext (gatherstate=0x55bfbd053340) at /home/andres/src/postgresql/src/backend/executor/nodeGather.c:285
#28 0x000055bfbaa90f5f in ExecGather (pstate=0x55bfbd053340) at /home/andres/src/postgresql/src/backend/executor/nodeGather.c:216
#29 0x000055bfbaa7a424 in ExecProcNodeFirst (node=0x55bfbd053340) at /home/andres/src/postgresql/src/backend/executor/execProcnode.c:446
#30 0x000055bfbaa858c7 in ExecProcNode (node=0x55bfbd053340) at /home/andres/src/postgresql/src/include/executor/executor.h:242
#31 0x000055bfbaa85d67 in fetch_input_tuple (aggstate=0x55bfbd052c18) at /home/andres/src/postgresql/src/backend/executor/nodeAgg.c:699
#32 0x000055bfbaa889b5 in agg_retrieve_direct (aggstate=0x55bfbd052c18) at /home/andres/src/postgresql/src/backend/executor/nodeAgg.c:2355
#33 0x000055bfbaa8858e in ExecAgg (pstate=0x55bfbd052c18) at /home/andres/src/postgresql/src/backend/executor/nodeAgg.c:2166
#34 0x000055bfbaa7a424 in ExecProcNodeFirst (node=0x55bfbd052c18) at /home/andres/src/postgresql/src/backend/executor/execProcnode.c:446
#35 0x000055bfbaa716c6 in ExecProcNode (node=0x55bfbd052c18) at /home/andres/src/postgresql/src/include/executor/executor.h:242
#36 0x000055bfbaa7404e in ExecutePlan (estate=0x55bfbd0529c8, planstate=0x55bfbd052c18, use_parallel_mode=1 '\001', operation=CMD_SELECT, sendTuples=1 '\001', numberTuples=0, direction=ForwardScanDirection, dest=0x55bfbd121ae0, execute_once=1 '\001')
    at /home/andres/src/postgresql/src/backend/executor/execMain.c:1718
#37 0x000055bfbaa71cba in standard_ExecutorRun (queryDesc=0x55bfbcf0fe68, direction=ForwardScanDirection, count=0, execute_once=1 '\001') at /home/andres/src/postgresql/src/backend/executor/execMain.c:361
#38 0x000055bfbaa71ad4 in ExecutorRun (queryDesc=0x55bfbcf0fe68, direction=ForwardScanDirection, count=0, execute_once=1 '\001') at /home/andres/src/postgresql/src/backend/executor/execMain.c:304
#39 0x000055bfbac52725 in PortalRunSelect (portal=0x55bfbcf56a48, forward=1 '\001', count=0, dest=0x55bfbd121ae0) at /home/andres/src/postgresql/src/backend/tcop/pquery.c:932
#40 0x000055bfbac523b8 in PortalRun (portal=0x55bfbcf56a48, count=9223372036854775807, isTopLevel=1 '\001', run_once=1 '\001', dest=0x55bfbd121ae0, altdest=0x55bfbd121ae0, completionTag=0x7ffda8967840 "") at /home/andres/src/postgresql/src/backend/tcop/pquery.c:773
#41 0x000055bfbac4c0a1 in exec_simple_query (query_string=0x55bfbceefaf8 "select count(*) from simple r join bigger_than_it_looks s using (id);") at /home/andres/src/postgresql/src/backend/tcop/postgres.c:1120
#42 0x000055bfbac505e4 in PostgresMain (argc=1, argv=0x55bfbcf1d178, dbname=0x55bfbcf1cf30 "regression", username=0x55bfbceec588 "andres") at /home/andres/src/postgresql/src/backend/tcop/postgres.c:4139
#43 0x000055bfbabac375 in BackendRun (port=0x55bfbcf120f0) at /home/andres/src/postgresql/src/backend/postmaster/postmaster.c:4412
#44 0x000055bfbababa74 in BackendStartup (port=0x55bfbcf120f0) at /home/andres/src/postgresql/src/backend/postmaster/postmaster.c:4084
#45 0x000055bfbaba7d49 in ServerLoop () at /home/andres/src/postgresql/src/backend/postmaster/postmaster.c:1757
#46 0x000055bfbaba72d2 in PostmasterMain (argc=39, argv=0x55bfbcee9e90) at /home/andres/src/postgresql/src/backend/postmaster/postmaster.c:1365
#47 0x000055bfbaadb49d in main (argc=39, argv=0x55bfbcee9e90) at /home/andres/src/postgresql/src/backend/main/main.c:228

So, afaics no workers had yet attached, the leader accepted the cancel
interrupt, the dsm segments were destroyed, and as part of cleanup
cv_sleep_target was supposed to be reset, which fails, because it's
memory has since been freed.   Looking at how that can happen.

Greetings,

Andres Freund

condition variable cleanup and subtransactions

Andres Freund <andres@anarazel.de> — 2017-12-21T11:00:48Z

Hi,

On 2017-12-21 02:42:25 -0800, Andres Freund wrote:
> Trying to debug this I found another issue. I'd placed a sleep(10) in
> ExecParallelHashCloseBatchAccessors() and then ctrl-c'ed the server for
> some reason. Segfault time:
> 
> #0  0x000055bfbac42539 in tas (lock=0x7fcd82ae14ac <error: Cannot access memory at address 0x7fcd82ae14ac>) at /home/andres/src/postgresql/src/include/storage/s_lock.h:228
> #1  0x000055bfbac42b4d in ConditionVariableCancelSleep () at /home/andres/src/postgresql/src/backend/storage/lmgr/condition_variable.c:173
> #2  0x000055bfba8e24ae in AbortTransaction () at /home/andres/src/postgresql/src/backend/access/transam/xact.c:2478
> #3  0x000055bfba8e4a2a in AbortOutOfAnyTransaction () at /home/andres/src/postgresql/src/backend/access/transam/xact.c:4387

> So, afaics no workers had yet attached, the leader accepted the cancel
> interrupt, the dsm segments were destroyed, and as part of cleanup
> cv_sleep_target was supposed to be reset, which fails, because it's
> memory has since been freed.   Looking at how that can happen.

Oh. This seems to be a condition variable bug independent of PHJ. The
problem is that the DSM segment etc all get cleaned up in
*subtransaction* abort.

Afaict it's a bug that AbortTransaction() does
ConditionVariableCancelSleep() but AbortSubTransaction() does not,
despite the latter releasing dsm segments via
ResourceOwnerRelease(RESOURCE_RELEASE_BEFORE_LOCKS).

Adding that seems to fix the crash.

This seems like something we need to backpatch.

Greetings,

Andres Freund

Re: condition variable cleanup and subtransactions

Thomas Munro <thomas.munro@enterprisedb.com> — 2017-12-21T11:46:09Z

On Fri, Dec 22, 2017 at 12:00 AM, Andres Freund <andres@anarazel.de> wrote:
> Oh. This seems to be a condition variable bug independent of PHJ. The
> problem is that the DSM segment etc all get cleaned up in
> *subtransaction* abort.
>
> Afaict it's a bug that AbortTransaction() does
> ConditionVariableCancelSleep() but AbortSubTransaction() does not,
> despite the latter releasing dsm segments via
> ResourceOwnerRelease(RESOURCE_RELEASE_BEFORE_LOCKS).
>
> Adding that seems to fix the crash.
>
> This seems like something we need to backpatch.

Agreed.  That affects any user of condition variables inside DSM
segments, including the released Parallel Index Scan and Parallel
Bitmap Heap Scan code.

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2017-12-21T12:48:59Z

On Thu, Dec 21, 2017 at 10:55 PM, Andres Freund <andres@anarazel.de> wrote:
> Thomas, I wonder if the problem is that PHJ_GROW_BATCHES_ELECTING
> updates, via ExecParallelHashJoinSetUpBatches(), HashJoinTable->nbatch,
> while other backends also access ->nbatch in
> ExecParallelHashCloseBatchAccessors(). Both happens after waiting for
> the WAIT_EVENT_HASH_GROW_BATCHES_ELECTING phase.
>
> That'd lead to ExecParallelHashCloseBatchAccessors() likely not finish
> writing all batches (because nbatch < nbatch_old), which seems like it'd
> explain this?

I don't think that's quite it, because it should never have set
'writing' for any batch number >= nbatch.

It's late here, but I'll take this up tomorrow and either find a fix
or figure out how to avoid antisocial noise levels on the build farm
in the meantime.

-- 
Thomas Munro
http://www.enterprisedb.com

Re: condition variable cleanup and subtransactions

Robert Haas <robertmhaas@gmail.com> — 2017-12-21T14:25:27Z

On Thu, Dec 21, 2017 at 6:46 AM, Thomas Munro
<thomas.munro@enterprisedb.com> wrote:
> On Fri, Dec 22, 2017 at 12:00 AM, Andres Freund <andres@anarazel.de> wrote:
>> Oh. This seems to be a condition variable bug independent of PHJ. The
>> problem is that the DSM segment etc all get cleaned up in
>> *subtransaction* abort.
>>
>> Afaict it's a bug that AbortTransaction() does
>> ConditionVariableCancelSleep() but AbortSubTransaction() does not,
>> despite the latter releasing dsm segments via
>> ResourceOwnerRelease(RESOURCE_RELEASE_BEFORE_LOCKS).
>>
>> Adding that seems to fix the crash.
>>
>> This seems like something we need to backpatch.
>
> Agreed.  That affects any user of condition variables inside DSM
> segments, including the released Parallel Index Scan and Parallel
> Bitmap Heap Scan code.

Fixed.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2017-12-21T16:11:44Z

Andres Freund <andres@anarazel.de> writes:
> On 2017-12-21 08:49:46 +0000, Andres Freund wrote:
>> Add parallel-aware hash joins.

> There's to relatively mundane failures:
> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=tern&dt=2017-12-21%2008%3A48%3A12
> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=termite&dt=2017-12-21%2008%3A50%3A08

> [ as well as various assertion crashes ]

I see my machine prairiedog is showing yet another variation, possibly
related to the tern/termite failure, but not the same:

================= pgsql.build/src/test/regress/regression.diffs ===================
*** /Users/buildfarm/bf-data/HEAD/pgsql.build/src/test/regress/expected/join.out	Thu Dec 21 03:55:15 2017
--- /Users/buildfarm/bf-data/HEAD/pgsql.build/src/test/regress/results/join.out	Thu Dec 21 10:56:00 2017
***************
*** 6682,6688 ****
  $$);
   multibatch 
  ------------
!  t
  (1 row)
  
  rollback to settings;
--- 6682,6688 ----
  $$);
   multibatch 
  ------------
!  f
  (1 row)
  
  rollback to settings;

======================================================================

Let me know if you need me to poke into that.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2017-12-22T08:16:10Z

On Fri, Dec 22, 2017 at 1:48 AM, Thomas Munro
<thomas.munro@enterprisedb.com> wrote:
> I don't think that's quite it, because it should never have set
> 'writing' for any batch number >= nbatch.
>
> It's late here, but I'll take this up tomorrow and either find a fix
> or figure out how to avoid antisocial noise levels on the build farm
> in the meantime.

Not there yet but I learned some things and am still working on it.  I
spent a lot of time trying to reproduce the assertion failure, and
succeeded exactly once.  Unfortunately the one time I managed do to
that I'd built with clang -O2 and got a core file that I couldn't get
much useful info out of, and I've been trying to do it again with -O0
ever since without luck.  The time I succeeded, I reproduced it by
creating the tables "simple" and "bigger_than_it_looks" from join.sql
and then doing this in a loop:

  set min_parallel_table_scan_size = 0;
  set parallel_setup_cost = 0;
  set work_mem = '192kB';

  explain analyze select count(*) from simple r join
bigger_than_it_looks s using (id);

The machine that it happened on is resource constrained, and exhibits
another problem: though the above query normally runs in ~20ms,
sometimes it takes several seconds and occasionally much longer.  That
never happens on fast development systems or test servers which run it
quickly every time, and it doesn't happen on my 2 core slow system if
I have only two workers (or one worker + leader).  I dug into that and
figured out what was going wrong and wrote that up separately[1],
because I think it's an independent bug needing to be fixed, not the
root cause here.  However, I think it could easily be contributing to
the timing required to trigger the bug we're looking for.

Andres, your machine francolin crashed -- got a core file?

[1] https://www.postgresql.org/message-id/CAEepm%3D0NWKehYw7NDoUSf8juuKOPRnCyY3vuaSvhrEWsOTAa3w%40mail.gmail.com

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2017-12-22T08:22:03Z

Hi,

On 2017-12-22 21:16:10 +1300, Thomas Munro wrote:
> Andres, your machine francolin crashed -- got a core file?

Unfortunately not - it appears the buildfarm cleared it away :(

Might try to reproduce it on that machine...

Greetings,

Andres Freund

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2017-12-26T10:48:37Z

On Fri, Dec 22, 2017 at 9:22 PM, Andres Freund <andres@anarazel.de> wrote:
> On 2017-12-22 21:16:10 +1300, Thomas Munro wrote:
>> Andres, your machine francolin crashed -- got a core file?
>
> Unfortunately not - it appears the buildfarm cleared it away :(

I now have a workload that fails within a few minutes or so on master.
I see the problem: MultiExecParallelHash() needs to run
sts_end_write() *before* detaching from grow_batches_barrier.  My test
case doesn't fail with the attached patch applied.

I'll address the instability of the regression test output separately.
Sorry for the delay, due to the time of year.

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2017-12-28T02:32:26Z

Thomas Munro <thomas.munro@enterprisedb.com> writes:
> I'll address the instability of the regression test output separately.

If you're still looking for data on that --- prairiedog is able to
reproduce the "multibatch = f" variant about one time in thirty.
I modified the test case to print out the full EXPLAIN ANALYZE output
rather than a heavily filtered version.  Here's a typical successful run:

! explain analyze
    select length(max(s.t))
    from wide left join (select id, coalesce(t, '') || '' as t from wide) s using (id);
!                                                                    QUERY PLAN                                                                   
! ------------------------------------------------------------------------------------------------------------------------------------------------
!  Finalize Aggregate  (cost=97.49..97.51 rows=1 width=4) (actual time=409.330..409.331 rows=1 loops=1)
!    ->  Gather  (cost=97.28..97.49 rows=2 width=32) (actual time=376.957..395.841 rows=3 loops=1)
!          Workers Planned: 2
!          Workers Launched: 2
!          ->  Partial Aggregate  (cost=97.28..97.29 rows=1 width=32) (actual time=254.370..254.373 rows=1 loops=3)
!                ->  Parallel Hash Left Join  (cost=23.23..88.88 rows=3360 width=32) (actual time=240.812..241.297 rows=1 loops=3)
!                      Hash Cond: (wide.id = wide_1.id)
!                      ->  Parallel Seq Scan on wide  (cost=0.00..15.29 rows=529 width=4) (actual time=0.066..0.075 rows=1 loops=3)
!                      ->  Parallel Hash  (cost=16.61..16.61 rows=529 width=36) (actual time=109.565..109.565 rows=1 loops=3)
!                            Buckets: 1024 (originally 2048)  Batches: 8 (originally 1)  Memory Usage: 321kB
!                            ->  Parallel Seq Scan on wide wide_1  (cost=0.00..16.61 rows=529 width=36) (actual time=2.989..7.218 rows=1 loops=3)
!  Planning time: 1.317 ms
!  Execution time: 424.395 ms
! (13 rows)

and here's a failing run:

! explain analyze
    select length(max(s.t))
    from wide left join (select id, coalesce(t, '') || '' as t from wide) s using (id);
!                                                                    QUERY PLAN                                                                    
! -------------------------------------------------------------------------------------------------------------------------------------------------
!  Finalize Aggregate  (cost=97.49..97.51 rows=1 width=4) (actual time=232.440..232.441 rows=1 loops=1)
!    ->  Gather  (cost=97.28..97.49 rows=2 width=32) (actual time=225.738..226.744 rows=3 loops=1)
!          Workers Planned: 2
!          Workers Launched: 2
!          ->  Partial Aggregate  (cost=97.28..97.29 rows=1 width=32) (actual time=29.377..29.379 rows=1 loops=3)
!                ->  Parallel Hash Left Join  (cost=23.23..88.88 rows=3360 width=32) (actual time=22.747..25.340 rows=1 loops=3)
!                      Hash Cond: (wide.id = wide_1.id)
!                      ->  Parallel Seq Scan on wide  (cost=0.00..15.29 rows=529 width=4) (actual time=0.086..0.113 rows=2 loops=1)
!                      ->  Parallel Hash  (cost=16.61..16.61 rows=529 width=36) (actual time=16.382..16.382 rows=1 loops=3)
!                            Buckets: 1024 (originally 2048)  Batches: 1 (originally 1)  Memory Usage: 0kB
!                            ->  Parallel Seq Scan on wide wide_1  (cost=0.00..16.61 rows=529 width=36) (actual time=9.167..21.301 rows=2 loops=1)
!  Planning time: 1.289 ms
!  Execution time: 243.120 ms
! (13 rows)
  
I don't have enough insight to be totally sure what this means, but the
"Memory Usage: 0kB" bit is obviously bogus, so I'd venture that at least
part of the issue is failure to return stats from a worker.  I also find
it most curious that the "success" case is a lot slower than the "not
success" case.  Perhaps this is related to your livelock issue?  Doing
another run, I get something even slower:

! explain analyze
    select length(max(s.t))
    from wide left join (select id, coalesce(t, '') || '' as t from wide) s using (id);
!                                                                    QUERY PLAN                                                                    
! -------------------------------------------------------------------------------------------------------------------------------------------------
!  Finalize Aggregate  (cost=97.49..97.51 rows=1 width=4) (actual time=487.245..487.246 rows=1 loops=1)
!    ->  Gather  (cost=97.28..97.49 rows=2 width=32) (actual time=444.650..475.390 rows=3 loops=1)
!          Workers Planned: 2
!          Workers Launched: 2
!          ->  Partial Aggregate  (cost=97.28..97.29 rows=1 width=32) (actual time=345.816..345.819 rows=1 loops=3)
!                ->  Parallel Hash Left Join  (cost=23.23..88.88 rows=3360 width=32) (actual time=334.229..338.098 rows=1 loops=3)
!                      Hash Cond: (wide.id = wide_1.id)
!                      ->  Parallel Seq Scan on wide  (cost=0.00..15.29 rows=529 width=4) (actual time=0.065..0.074 rows=1 loops=3)
!                      ->  Parallel Hash  (cost=16.61..16.61 rows=529 width=36) (actual time=140.210..140.210 rows=1 loops=3)
!                            Buckets: 1024 (originally 2048)  Batches: 8 (originally 1)  Memory Usage: 321kB
!                            ->  Parallel Seq Scan on wide wide_1  (cost=0.00..16.61 rows=529 width=36) (actual time=4.233..15.117 rows=1 loops=3)
!  Planning time: 1.380 ms
!  Execution time: 509.607 ms
! (13 rows)


Aside from the instability problems, I'm pretty unhappy about how much
the PHJ patch has added to the runtime of "make check".  I do not think
any one feature can justify adding 20% to that.  Can't you cut down the
amount of data processed by these new test cases?

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2017-12-28T04:15:00Z

On Thu, Dec 28, 2017 at 3:32 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Thomas Munro <thomas.munro@enterprisedb.com> writes:
>> I'll address the instability of the regression test output separately.
>
> If you're still looking for data on that --- prairiedog is able to
> reproduce the "multibatch = f" variant about one time in thirty.
> I modified the test case to print out the full EXPLAIN ANALYZE output
> rather than a heavily filtered version.  Here's a typical successful run:
>
> !                            Buckets: 1024 (originally 2048)  Batches: 8 (originally 1)  Memory Usage: 321kB
> !  Execution time: 424.395 ms
>
> and here's a failing run:
>
> !                            Buckets: 1024 (originally 2048)  Batches: 1 (originally 1)  Memory Usage: 0kB
> !  Execution time: 243.120 ms
>
> I don't have enough insight to be totally sure what this means, but the
> "Memory Usage: 0kB" bit is obviously bogus, so I'd venture that at least
> part of the issue is failure to return stats from a worker.

Hmm.  Yeah, that seems quite likely -- thanks.  Investigating now.

> I also find
> it most curious that the "success" case is a lot slower than the "not
> success" case.  Perhaps this is related to your livelock issue?  Doing
> another run, I get something even slower:
>
> !                            Buckets: 1024 (originally 2048)  Batches: 8 (originally 1)  Memory Usage: 321kB
> !  Execution time: 509.607 ms

Yes, that looks a lot like the ConditionVariableBroadcast() livelock
problem.  That query with the same 8-batch 2-worker plan runs in ~12ms
and ~19ms for me on two different machines here without the run-to-run
variation you see.

> Aside from the instability problems, I'm pretty unhappy about how much
> the PHJ patch has added to the runtime of "make check".  I do not think
> any one feature can justify adding 20% to that.  Can't you cut down the
> amount of data processed by these new test cases?

Isn't that mostly because of the CV livelock problem?  Here are the
real times I got with "time make check" on my slow 2 core Intel(R)
Celeron(R) CPU G1610T @ 2.30GHz running FreeBSD, which seems to be
prone to that problem on certain queries:

84940644 = 34.83s (before hash join regression tests)
fa330f9a = 35.81s (hash join regression tests)
18042840 = 44.92s (parallel-aware hash joins + new tests)

So the PHJ patch made it take 25% longer, similar to what you
reported.  But then if I apply the following band-aid kludge to
condition_variable.c to limit the looping, I get:

-       while (ConditionVariableSignal(cv))
+       while (nwoken < max_parallel_workers && ConditionVariableSignal(cv))
                ++nwoken;

18042840 + kludge = 36.70s

So without the effects of that bug it's only taking 2.4% longer than
commit fa330f9a.  Is that acceptable for a feature of this size and
complexity?  I will also look into making the data sets smaller.

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2017-12-28T04:26:35Z

Thomas Munro <thomas.munro@enterprisedb.com> writes:
> On Thu, Dec 28, 2017 at 3:32 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> Aside from the instability problems, I'm pretty unhappy about how much
>> the PHJ patch has added to the runtime of "make check".  I do not think
>> any one feature can justify adding 20% to that.  Can't you cut down the
>> amount of data processed by these new test cases?

> Isn't that mostly because of the CV livelock problem?

Hm, maybe.  I quoted the 20% figure on the basis of longfin's reports,
not prairiedog's ... but it might be seeing some of the livelock effect
too.

> So without the effects of that bug it's only taking 2.4% longer than
> commit fa330f9a.  Is that acceptable for a feature of this size and
> complexity?  I will also look into making the data sets smaller.

That sounds better, but it's still worth asking whether the tests
could be quicker.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2017-12-28T13:21:01Z

On Thu, Dec 28, 2017 at 5:15 PM, Thomas Munro
<thomas.munro@enterprisedb.com> wrote:
> On Thu, Dec 28, 2017 at 3:32 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> !                            Buckets: 1024 (originally 2048)  Batches: 1 (originally 1)  Memory Usage: 0kB
>> !  Execution time: 243.120 ms
>>
>> I don't have enough insight to be totally sure what this means, but the
>> "Memory Usage: 0kB" bit is obviously bogus, so I'd venture that at least
>> part of the issue is failure to return stats from a worker.
>
> Hmm.  Yeah, that seems quite likely -- thanks.  Investigating now.

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().

In my patch for commit 5bcf389e (before PHJ), I had extracted and
rejiggered some parts of my PHJ work to fix a problem with EXPLAIN for
parallel-oblivious hash joins running in parallel queries, but I
failed to readapt it properly for PHJ.  EXPLAIN needs to scan all
participants' HashInstrumentation to collect the greatest space
report, not just the first one it finds.  I'll test and post a patch
to fix this tomorrow.

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2017-12-30T13:51:26Z

On Fri, Dec 29, 2017 at 2:21 AM, Thomas Munro
<thomas.munro@enterprisedb.com> wrote:
> On Thu, Dec 28, 2017 at 5:15 PM, Thomas Munro
> <thomas.munro@enterprisedb.com> wrote:
>> On Thu, Dec 28, 2017 at 3:32 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>>> !                            Buckets: 1024 (originally 2048)  Batches: 1 (originally 1)  Memory Usage: 0kB
>>> !  Execution time: 243.120 ms
>>>
>>> I don't have enough insight to be totally sure what this means, but the
>>> "Memory Usage: 0kB" bit is obviously bogus, so I'd venture that at least
>>> part of the issue is failure to return stats from a worker.
>>
>> Hmm.  Yeah, that seems quite likely -- thanks.  Investigating now.
>
> 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?

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2017-12-30T16:16:34Z

Hi,

On 2017-12-31 02:51:26 +1300, Thomas Munro wrote:
> You mentioned that prairiedog sees the problem about one time in
> thirty.  Would you mind checking if it goes away with this patch
> applied?
> 
> -- 
> Thomas Munro
> http://www.enterprisedb.com

> From cbed027275039cc5debf8db89342a133a831c9ca Mon Sep 17 00:00:00 2001
> From: Thomas Munro <thomas.munro@enterprisedb.com>
> Date: Sun, 31 Dec 2017 02:03:07 +1300
> Subject: [PATCH] Fix EXPLAIN ANALYZE output for Parallel Hash.
> 
> In a race case, EXPLAIN ANALYZE could fail to display correct nbatch and size
> information.  Refactor so that participants report only on batches they worked
> on rather than trying to report on all of them, and teach explain.c to
> consider the HashInstrumentation object from all participants instead of
> picking the first one it can find.  This should fix an occasional build farm
> failure in the "join" regression test.

This seems buggy independent of whether it fixes the issue on prairedog,
right? So I'm inclined to go ahead and just fix it...


> +	/*
> +	 * Merge results from workers.  In the parallel-oblivious case, the
> +	 * results from all participants should be identical, except where
> +	 * participants didn't run the join at all so have no data.  In the
> +	 * parallel-aware case, we need to aggregate the results.  Each worker may
> +	 * have seen a different subset of batches and we want to report the peak
> +	 * memory usage across all batches.
> +	 */

It's not necessarily the peak though, right? The largest batches might
not be read in at the same time. I'm fine with approximating it as such,
just want to make sure I understand.


> +	if (hashstate->shared_info)
>  	{
>  		SharedHashInfo *shared_info = hashstate->shared_info;
>  		int		i;
>  
> -		/* Find the first worker that built a hash table. */
>  		for (i = 0; i < shared_info->num_workers; ++i)
>  		{
> -			if (shared_info->hinstrument[i].nbatch > 0)
> +			HashInstrumentation *worker_hi = &shared_info->hinstrument[i];
> +
> +			if (worker_hi->nbatch > 0)
>  			{
> -				hinstrument = &shared_info->hinstrument[i];
> -				break;
> +				/*
> +				 * Every participant should agree on the buckets, so to be
> +				 * sure we have a value we'll just overwrite each time.
> +				 */
> +				hinstrument.nbuckets = worker_hi->nbuckets;
> +				hinstrument.nbuckets_original = worker_hi->nbuckets_original;
> +				/*
> +				 * Normally every participant should agree on the number of
> +				 * batches too, but it's possible for a backend that started
> +				 * late and missed the whole join not to have the final nbatch
> +				 * number.  So we'll take the largest number.
> +				 */
> +				hinstrument.nbatch = Max(hinstrument.nbatch, worker_hi->nbatch);
> +				hinstrument.nbatch_original = worker_hi->nbatch_original;
> +				/*
> +				 * In a parallel-aware hash join, for now we report the
> +				 * maximum peak memory reported by any worker.
> +				 */
> +				hinstrument.space_peak =
> +					Max(hinstrument.space_peak, worker_hi->space_peak);

I bet pgindent will not like this layout.

Ho hum. Is this really, as you say above, an "aggregate the results"?


Greetings,

Andres Freund

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2017-12-30T21:59:26Z

On Sun, Dec 31, 2017 at 5:16 AM, Andres Freund <andres@anarazel.de> wrote:
>> In a race case, EXPLAIN ANALYZE could fail to display correct nbatch and size
>> information.  Refactor so that participants report only on batches they worked
>> on rather than trying to report on all of them, and teach explain.c to
>> consider the HashInstrumentation object from all participants instead of
>> picking the first one it can find.  This should fix an occasional build farm
>> failure in the "join" regression test.
>
> This seems buggy independent of whether it fixes the issue on prairedog,
> right? So I'm inclined to go ahead and just fix it...

+1

>> +     /*
>> +      * Merge results from workers.  In the parallel-oblivious case, the
>> +      * results from all participants should be identical, except where
>> +      * participants didn't run the join at all so have no data.  In the
>> +      * parallel-aware case, we need to aggregate the results.  Each worker may
>> +      * have seen a different subset of batches and we want to report the peak
>> +      * memory usage across all batches.
>> +      */
>
> It's not necessarily the peak though, right? The largest batches might
> not be read in at the same time. I'm fine with approximating it as such,
> just want to make sure I understand.

Yeah, it's not attempting to report the true simultaneous peak memory
usage.  It's only reporting the largest individual hash table ever
loaded.  In a multi-batch join more than one hash table may be loaded
at the same time -- up to the number of participants -- but I'm not
yet attempting to reflect that.  On the one hand, that's a bit like
the way we show the size for parallel-oblivious hash joins: each
participant used the reported amount of memory at approximately the
same time.  On the other hand, the total simultaneous memory usage for
parallel-aware hash join is capped by both nbatch and nparticipants:
the true simultaneous peak must be <= largest_hash_table * Min(nbatch,
nparticipants).  I considered various ways to capture and report this
(see the 0007 patch in the v26 patchset, which showed per-worker
information separately, but I abandoned that patch because it was
useless and confusing; another idea would be to report the sum of the
nparticipants largest hash tables, or just assume all batches are
similarly sized and use the formula I gave above, and another would be
to actually track which hash tables or memory regions that were
simultaneously loaded with an incremental shared counter maintained
when hash chunks and bucket arrays are allocated and freed), but
figured we should just go with something super simple for now and then
discuss better ideas as a later evolution.

>> [code]
>
> I bet pgindent will not like this layout.

pgindented.

> Ho hum. Is this really, as you say above, an "aggregate the results"?

Yeah, misleading/stupid use of "aggregate" (SQL MAX() is an
aggregate...).  Offending word removed.

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2017-12-30T22:34:17Z

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 = t" diff, and
I can report that this patch does *not* help that.  The underlying
EXPLAIN output goes from something like

!  Finalize Aggregate  (cost=823.85..823.86 rows=1 width=8) (actual time=1378.102..1378.105 rows=1 loops=1)
!    ->  Gather  (cost=823.63..823.84 rows=2 width=8) (actual time=1377.909..1378.006 rows=3 loops=1)
!          Workers Planned: 2
!          Workers Launched: 2
!          ->  Partial Aggregate  (cost=823.63..823.64 rows=1 width=8) (actual time=1280.298..1280.302 rows=1 loops=3)
!                ->  Parallel Hash Join  (cost=387.50..802.80 rows=8333 width=0) (actual time=1070.179..1249.142 rows=6667 loops=3)
!                      Hash Cond: (r.id = s.id)
!                      ->  Parallel Seq Scan on simple r  (cost=0.00..250.33 rows=8333 width=4) (actual time=0.173..62.063 rows=6667 loops=3)
!                      ->  Parallel Hash  (cost=250.33..250.33 rows=8333 width=4) (actual time=454.305..454.305 rows=6667 loops=3)
!                            Buckets: 4096  Batches: 8  Memory Usage: 208kB
!                            ->  Parallel Seq Scan on simple s  (cost=0.00..250.33 rows=8333 width=4) (actual time=0.178..67.115 rows=6667 loops=3)
!  Planning time: 1.861 ms
!  Execution time: 1687.311 ms

to something like

!  Finalize Aggregate  (cost=823.85..823.86 rows=1 width=8) (actual time=1588.733..1588.737 rows=1 loops=1)
!    ->  Gather  (cost=823.63..823.84 rows=2 width=8) (actual time=1588.529..1588.634 rows=3 loops=1)
!          Workers Planned: 2
!          Workers Launched: 2
!          ->  Partial Aggregate  (cost=823.63..823.64 rows=1 width=8) (actual time=1492.631..1492.635 rows=1 loops=3)
!                ->  Parallel Hash Join  (cost=387.50..802.80 rows=8333 width=0) (actual time=1270.309..1451.501 rows=6667 loops=3)
!                      Hash Cond: (r.id = s.id)
!                      ->  Parallel Seq Scan on simple r  (cost=0.00..250.33 rows=8333 width=4) (actual time=0.219..158.144 rows=6667 loops=3)
!                      ->  Parallel Hash  (cost=250.33..250.33 rows=8333 width=4) (actual time=634.614..634.614 rows=6667 loops=3)
!                            Buckets: 4096 (originally 4096)  Batches: 16 (originally 8)  Memory Usage: 176kB
!                            ->  Parallel Seq Scan on simple s  (cost=0.00..250.33 rows=8333 width=4) (actual time=0.182..120.074 rows=6667 loops=3)
!  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

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2017-12-30T23:28:58Z

On Sun, Dec 31, 2017 at 11:34 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Thomas Munro <thomas.munro@enterprisedb.com> writes:
>> 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.

Thanks!

> However ... I noticed that my other dinosaur gaur shows the other failure
> mode we see in the buildfarm, the "increased_batches = t" diff, and
> I can report that this patch does *not* help that.  The underlying
> EXPLAIN output goes from something like
>
> !                            Buckets: 4096  Batches: 8  Memory Usage: 208kB
>
> to something like
>
> !                            Buckets: 4096 (originally 4096)  Batches: 16 (originally 8)  Memory Usage: 176kB
>
> 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.

Right.  That's apparently unrelated and is the last build-farm issue
on my list (so far).  I had noticed that certain BF animals are prone
to that particular failure, and they mostly have architectures that I
don't have so a few things are probably just differently sized.  At
first I thought I'd tweak the tests so that the parameters were always
stable, and I got as far as installing Debian on qemu-system-ppc (it
took a looong time to compile PostgreSQL), but that seems a bit cheap
and flimsy... better to fix the size estimation error.

I assume that what happens here is the planner's size estimation code
sometimes disagrees with Parallel Hash's chunk-based memory
accounting, even though in this case we had perfect tuple count and
tuple size information.  In an earlier version of the patch set I
refactored the planner to be chunk-aware (even for parallel-oblivious
hash join), but later in the process I tried to simplify and shrink
the patch set and avoid making unnecessary changes to non-Parallel
Hash code paths.  I think I'll need to make the planner aware of the
maximum amount of fragmentation possible when parallel-aware
(something like: up to one tuple's worth at the end of each chunk, and
up to one whole wasted chunk per participating backend).  More soon.

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2017-12-31T00:00:19Z

Thomas Munro <thomas.munro@enterprisedb.com> writes:
> On Sun, Dec 31, 2017 at 11:34 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> ... 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.

> Right.  That's apparently unrelated and is the last build-farm issue
> on my list (so far).  I had noticed that certain BF animals are prone
> to that particular failure, and they mostly have architectures that I
> don't have so a few things are probably just differently sized.  At
> first I thought I'd tweak the tests so that the parameters were always
> stable, and I got as far as installing Debian on qemu-system-ppc (it
> took a looong time to compile PostgreSQL), but that seems a bit cheap
> and flimsy... better to fix the size estimation error.

"Size estimation error"?  Why do you think it's that?  We have exactly
the same plan in both cases.

My guess is that what's happening is that one worker or the other ends
up processing the whole scan, or the vast majority of it, so that that
worker's hash table has to hold substantially more than half of the
tuples and thereby is forced to up the number of batches.  I don't see
how you can expect to estimate that situation exactly; or if you do,
you'll be pessimizing the plan for cases where the split is more nearly
equal.

By this theory, the reason why certain BF members are more prone to the
failure is that they're single-processor machines, and perhaps have
kernels with relatively long scheduling quanta, so that it's more likely
that the worker that gets scheduled first is able to read the whole input
to the hash step.

> I assume that what happens here is the planner's size estimation code
> sometimes disagrees with Parallel Hash's chunk-based memory
> accounting, even though in this case we had perfect tuple count and
> tuple size information.  In an earlier version of the patch set I
> refactored the planner to be chunk-aware (even for parallel-oblivious
> hash join), but later in the process I tried to simplify and shrink
> the patch set and avoid making unnecessary changes to non-Parallel
> Hash code paths.  I think I'll need to make the planner aware of the
> maximum amount of fragmentation possible when parallel-aware
> (something like: up to one tuple's worth at the end of each chunk, and
> up to one whole wasted chunk per participating backend).  More soon.

I'm really dubious that trying to model the executor's space consumption
exactly is a good idea, even if it did fix this specific problem.
That would expend extra planner cycles and pose a continuing maintenance
gotcha.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2018-01-01T22:42:28Z

On 2017-12-31 10:59:26 +1300, Thomas Munro wrote:
> On Sun, Dec 31, 2017 at 5:16 AM, Andres Freund <andres@anarazel.de> wrote:
> >> In a race case, EXPLAIN ANALYZE could fail to display correct nbatch and size
> >> information.  Refactor so that participants report only on batches they worked
> >> on rather than trying to report on all of them, and teach explain.c to
> >> consider the HashInstrumentation object from all participants instead of
> >> picking the first one it can find.  This should fix an occasional build farm
> >> failure in the "join" regression test.
> >
> > This seems buggy independent of whether it fixes the issue on prairedog,
> > right? So I'm inclined to go ahead and just fix it...
> 
> +1

Pushed your updated version.

Thanks,

Andres

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2018-01-02T03:23:45Z

On Tue, Jan 2, 2018 at 11:42 AM, Andres Freund <andres@anarazel.de> wrote:
> Pushed your updated version.

Thanks.  That should leave just the test failures like this on certain machines:

*** 6103,6109 ****
  $$);
   initially_multibatch | increased_batches
  ----------------------+-------------------
!  t                    | f
  (1 row)

  rollback to settings;
--- 6103,6109 ----
  $$);
   initially_multibatch | increased_batches
  ----------------------+-------------------
!  t                    | t
  (1 row)

I'll post a patch that should fix that along with a reply to Tom's
most recent email tomorrow, when I'm back from my break.

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2018-01-03T01:14:30Z

On Sun, Dec 31, 2017 at 1:00 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> Right.  That's apparently unrelated and is the last build-farm issue
>> on my list (so far).  I had noticed that certain BF animals are prone
>> to that particular failure, and they mostly have architectures that I
>> don't have so a few things are probably just differently sized.  At
>> first I thought I'd tweak the tests so that the parameters were always
>> stable, and I got as far as installing Debian on qemu-system-ppc (it
>> took a looong time to compile PostgreSQL), but that seems a bit cheap
>> and flimsy... better to fix the size estimation error.
>
> "Size estimation error"?  Why do you think it's that?  We have exactly
> the same plan in both cases.

I mean that ExecChooseHashTableSize() estimates the hash table size like this:

    inner_rel_bytes = ntuples * tupsize;

... but then at execution time, in the Parallel Hash case, we do
memory accounting not in tuples but in chunks.  The various
participants pack tuples into 32KB chunks, and they trigger an
increase in the number of batches when the total size of all chunks
happens to exceeds the memory budget.  In this case they do so
unexpectedly due to that extra overhead at execution time that the
planner didn't account for.  We happened to be close to the threshold,
in this case between choosing 8 batches and 16 batches, we can get it
wrong and have to increase nbatch at execution time.

Non-parallel Hash also has such fragmentation.  There are headers +
extra space at the end of each chunk, especially the end of the final
chunk.  But it doesn't matter there because the executor doesn't count
the overhead either.  For Parallel Hash I count the overhead, because
it reduces IPC if I do all the accounting in 32KB chunks.

I'm torn between (1) posting a patch that teaches
ExecChooseHashTableSize() to estimate the worst case extra
fragmentation assuming all participants contribute an almost entirely
empty chunk at the end, and (2) just finding some parameters (ie tweak
work_mem or number of tuples) that will make this work on all
computers in the build farm.  I think the former is the correct
solution.  Another solution would be to teach the executor to discount
the overhead, but that seems hard and seems like it's travelling in
the wrong direction.

> My guess is that what's happening is that one worker or the other ends
> up processing the whole scan, or the vast majority of it, so that that
> worker's hash table has to hold substantially more than half of the
> tuples and thereby is forced to up the number of batches.  I don't see
> how you can expect to estimate that situation exactly; or if you do,
> you'll be pessimizing the plan for cases where the split is more nearly
> equal.

That sort of thing does indeed affect the size at execution.  You can
see that run to run variation easily with a small join forced to use
Parallel Hash, so that there is a race to load tuples.  You get a
larger size if more workers manage to load at least one tuple, due to
their final partially filled chunk.

There is also the question of this being underestimated on systems
without real atomics:

    bucket_bytes = sizeof(HashJoinTuple) * nbuckets;

The real size at execution time is sizeof(dsa_pointer_atomic) *
nbuckets.  I don't think that's responsible for this particular
underestimation problem because the bucket array is currently not
considered at execution time when deciding to increase batches -- it
should be, and I'll come back to those two problems separately.

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-03T01:38:30Z

Thomas Munro <thomas.munro@enterprisedb.com> writes:
> On Sun, Dec 31, 2017 at 1:00 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> "Size estimation error"?  Why do you think it's that?  We have exactly
>> the same plan in both cases.

> I mean that ExecChooseHashTableSize() estimates the hash table size like this:
>     inner_rel_bytes = ntuples * tupsize;

> ... but then at execution time, in the Parallel Hash case, we do
> memory accounting not in tuples but in chunks.  The various
> participants pack tuples into 32KB chunks, and they trigger an
> increase in the number of batches when the total size of all chunks
> happens to exceeds the memory budget.  In this case they do so
> unexpectedly due to that extra overhead at execution time that the
> planner didn't account for.  We happened to be close to the threshold,
> in this case between choosing 8 batches and 16 batches, we can get it
> wrong and have to increase nbatch at execution time.

If that's the issue, why doesn't the test fail every time on affected
platforms?  There shouldn't be anything nondeterministic about the
number or size of tuples going into the hash table?

> ... You get a
> larger size if more workers manage to load at least one tuple, due to
> their final partially filled chunk.

Hm.  That could do it, except it doesn't really account for the observed
result that slower single-processor machines seem more prone to the
bug.  Surely they should be less likely to get multiple workers activated.

BTW, I'm seeing a few things that look bug-like about
ExecParallelHashTuplePrealloc, for instance why does it use just
"size" to decide if space_allowed is exceeded but if not then add the
typically-much-larger value "want + HASH_CHUNK_HEADER_SIZE" to
estimated_size.  That clearly can allow estimated_size to get
significantly past space_allowed --- if it's not a bug, it at least
deserves a comment explaining why not.  Another angle, which does not
apply to this test case but seems like a bug for real usage, is that
ExecParallelHashTuplePrealloc doesn't account correctly for tuples wider
than HASH_CHUNK_THRESHOLD.

I'm also wondering why the non-parallel path seems to prefer to allocate
in units of HASH_CHUNK_SIZE + HASH_CHUNK_HEADER_SIZE while the parallel
path targets allocations of exactly HASH_CHUNK_SIZE, and why there's such
inconsistency in whether tuples of exactly HASH_CHUNK_THRESHOLD bytes
are treated as "big" or not.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2018-01-03T12:06:38Z

On Wed, Jan 3, 2018 at 2:38 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Thomas Munro <thomas.munro@enterprisedb.com> writes:
>> I mean that ExecChooseHashTableSize() estimates the hash table size like this:
>>     inner_rel_bytes = ntuples * tupsize;
>
>> ... but then at execution time, in the Parallel Hash case, we do
>> memory accounting not in tuples but in chunks.  The various
>> participants pack tuples into 32KB chunks, and they trigger an
>> increase in the number of batches when the total size of all chunks
>> happens to exceeds the memory budget.  In this case they do so
>> unexpectedly due to that extra overhead at execution time that the
>> planner didn't account for.  We happened to be close to the threshold,
>> in this case between choosing 8 batches and 16 batches, we can get it
>> wrong and have to increase nbatch at execution time.
>
> If that's the issue, why doesn't the test fail every time on affected
> platforms?  There shouldn't be anything nondeterministic about the
> number or size of tuples going into the hash table?
>
>> ... You get a
>> larger size if more workers manage to load at least one tuple, due to
>> their final partially filled chunk.
>
> Hm.  That could do it, except it doesn't really account for the observed
> result that slower single-processor machines seem more prone to the
> bug.  Surely they should be less likely to get multiple workers activated.

I can reproduce the instability here with an -m32 build and this:

  create table simple as
    select generate_series(1, 20000) AS id,
'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
  alter table simple set (parallel_workers = 2);
  analyze simple;

  set parallel_setup_cost = 0;
  set work_mem = '96kB';

  explain analyze select count(*) from simple r join simple s using
(id);

It plans for 8 batches, and then usually but not always goes to 16 at
execution time depending on timing.  It doesn't happen for me with
128kB (the setting used in the regression test), but I think the
affected BF machines are all 32 bit systems that have MAXIMUM_ALIGNOF
8 and therefore use a bit more space, whereas my machines have
MAXIMUM_ALIGNOF 4 in a 32 bit build, so that would explain the
different location of this unstable border.  We could probably fix the
failures by simply increasing work_mem out of that zone, but I'm
hoping to fix the problem in a more principled way.  More soon.

> BTW, I'm seeing a few things that look bug-like about
> ExecParallelHashTuplePrealloc, for instance why does it use just
> "size" to decide if space_allowed is exceeded but if not then add the
> typically-much-larger value "want + HASH_CHUNK_HEADER_SIZE" to
> estimated_size.  That clearly can allow estimated_size to get
> significantly past space_allowed --- if it's not a bug, it at least
> deserves a comment explaining why not.

Right.  Fixed in the attached.

> Another angle, which does not
> apply to this test case but seems like a bug for real usage, is that
> ExecParallelHashTuplePrealloc doesn't account correctly for tuples wider
> than HASH_CHUNK_THRESHOLD.

Right.  I'll address that separately.

> I'm also wondering why the non-parallel path seems to prefer to allocate
> in units of HASH_CHUNK_SIZE + HASH_CHUNK_HEADER_SIZE while the parallel
> path targets allocations of exactly HASH_CHUNK_SIZE,

That is intentional: dsa.c sucks at allocating 32KB + a tiny bit
because it works in 4KB pages for large allocations, so I wanted to
make HASH_CHUNK_SIZE the total size that arrives into dsa_allocate().
The non-parallel path has similar problems on some libc
implementations, as we discussed over here:

https://www.postgresql.org/message-id/flat/29770.1511495642%40sss.pgh.pa.us

> and why there's such
> inconsistency in whether tuples of exactly HASH_CHUNK_THRESHOLD bytes
> are treated as "big" or not.

Right, that's inconsistent.  Fixed in the attached.

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-03T18:03:39Z

Thomas Munro <thomas.munro@enterprisedb.com> writes:
> On Wed, Jan 3, 2018 at 2:38 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> Hm.  That could do it, except it doesn't really account for the observed
>> result that slower single-processor machines seem more prone to the
>> bug.  Surely they should be less likely to get multiple workers activated.

> It plans for 8 batches, and then usually but not always goes to 16 at
> execution time depending on timing.  It doesn't happen for me with
> 128kB (the setting used in the regression test), but I think the
> affected BF machines are all 32 bit systems that have MAXIMUM_ALIGNOF
> 8 and therefore use a bit more space, whereas my machines have
> MAXIMUM_ALIGNOF 4 in a 32 bit build, so that would explain the
> different location of this unstable border.

Ah, that might do it.  You're right that gaur/pademelon are in that class.

> We could probably fix the
> failures by simply increasing work_mem out of that zone, but I'm
> hoping to fix the problem in a more principled way.  More soon.

Meh.  I think we're going to end up having to pick a modified test
case that's further away from the chunk size threshold.  I do not
think it is possible to predict this runtime behavior exactly at
plan time, nor am I convinced that expending planner cycles on a
somewhat closer estimate is a useful use of planning time.

>> I'm also wondering why the non-parallel path seems to prefer to allocate
>> in units of HASH_CHUNK_SIZE + HASH_CHUNK_HEADER_SIZE while the parallel
>> path targets allocations of exactly HASH_CHUNK_SIZE,

> That is intentional: dsa.c sucks at allocating 32KB + a tiny bit
> because it works in 4KB pages for large allocations, so I wanted to
> make HASH_CHUNK_SIZE the total size that arrives into dsa_allocate().
> The non-parallel path has similar problems on some libc
> implementations, as we discussed over here:
> https://www.postgresql.org/message-id/flat/29770.1511495642%40sss.pgh.pa.us

Oh, right, I'd forgotten about that discussion.  I think it would be
good to adjust hashjoin so that both paths are targeting 32KB total;
but you are right that there's not a lot of point in fooling with the
non-parallel path until we add some way of accounting for aset.c's
overhead too.  We can leave that for later.

>> BTW, I'm seeing a few things that look bug-like about
>> ExecParallelHashTuplePrealloc, ...

> Right.  Fixed in the attached.

Pushed, plus an additional Assert to clarify that we're expecting
ExecParallelHashTuplePrealloc's caller to have already maxalign'ed
the request size.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-04T01:17:04Z

So this patch has been in place for two weeks, the buildfarm has still
got the measles, and we're entering the January commitfest with a lot
of other work to get done.  I realize that the two weeks were mostly
holiday time, but it's time to have some urgency about clearing the
buildfarm failures.

As best I understand, the remaining failures simply arise from
an unstable regression test case and aren't teaching us anything
of value.  I propose that for the moment, we simply remove the
failing query from join.sql.  We can put it back when there's
reason to think it will pass everywhere.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2018-01-04T01:23:05Z

Hi,

On 2018-01-03 20:17:04 -0500, Tom Lane wrote:
> So this patch has been in place for two weeks, the buildfarm has still
> got the measles, and we're entering the January commitfest with a lot
> of other work to get done.  I realize that the two weeks were mostly
> holiday time, but it's time to have some urgency about clearing the
> buildfarm failures.

Agreed.

> As best I understand, the remaining failures simply arise from
> an unstable regression test case and aren't teaching us anything
> of value.

I think that's the correct interpretation.

> I propose that for the moment, we simply remove the
> failing query from join.sql.  We can put it back when there's
> reason to think it will pass everywhere.

Alternatively we could temporarily push an alternative output. It
doesn't seem inconceivable we missed an actual bug due to the
noise. Don't have a strong opinion on which of the two to choose.

Unless somebody does something first, I'll disable the test tomorrow
pacific morning. But perhaps Thomas can up with an approach till then
that seems likely to pass on the different architectures. Seems quite
possible to just adjust the thresholds carefully?

Greetings,

Andres Freund

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2018-01-04T01:26:28Z

On Thu, Jan 4, 2018 at 2:17 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> So this patch has been in place for two weeks, the buildfarm has still
> got the measles, and we're entering the January commitfest with a lot
> of other work to get done.  I realize that the two weeks were mostly
> holiday time, but it's time to have some urgency about clearing the
> buildfarm failures.
>
> As best I understand, the remaining failures simply arise from
> an unstable regression test case and aren't teaching us anything
> of value.  I propose that for the moment, we simply remove the
> failing query from join.sql.  We can put it back when there's
> reason to think it will pass everywhere.

I spent a lot of time trying and failing to get the world's slowest 32
bit powerpc emulation to reproduce this.  Bleugh.  Before we rip that
test out, would you mind checking if this passes repeatedly on gaur or
pademelon?

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-04T02:09:24Z

Thomas Munro <thomas.munro@enterprisedb.com> writes:
> I spent a lot of time trying and failing to get the world's slowest 32
> bit powerpc emulation to reproduce this.  Bleugh.  Before we rip that
> test out, would you mind checking if this passes repeatedly on gaur or
> pademelon?

Will do, but that machine is none too fast itself ... it'll be a few
hours before I can confirm anything.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-04T06:09:33Z

Thomas Munro <thomas.munro@enterprisedb.com> writes:
> I spent a lot of time trying and failing to get the world's slowest 32
> bit powerpc emulation to reproduce this.  Bleugh.  Before we rip that
> test out, would you mind checking if this passes repeatedly on gaur or
> pademelon?

I ran a couple dozen test cycles on gaur without a failure.  That's
not enough to really prove anything, but it's more successes than I was
getting before.  I pushed the patch so we can see what the rest of the
buildfarm thinks.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-04T16:00:24Z

I wrote:
> I ran a couple dozen test cycles on gaur without a failure.  That's
> not enough to really prove anything, but it's more successes than I was
> getting before.  I pushed the patch so we can see what the rest of the
> buildfarm thinks.

The early returns indicate that that problem is fixed; but now that the
noise level is down, it's possible to see that brolga is showing an actual
crash in the PHJ test, perhaps one time in four.  So we're not out of
the woods yet.  It seems to consistently look like this:

2017-12-21 17:34:52.092 EST [2252:4] LOG:  background worker "parallel worker" (PID 3584) was terminated by signal 11
2017-12-21 17:34:52.092 EST [2252:5] DETAIL:  Failed process was running: select count(*) from foo
	  left join (select b1.id, b1.t from bar b1 join bar b2 using (id)) ss
	  on foo.id < ss.id + 1 and foo.id > ss.id - 1;
2017-12-21 17:34:52.092 EST [2252:6] LOG:  terminating any other active server processes

Also, what the devil is happening on skink?

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Robert Haas <robertmhaas@gmail.com> — 2018-01-04T16:59:09Z

On Thu, Jan 4, 2018 at 11:00 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Also, what the devil is happening on skink?

I looked at the server log for the first of the two skink failures.
The key lines seem to be:

2018-01-04 07:45:36.764 UTC [5a4ddb98.5a97:154] LOG:  statement: DROP
SCHEMA testschema CASCADE;
2018-01-04 07:45:36.922 UTC [5a4ddb98.5a97:155] LOG:  statement: DROP
ROLE regress_tablespace_user1;
2018-01-04 07:45:36.941 UTC [5a4ddb98.5a97:156] LOG:  statement: DROP
ROLE regress_tablespace_user2;
2018-01-04 07:45:36.963 UTC [5a4ddb98.5a97:157] LOG:  disconnection:
session time: 0:00:08.472 user=andres database=regression host=[local]
...lines from other backends indicating new connections...
2018-01-04 07:45:37.289 UTC [5a4ddb92.2b65:4] LOG:  server process
(PID 23191) exited with exit code 128
2018-01-04 07:45:37.290 UTC [5a4ddb92.2b65:5] LOG:  terminating any
other active server processes

So, skink is apparently dying during shutdown of a user-connected
backend, and specifically the one that executed the 'tablespace' test.
That test itself passed, but then afterward the backend fell over and
died horribly.  Interestingly, I see multiple other messages in the
logs indicating similar failures:

2018-01-04 07:45:37.821 UTC [5a4ddb92.2b65:6] LOG:  statistics
collector process (PID 20842) exited with exit code 128
2018-01-04 07:46:08.113 UTC [5a4ddb92.2b65:9] LOG:  server process
(PID 29128) exited with exit code 128
2018-01-04 07:46:08.293 UTC [5a4ddb92.2b65:11] LOG:  statistics
collector process (PID 29059) exited with exit code 128
2018-01-04 07:46:26.384 UTC [5a4ddb92.2b65:14] LOG:  server process
(PID 13787) exited with exit code 128
2018-01-04 07:46:27.122 UTC [5a4ddb92.2b65:16] LOG:  statistics
collector process (PID 13776) exited with exit code 128

This is a valgrind animal.  I don't know if that might be related somehow.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-04T17:11:37Z

Robert Haas <robertmhaas@gmail.com> writes:
> On Thu, Jan 4, 2018 at 11:00 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> Also, what the devil is happening on skink?

> So, skink is apparently dying during shutdown of a user-connected
> backend, and specifically the one that executed the 'tablespace' test.

Well, yeah, valgrind is burping: the postmaster log is full of

==10544== VALGRINDERROR-BEGIN
==10544== Syscall param epoll_pwait(sigmask) points to unaddressable byte(s)
==10544==    at 0x7011490: epoll_pwait (epoll_pwait.c:42)
==10544==    by 0x4BF40B: WaitEventSetWaitBlock (latch.c:1048)
==10544==    by 0x4BF40B: WaitEventSetWait (latch.c:1000)
==10544==    by 0x3C0B3B: secure_read (be-secure.c:166)
==10544==    by 0x3CCD9E: pq_recvbuf (pqcomm.c:963)
==10544==    by 0x3CDA07: pq_getbyte (pqcomm.c:1006)
==10544==    by 0x4E2A2D: SocketBackend (postgres.c:339)
==10544==    by 0x4E444E: ReadCommand (postgres.c:512)
==10544==    by 0x4E7588: PostgresMain (postgres.c:4085)
==10544==    by 0x4641D0: BackendRun (postmaster.c:4412)
==10544==    by 0x467308: BackendStartup (postmaster.c:4084)
==10544==    by 0x4675F7: ServerLoop (postmaster.c:1757)
==10544==    by 0x4689D4: PostmasterMain (postmaster.c:1365)
==10544==  Address 0x0 is not stack'd, malloc'd or (recently) free'd
==10544== 
==10544== VALGRINDERROR-END

But (a) this is happening in multiple branches, and (b) we've not
changed anything near that code in awhile.  I think something broke
in valgrind itself.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2018-01-04T19:20:33Z

On 2018-01-04 12:11:37 -0500, Tom Lane wrote:
> Robert Haas <robertmhaas@gmail.com> writes:
> > On Thu, Jan 4, 2018 at 11:00 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> >> Also, what the devil is happening on skink?
> 
> > So, skink is apparently dying during shutdown of a user-connected
> > backend, and specifically the one that executed the 'tablespace' test.
> 
> Well, yeah, valgrind is burping: the postmaster log is full of
> 
> ==10544== VALGRINDERROR-BEGIN
> ==10544== Syscall param epoll_pwait(sigmask) points to unaddressable byte(s)
> ==10544==    at 0x7011490: epoll_pwait (epoll_pwait.c:42)
> ==10544==    by 0x4BF40B: WaitEventSetWaitBlock (latch.c:1048)
> ==10544==    by 0x4BF40B: WaitEventSetWait (latch.c:1000)
> ==10544==    by 0x3C0B3B: secure_read (be-secure.c:166)
> ==10544==    by 0x3CCD9E: pq_recvbuf (pqcomm.c:963)
> ==10544==    by 0x3CDA07: pq_getbyte (pqcomm.c:1006)
> ==10544==    by 0x4E2A2D: SocketBackend (postgres.c:339)
> ==10544==    by 0x4E444E: ReadCommand (postgres.c:512)
> ==10544==    by 0x4E7588: PostgresMain (postgres.c:4085)
> ==10544==    by 0x4641D0: BackendRun (postmaster.c:4412)
> ==10544==    by 0x467308: BackendStartup (postmaster.c:4084)
> ==10544==    by 0x4675F7: ServerLoop (postmaster.c:1757)
> ==10544==    by 0x4689D4: PostmasterMain (postmaster.c:1365)
> ==10544==  Address 0x0 is not stack'd, malloc'd or (recently) free'd
> ==10544== 
> ==10544== VALGRINDERROR-END
> 
> But (a) this is happening in multiple branches, and (b) we've not
> changed anything near that code in awhile.  I think something broke
> in valgrind itself.

Some packages on skink have been upgraded. It appears that there either
was a libc or valgrind change that made valgrind not recognize that a
pointer of 0 might not point anywhere :(

Let me check whether valgrind accept multiple suppression files, in
which case I could add a suppression for this error to all
branches. Will also check whether I can reproduce locally.

Greetings,

Andres Freund

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2018-01-04T20:06:47Z

On 2018-01-04 11:20:33 -0800, Andres Freund wrote:
> On 2018-01-04 12:11:37 -0500, Tom Lane wrote:
> > Robert Haas <robertmhaas@gmail.com> writes:
> > > On Thu, Jan 4, 2018 at 11:00 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> > >> Also, what the devil is happening on skink?
> > 
> > > So, skink is apparently dying during shutdown of a user-connected
> > > backend, and specifically the one that executed the 'tablespace' test.
> > 
> > Well, yeah, valgrind is burping: the postmaster log is full of
> > 
> > ==10544== VALGRINDERROR-BEGIN
> > ==10544== Syscall param epoll_pwait(sigmask) points to unaddressable byte(s)
> > ==10544==    at 0x7011490: epoll_pwait (epoll_pwait.c:42)
> > ==10544==    by 0x4BF40B: WaitEventSetWaitBlock (latch.c:1048)
> > ==10544==    by 0x4BF40B: WaitEventSetWait (latch.c:1000)
> > ==10544==    by 0x3C0B3B: secure_read (be-secure.c:166)
> > ==10544==    by 0x3CCD9E: pq_recvbuf (pqcomm.c:963)
> > ==10544==    by 0x3CDA07: pq_getbyte (pqcomm.c:1006)
> > ==10544==    by 0x4E2A2D: SocketBackend (postgres.c:339)
> > ==10544==    by 0x4E444E: ReadCommand (postgres.c:512)
> > ==10544==    by 0x4E7588: PostgresMain (postgres.c:4085)
> > ==10544==    by 0x4641D0: BackendRun (postmaster.c:4412)
> > ==10544==    by 0x467308: BackendStartup (postmaster.c:4084)
> > ==10544==    by 0x4675F7: ServerLoop (postmaster.c:1757)
> > ==10544==    by 0x4689D4: PostmasterMain (postmaster.c:1365)
> > ==10544==  Address 0x0 is not stack'd, malloc'd or (recently) free'd
> > ==10544== 
> > ==10544== VALGRINDERROR-END
> > 
> > But (a) this is happening in multiple branches, and (b) we've not
> > changed anything near that code in awhile.  I think something broke
> > in valgrind itself.
> 
> Some packages on skink have been upgraded. It appears that there either
> was a libc or valgrind change that made valgrind not recognize that a
> pointer of 0 might not point anywhere :(

It looks like recent glibc implements epoll_wait() as epoll_pwait() with
a NULL sigmask argument, and valgrind isn't happy with it.


> Let me check whether valgrind accept multiple suppression files, in
> which case I could add a suppression for this error to all
> branches.

Done that. I've added a valgrind-global.supp that has:

{
   null-sigmask-to-pwait-means-no-sigmask
   Memcheck:Param
   epoll_pwait(sigmask)
   fun:epoll_pwait
   fun:WaitEventSetWaitBlock
}


> Will also check whether I can reproduce locally.

Locally the above suppression allowed me to continue a bit further. But
I promptly hit other new blurbs:

assert build:
2018-01-04 12:03:45.927 PST [5716][3/189] STATEMENT:  select format('%1$s %4$s', 1, 2, 3);
==5718== Invalid write of size 8
==5718==    at 0x40E3DD: ExecInterpExpr (execExprInterp.c:1117)
==5718==    by 0x40F5E9: ExecInterpExprStillValid (execExprInterp.c:1788)
==5718==    by 0xE6B0409: ExecEvalExpr (executor.h:282)
==5718==    by 0xE6BA6EA: exec_eval_simple_expr (pl_exec.c:5602)
==5718==    by 0xE6B9DBB: exec_eval_expr (pl_exec.c:5197)
==5718==    by 0xE6B5A4B: exec_stmt_raise (pl_exec.c:3230)
==5718==    by 0xE6B2C04: exec_stmt (pl_exec.c:1632)
==5718==    by 0xE6B2956: exec_stmts (pl_exec.c:1535)
==5718==    by 0xE6B27FC: exec_stmt_block (pl_exec.c:1473)
==5718==    by 0xE6B083E: plpgsql_exec_function (pl_exec.c:474)
==5718==    by 0xE6AB13C: plpgsql_inline_handler (pl_handler.c:330)
==5718==    by 0x76C2B9: OidFunctionCall1Coll (fmgr.c:1327)
==5718==    by 0x3A28CA: ExecuteDoStmt (functioncmds.c:2234)
==5718==    by 0x5F92EB: standard_ProcessUtility (utility.c:532)
==5718==    by 0x5F8E26: ProcessUtility (utility.c:357)
==5718==    by 0x5F7D9F: PortalRunUtility (pquery.c:1178)
==5718==    by 0x5F7FC0: PortalRunMulti (pquery.c:1324)
==5718==    by 0x5F74DE: PortalRun (pquery.c:799)
==5718==    by 0x5F10BE: exec_simple_query (postgres.c:1120)
==5718==    by 0x5F5640: PostgresMain (postgres.c:4143)
==5718==  Address 0x20 is not stack'd, malloc'd or (recently) free'd
==5718== 
{
   <insert_a_suppression_name_here>
   Memcheck:Addr8
   fun:ExecInterpExpr
   fun:ExecInterpExprStillValid
   fun:ExecEvalExpr
   fun:exec_eval_simple_expr
   fun:exec_eval_expr
   fun:exec_stmt_raise
   fun:exec_stmt
   fun:exec_stmts
   fun:exec_stmt_block
   fun:plpgsql_exec_function
   fun:plpgsql_inline_handler
   fun:OidFunctionCall1Coll
   fun:ExecuteDoStmt
   fun:standard_ProcessUtility
   fun:ProcessUtility
   fun:PortalRunUtility
   fun:PortalRunMulti
   fun:PortalRun
   fun:exec_simple_query
   fun:PostgresMain
}
==5718== 
==5718== Process terminating with default action of signal 11 (SIGSEGV)
==5718==  Access not within mapped region at address 0x20
==5718==    at 0x40E3DD: ExecInterpExpr (execExprInterp.c:1117)
==5718==    by 0x40F5E9: ExecInterpExprStillValid (execExprInterp.c:1788)
==5718==    by 0xE6B0409: ExecEvalExpr (executor.h:282)
==5718==    by 0xE6BA6EA: exec_eval_simple_expr (pl_exec.c:5602)
==5718==    by 0xE6B9DBB: exec_eval_expr (pl_exec.c:5197)
==5718==    by 0xE6B5A4B: exec_stmt_raise (pl_exec.c:3230)
==5718==    by 0xE6B2C04: exec_stmt (pl_exec.c:1632)
==5718==    by 0xE6B2956: exec_stmts (pl_exec.c:1535)
==5718==    by 0xE6B27FC: exec_stmt_block (pl_exec.c:1473)
==5718==    by 0xE6B083E: plpgsql_exec_function (pl_exec.c:474)
==5718==    by 0xE6AB13C: plpgsql_inline_handler (pl_handler.c:330)
==5718==    by 0x76C2B9: OidFunctionCall1Coll (fmgr.c:1327)
==5718==    by 0x3A28CA: ExecuteDoStmt (functioncmds.c:2234)
==5718==    by 0x5F92EB: standard_ProcessUtility (utility.c:532)
==5718==    by 0x5F8E26: ProcessUtility (utility.c:357)
==5718==    by 0x5F7D9F: PortalRunUtility (pquery.c:1178)
==5718==    by 0x5F7FC0: PortalRunMulti (pquery.c:1324)
==5718==    by 0x5F74DE: PortalRun (pquery.c:799)
==5718==    by 0x5F10BE: exec_simple_query (postgres.c:1120)
==5718==    by 0x5F5640: PostgresMain (postgres.c:4143)
==5718==  If you believe this happened as a result of a stack
==5718==  overflow in your program's main thread (unlikely but
==5718==  possible), you can try to increase the size of the
==5718==  main thread stack using the --main-stacksize= flag.
==5718==  The main thread stack size used in this run was 8388608.

This looks like it might be related to recent plpgsql changes. Looks
like some pointer in:
			/* call input function (similar to InputFunctionCall) */
			if (!op->d.iocoerce.finfo_in->fn_strict || str != NULL)
is NULL.


==4286== Conditional jump or move depends on uninitialised value(s)
==4286==    at 0x6BA8A17: __wcsnlen_avx2 (strlen-avx2.S:261)
==4286==    by 0x6AF2FF1: wcsrtombs (wcsrtombs.c:104)
==4286==    by 0x6A88A40: wcstombs (wcstombs.c:34)
==4286==    by 0x514772: lowerstr_with_len.part.1 (ts_locale.c:284)
==4286==    by 0x523A63: readstoplist (ts_utils.c:119)
==4286==    by 0xEAB2839: dsnowball_init (dict_snowball.c:201)
==4286==    by 0x684975: OidFunctionCall1Coll (fmgr.c:1327)
==4286==    by 0x679277: lookup_ts_dictionary_cache (ts_cache.c:337)
==4286==    by 0x514E02: LexizeExec (ts_parse.c:203)
==4286==    by 0x5153ED: parsetext (ts_parse.c:405)
==4286==    by 0x521DD2: to_tsvector_byid (to_tsany.c:249)
==4286==    by 0x380261: ExecInterpExpr (execExprInterp.c:664)
==4286==    by 0x456069: ExecEvalExprSwitchContext (executor.h:301)
==4286==    by 0x456069: evaluate_expr (clauses.c:4873)
==4286==    by 0x4588B5: evaluate_function (clauses.c:4424)
==4286==    by 0x4588B5: simplify_function (clauses.c:4064)
==4286==    by 0x457519: eval_const_expressions_mutator (clauses.c:2676)
==4286==    by 0x3D615A: expression_tree_mutator (nodeFuncs.c:2903)
==4286==    by 0x458E43: simplify_function (clauses.c:4055)
==4286==    by 0x457519: eval_const_expressions_mutator (clauses.c:2676)
==4286==    by 0x3D5C02: expression_tree_mutator (nodeFuncs.c:2614)
==4286==    by 0x4572C1: eval_const_expressions_mutator (clauses.c:3671)
==4286==  Uninitialised value was created by a heap allocation
==4286==    at 0x4C2BB76: malloc (vg_replace_malloc.c:299)
==4286==    by 0x6A9667: AllocSetAlloc (aset.c:945)
==4286==    by 0x6B5AC7: palloc (mcxt.c:848)
==4286==    by 0x5238EA: get_tsearch_config_filename (ts_utils.c:55)
==4286==    by 0x5239AF: readstoplist (ts_utils.c:75)
==4286==    by 0xEAB2839: dsnowball_init (dict_snowball.c:201)
==4286==    by 0x684975: OidFunctionCall1Coll (fmgr.c:1327)
==4286==    by 0x679277: lookup_ts_dictionary_cache (ts_cache.c:337)
==4286==    by 0x514E02: LexizeExec (ts_parse.c:203)
==4286==    by 0x5153ED: parsetext (ts_parse.c:405)
==4286==    by 0x521DD2: to_tsvector_byid (to_tsany.c:249)
==4286==    by 0x380261: ExecInterpExpr (execExprInterp.c:664)
==4286==    by 0x456069: ExecEvalExprSwitchContext (executor.h:301)
==4286==    by 0x456069: evaluate_expr (clauses.c:4873)
==4286==    by 0x4588B5: evaluate_function (clauses.c:4424)
==4286==    by 0x4588B5: simplify_function (clauses.c:4064)
==4286==    by 0x457519: eval_const_expressions_mutator (clauses.c:2676)
==4286==    by 0x3D615A: expression_tree_mutator (nodeFuncs.c:2903)
==4286==    by 0x458E43: simplify_function (clauses.c:4055)
==4286==    by 0x457519: eval_const_expressions_mutator (clauses.c:2676)
==4286==    by 0x3D5C02: expression_tree_mutator (nodeFuncs.c:2614)
==4286==    by 0x4572C1: eval_const_expressions_mutator (clauses.c:3671)
==4286== 
{
   <insert_a_suppression_name_here>
   Memcheck:Cond
   fun:__wcsnlen_avx2
   fun:wcsrtombs
   fun:wcstombs
   fun:lowerstr_with_len.part.1
   fun:readstoplist
   fun:dsnowball_init
   fun:OidFunctionCall1Coll
   fun:lookup_ts_dictionary_cache
   fun:LexizeExec
   fun:parsetext
   fun:to_tsvector_byid
   fun:ExecInterpExpr
   fun:ExecEvalExprSwitchContext
   fun:evaluate_expr
   fun:evaluate_function
   fun:simplify_function
   fun:eval_const_expressions_mutator
   fun:expression_tree_mutator
   fun:simplify_function
   fun:eval_const_expressions_mutator
   fun:expression_tree_mutator
   fun:eval_const_expressions_mutator
}

I don't recall any recent changes in the area, so this might be a glibc
internal issue.

Greetings,

Andres Freund

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-04T20:16:15Z

Andres Freund <andres@anarazel.de> writes:
> On 2018-01-04 11:20:33 -0800, Andres Freund wrote:
>> Some packages on skink have been upgraded. It appears that there either
>> was a libc or valgrind change that made valgrind not recognize that a
>> pointer of 0 might not point anywhere :(

> ==5718== Invalid write of size 8
> ==5718==    at 0x40E3DD: ExecInterpExpr (execExprInterp.c:1117)
> ==5718==    by 0x40F5E9: ExecInterpExprStillValid (execExprInterp.c:1788)
> ==5718==    by 0xE6B0409: ExecEvalExpr (executor.h:282)

Are those line numbers supposed to match current HEAD?  1117 does not
contain any write AFAICS:

	if (!op->d.iocoerce.finfo_in->fn_strict || str != NULL)

> ==5718== Process terminating with default action of signal 11 (SIGSEGV)
> ==5718==  Access not within mapped region at address 0x20
> ==5718==    at 0x40E3DD: ExecInterpExpr (execExprInterp.c:1117)
> ==5718==    by 0x40F5E9: ExecInterpExprStillValid (execExprInterp.c:1788)

This would be consistent with op->d.iocoerce.finfo_in being NULL, I think,
but there is no way that execExpr.c could have created an EEOP_IOCOERCE
step without filling in the finfo_in pointer.

I think the correct conclusion is that this version of valgrind is
buggy as hell.  I wouldn't clutter our code with suppressions trying
to make it sort-of work.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2018-01-04T20:47:41Z

On 2018-01-04 15:16:15 -0500, Tom Lane wrote:
> Andres Freund <andres@anarazel.de> writes:
> > On 2018-01-04 11:20:33 -0800, Andres Freund wrote:
> >> Some packages on skink have been upgraded. It appears that there either
> >> was a libc or valgrind change that made valgrind not recognize that a
> >> pointer of 0 might not point anywhere :(
> 
> > ==5718== Invalid write of size 8
> > ==5718==    at 0x40E3DD: ExecInterpExpr (execExprInterp.c:1117)
> > ==5718==    by 0x40F5E9: ExecInterpExprStillValid (execExprInterp.c:1788)
> > ==5718==    by 0xE6B0409: ExecEvalExpr (executor.h:282)
> 
> Are those line numbers supposed to match current HEAD?

Well, 3e68686e2c55799234ecd020bd1621f913d65475, but that's pretty
close.

But I think it was just the result of a somehow not entirely clean
build, with plpgsql not being rebuilt when necessary. Not sure why/how,
but at least that means the epoll_pwait() suppression likely revive
skink to some degree.

I made sure that the valgrind version isn't affected (from mid last
year). After a forced rebuild survives a bit longer, but also encounters

==13750== Conditional jump or move depends on uninitialised value(s)
==13750==    at 0x6BA888C: __wcsnlen_avx2 (strlen-avx2.S:103)
==13750==    by 0x6AF2FF1: wcsrtombs (wcsrtombs.c:104)
==13750==    by 0x6A88A40: wcstombs (wcstombs.c:34)
==13750==    by 0x6BA76C: wchar2char (pg_locale.c:1641)
==13750==    by 0x653A7C: str_tolower (formatting.c:1591)

and various other related issues. I'm not sure if there's a legitimate
formatting.c issue or whether it's glibc changes around string handling
triggering spurious blurbs.

Greetings,

Andres Freund

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2018-01-04T22:14:26Z

On Fri, Jan 5, 2018 at 5:00 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> The early returns indicate that that problem is fixed;

Thanks for your help and patience with that.  I've made a list over
here so we don't lose track of the various things that should be
improved in this area, and will start a new thread when I have patches
to propose:  https://wiki.postgresql.org/wiki/Parallel_Hash

> but now that the
> noise level is down, it's possible to see that brolga is showing an actual
> crash in the PHJ test, perhaps one time in four.  So we're not out of
> the woods yet.  It seems to consistently look like this:
>
> 2017-12-21 17:34:52.092 EST [2252:4] LOG:  background worker "parallel worker" (PID 3584) was terminated by signal 11
> 2017-12-21 17:34:52.092 EST [2252:5] DETAIL:  Failed process was running: select count(*) from foo
>           left join (select b1.id, b1.t from bar b1 join bar b2 using (id)) ss
>           on foo.id < ss.id + 1 and foo.id > ss.id - 1;
> 2017-12-21 17:34:52.092 EST [2252:6] LOG:  terminating any other active server processes

That is a test of a parallel-aware hash join with a rescan (ie workers
get restarted repeatedly by the gather node reusing the DSM; maybe I
misunderstood some detail of the protocol for that).  I'll go and
review that code and try to reproduce the failure.  On the off-chance,
Andrew, is there any chance you have a core dump you could pull a
backtrace out of, on brolga?

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2018-01-22T10:17:47Z

On Thu, Dec 28, 2017 at 5:26 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Thomas Munro <thomas.munro@enterprisedb.com> writes:
>> On Thu, Dec 28, 2017 at 3:32 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>>> Aside from the instability problems, I'm pretty unhappy about how much
>>> the PHJ patch has added to the runtime of "make check".  I do not think
>>> any one feature can justify adding 20% to that.  Can't you cut down the
>>> amount of data processed by these new test cases?
>
>> Isn't that mostly because of the CV livelock problem?
>
> Hm, maybe.  I quoted the 20% figure on the basis of longfin's reports,
> not prairiedog's ... but it might be seeing some of the livelock effect
> too.
>
>> So without the effects of that bug it's only taking 2.4% longer than
>> commit fa330f9a.  Is that acceptable for a feature of this size and
>> complexity?  I will also look into making the data sets smaller.
>
> That sounds better, but it's still worth asking whether the tests
> could be quicker.

Here is a patch that halves the size of the test tables used.  I don't
want them to be too small because I want some some real parallel
processing at least sometimes.  On my slowest system with assertions
enabled this brings "time make check" from ~37.5s to ~36.9s.  I'm a
bit worried about choosing parameters that lead to instability across
the buildfarm, until I make the size estimation code a bit smarter[1],
so I tested a few variations that affect the alignment and size of
things (-m32, -malign-double, --disable-atomics, --disable-spinlocks)
and didn't see failures.  Does this pass repeatedly on gaur?

Since you mentioned longfin, I checked some historical "check"
runtimes and they seemed pretty erratic so I decided to bust out
gnuplot to try to see what's happening.  See attached, which goes back
as far as I could web-scrape from the buildfarm.  Three interesting
commits are shown with vertical lines, in this order from left to
right:

Commit fa330f9a "Add some regression tests that exercise hash join
code.", Nov 29.
Commit 18042840 "Add parallel-aware hash joins.", Dec 20
Commit aced5a92 "Rewrite ConditionVariableBroadcast() to avoid
live-lock.", Jan 5.

For comparison I also plotted data for two other machines whose times
are in a similar range.  It looks to me like longfin's average and
variation increased half way between fa330f9a and 18042840, somewhere
near Dec 7 to 9, when we went from ~40s +/- 1 to ~50s with several
seconds' variation.  Was there some other environmental change then on
that machine?  Do you see any commit that could explain that -- maybe
0a3edbb33?  Then maybe it also suffered a bit from livelock woes from
18042840 until aced5a92? It's hard to say and I'm not really sure what
to make of this, but it seems clear that you could draw the wrong
conclusion if you just picked a couple of random data points from that
animal, and that those other animals aren't affected too much by any
of these commits.

[1] https://wiki.postgresql.org/wiki/Parallel_Hash

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2018-01-22T11:47:17Z

On Mon, Jan 22, 2018 at 11:17 PM, Thomas Munro
<thomas.munro@enterprisedb.com> wrote:
> It looks to me like longfin's average and
> variation increased half way between fa330f9a and 18042840, somewhere
> near Dec 7 to 9, when we went from ~40s +/- 1 to ~50s with several
> seconds' variation.  Was there some other environmental change then on
> that machine?

Ahh.  That corresponds to the release of this patch:

https://support.apple.com/en-nz/HT208331

And indeed I see from the logs that the kernel changed:

uname -v = Darwin Kernel Version 17.2.0: Fri Sep 29 18:27:05 PDT 2017;
root:xnu-4570.20.62~3/RELEASE_X86_64
uname -v = Darwin Kernel Version 17.3.0: Thu Nov  9 18:09:22 PST 2017;
root:xnu-4570.31.3~1/RELEASE_X86_64

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-22T15:01:50Z

Thomas Munro <thomas.munro@enterprisedb.com> writes:
> On Mon, Jan 22, 2018 at 11:17 PM, Thomas Munro
> <thomas.munro@enterprisedb.com> wrote:
>> It looks to me like longfin's average and
>> variation increased half way between fa330f9a and 18042840, somewhere
>> near Dec 7 to 9, when we went from ~40s +/- 1 to ~50s with several
>> seconds' variation.  Was there some other environmental change then on
>> that machine?

> Ahh.  That corresponds to the release of this patch:
> https://support.apple.com/en-nz/HT208331

Yeah, I'm pretty sure that I installed that update immediately when
it came out.

There were some other strange things going on on that machine too;
I remember having noticed and killed a daemon process that seemed to be
stuck at 100% CPU.  That might explain the sudden dropoff in runtimes in
early January.  And seeing that the times seem to be back up, I looked
just now, and there it is again:

PID    COMMAND      %CPU TIME     #TH   #WQ  #PORT MEM    PURG   CMPRS  PGRP
360    fontworker   75.9 238 hrs  4     4    45-   28M    0B     0B     360
359    fontd        25.3 86:18:50 4/1   3/1  74    33M+   0B     1396K  359
76     logd         12.7 26:25:16 5     5    611   31M-   0B     0B     76
46241  top          2.6  00:01.04 1/1   0    23    2140K  0B     0B     46241

Weird --- my other macOS machines aren't doing that.

Anyway, it looks like we should write off these longfin timings as
ambient noise :-(

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-22T23:53:10Z

I wrote:
> Anyway, it looks like we should write off these longfin timings as
> ambient noise :-(

Here's a possibly more useful graph of regression test timings over
the last year.  I pulled this from the buildfarm database: it is the
reported runtime for the "installcheck-C" step in each successful
build of HEAD on dromedary, going back to Jan. 2017.  I picked dromedary
because I know that that machine hasn't gotten any software updates
nor is there anything else very interesting going on on it.  I dropped
three or four obvious outlier reports (possibly those ran during the
machine's nightly backup cron job).  The reported runtime is only
precise to 1s, and a couple seconds jitter is hardly surprising, so
there's a good deal of noise.  Still, it's possible to discern when
I put some effort into test runtime reduction back in April, and
it can be seen that things have gotten notably slower since the
beginning of November.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Robert Haas <robertmhaas@gmail.com> — 2018-01-23T19:24:56Z

On Mon, Jan 22, 2018 at 6:53 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Here's a possibly more useful graph of regression test timings over
> the last year.  I pulled this from the buildfarm database: it is the
> reported runtime for the "installcheck-C" step in each successful
> build of HEAD on dromedary, going back to Jan. 2017.  I picked dromedary
> because I know that that machine hasn't gotten any software updates
> nor is there anything else very interesting going on on it.  I dropped
> three or four obvious outlier reports (possibly those ran during the
> machine's nightly backup cron job).  The reported runtime is only
> precise to 1s, and a couple seconds jitter is hardly surprising, so
> there's a good deal of noise.  Still, it's possible to discern when
> I put some effort into test runtime reduction back in April, and
> it can be seen that things have gotten notably slower since the
> beginning of November.

Right, but this doesn't seem to show any big spike in the runtime at
the time when parallel hash was committed, or when the preparatory
patch to add test coverage for hash joins got committed.  Rather,
there's a gradual increase over time.  Either we're making the server
slower (which would be bad) or we're adding proper test coverage for
all the new features that we're adding (which would be good).  We
can't expect every feature patch to preserve the runtime of the tests
absolutely unchanged; figuring out what can be optimized is a separate
exercise from adding test coverage either for new things or for things
that weren't previously covered.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-23T23:10:56Z

Robert Haas <robertmhaas@gmail.com> writes:
> On Mon, Jan 22, 2018 at 6:53 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> Here's a possibly more useful graph of regression test timings over
>> the last year.  I pulled this from the buildfarm database: it is the
>> reported runtime for the "installcheck-C" step in each successful
>> build of HEAD on dromedary, going back to Jan. 2017.

> Right, but this doesn't seem to show any big spike in the runtime at
> the time when parallel hash was committed, or when the preparatory
> patch to add test coverage for hash joins got committed.  Rather,
> there's a gradual increase over time.

Well, there's just too much noise in this chart.  Let's try another
machine: prairiedog, which is a lot slower so that the 1s resolution
isn't such a limiting factor, and it's also one that I know there hasn't
been much of any system change in.

The first attached PNG shows the "installcheck-C" runtime for as far
back as the buildfarm database has the data, and the second zooms in
on events since late 2016.  As before, I've dropped individual outlier
results (those significantly slower than any nearby run) on the grounds
that they probably represent interference from nightly backups.  I also
attached the raw data (including outliers) in case anyone wants to do
their own analysis.

There is a very clear secular trend up in the longer data series,
which indicates that we're testing more stuff, which doesn't bother
me in itself as long as the time is well spent.  However, the trend
over the last two months is very bad, and I do not think that we can
point to any large improvement in test coverage that someone committed
since November.

Looking more closely at the shorter series, there are four pretty obvious
step changes since 2016-09.  The PNG's x-axis doesn't have enough
resolution to match these up to commits, but looking at the underlying
data, they clearly correspond to:

Branch: master Release: REL_10_BR [b801e1200] 2016-10-18 15:57:58 -0400
    Improve regression test coverage for hash indexes.

Branch: master Release: REL_10_BR [4a8bc39b0] 2017-04-12 16:17:53 -0400
    Speed up hash_index regression test.

Branch: master [fa330f9ad] 2017-11-29 16:06:50 -0800
    Add some regression tests that exercise hash join code.

Branch: master [180428404] 2017-12-21 00:43:41 -0800
    Add parallel-aware hash joins.

I thought that the hash index test case was excessively expensive for
what it covered, and I'm now thinking the same about hash joins.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Thomas Munro <thomas.munro@enterprisedb.com> — 2018-01-24T01:41:21Z

On Wed, Jan 24, 2018 at 12:10 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> There is a very clear secular trend up in the longer data series,
> which indicates that we're testing more stuff,

+1

> which doesn't bother
> me in itself as long as the time is well spent.  However, the trend
> over the last two months is very bad, and I do not think that we can
> point to any large improvement in test coverage that someone committed
> since November.

I'm not sure if coverage.postgresql.org has a way to view historical
reports so we can see the actual percentage change, but as I recall
it, commit fa330f9ad "Add some regression tests that exercise hash
join code." pushed nodeHash.c and possibly nodeHashJoin.c into green
territory on here:

https://coverage.postgresql.org/src/backend/executor/index.html

> Looking more closely at the shorter series, there are four pretty obvious
> step changes since 2016-09.  The PNG's x-axis doesn't have enough
> resolution to match these up to commits, but looking at the underlying
> data, they clearly correspond to:
>
> Branch: master Release: REL_10_BR [b801e1200] 2016-10-18 15:57:58 -0400
>     Improve regression test coverage for hash indexes.
>
> Branch: master Release: REL_10_BR [4a8bc39b0] 2017-04-12 16:17:53 -0400
>     Speed up hash_index regression test.
>
> Branch: master [fa330f9ad] 2017-11-29 16:06:50 -0800
>     Add some regression tests that exercise hash join code.

Joining check runtimes with the commit log (see attached), I see:

 2017-11-30 | fa330f9a | Add some regression tests that exercise  | 00:08:30
 2017-11-29 | 84940644 | New C function: bms_add_range            | 00:08:18

That's +2.4%.

> Branch: master [180428404] 2017-12-21 00:43:41 -0800
>     Add parallel-aware hash joins.

 2017-12-21 | cce1ecfc | Adjust assertion in GetCurrentCommandId. | 00:09:03
 2017-12-21 | 6719b238 | Rearrange execution of PARAM_EXTERN Para |
 2017-12-21 | 8a0596cb | Get rid of copy_partition_key            |
 2017-12-21 | 9ef6aba1 | Fix typo                                 |
 2017-12-21 | c98c35cd | Avoid putting build-location-dependent s |
 2017-12-21 | 59d1e2b9 | Cancel CV sleep during subtransaction ab |
 2017-12-21 | 18042840 | Add parallel-aware hash joins.           |
 2017-12-20 | f94eec49 | When passing query strings to workers, p | 00:08:45

That's +3.4%.  That's a bit more than I expected.  I saw 2.5% on my
development box and hoped that'd be OK for a complex feature with a
lot of paths to test.

But hang on a minute -- how did we get to 08:45 from 08:30 between
those commits?  Of course this is all noisy data and individual
samples are all over the place, but I think I see some signal here:

 2017-12-20 | f94eec49 | When passing query strings to workers, p | 00:08:45
 2017-12-19 | 7d3583ad | Test instrumentation of Hash nodes with  | 00:08:43
 2017-12-19 | 8526bcb2 | Try again to fix accumulation of paralle |
 2017-12-19 | 38fc5470 | Re-fix wrong costing of Sort under Gathe | 00:08:31
 2017-12-19 | 09a65f5a | Mark a few parallelism-related variables | 00:08:27

Both 8526bcb2 and 7d3583ad add Gather rescans.  Doesn't 8526bcb2 add a
query that forks 40 times?  I wonder how long it takes to start a
background worker on a Mac Cube.  From that commit:

+         ->  Gather (actual rows=9800 loops=10)
+               Workers Planned: 4
+               Workers Launched: 4
+               ->  Parallel Seq Scan on tenk1 (actual rows=1960 loops=50)

> I thought that the hash index test case was excessively expensive for
> what it covered, and I'm now thinking the same about hash joins.

Does join-test-shrink.patch (from my earlier message) help much, on
prairiedog?  It cut "check" time by ~1.5% on my low end machine.

-- 
Thomas Munro
http://www.enterprisedb.com

Re: pgsql: Add parallel-aware hash joins.

Robert Haas <robertmhaas@gmail.com> — 2018-01-24T18:11:22Z

On Tue, Jan 23, 2018 at 6:10 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Looking more closely at the shorter series, there are four pretty obvious
> step changes since 2016-09.  The PNG's x-axis doesn't have enough
> resolution to match these up to commits, but looking at the underlying
> data, they clearly correspond to:
>
> Branch: master Release: REL_10_BR [b801e1200] 2016-10-18 15:57:58 -0400
>     Improve regression test coverage for hash indexes.
>
> Branch: master Release: REL_10_BR [4a8bc39b0] 2017-04-12 16:17:53 -0400
>     Speed up hash_index regression test.
>
> Branch: master [fa330f9ad] 2017-11-29 16:06:50 -0800
>     Add some regression tests that exercise hash join code.
>
> Branch: master [180428404] 2017-12-21 00:43:41 -0800
>     Add parallel-aware hash joins.
>
> I thought that the hash index test case was excessively expensive for
> what it covered, and I'm now thinking the same about hash joins.

Hmm.  I guess I'm insulated from some of the problem here by my choice
of hardware. On my laptop, 'make check' takes between 25.5 and 26
seconds (on 28e04155f17cabda7a18aee31d130aa10e25ee86).  If I remove
the hash_index test from parallel_schedule, it still takes between
25.5 and 26 seconds.  If I also remove the join test in its entirety,
it drops down to 24-24.5 seconds.  If I put hash_index and join back
in the schedule file but revert join.sql and join.out to the version
just before fa330f9ad, it takes about 24.5 seconds.  So for me, the
additional hash index tests don't cost anything measurable and the
additional hash join tests cost about a second.  I think this probably
accounts for why committers other than you keep "adding so much time
to the regression tests".  On modern hardware, the costs just don't
matter.  As a further point of reference, on this machine, 9.5 stable
is 24.5-25 seconds, and 9.3 is 25.5-26 seconds, so from here it looks
like in the last 5 years the speed of 'make check' is within a half
second or so of the performance we had 5 years ago even though the
volume of the regression tests in terms of lines of SQL code has
increased by more than 50% in the same time period.

Now, how much should we care about the performance of software with a
planned release date of 2018 on hardware discontinued in 2001,
hardware that is apparently about 20 times slower than a modern
laptop?  Some, perhaps, but maybe not a whole lot.  Removing tests
that have found actual bugs because they cost runtime on ancient
systems that nobody uses for serious work doesn't make sense to me.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2018-01-24T18:20:18Z

On 2018-01-23 14:24:56 -0500, Robert Haas wrote:
> Right, but this doesn't seem to show any big spike in the runtime at
> the time when parallel hash was committed, or when the preparatory
> patch to add test coverage for hash joins got committed.  Rather,
> there's a gradual increase over time.  Either we're making the server
> slower (which would be bad) or we're adding proper test coverage for
> all the new features that we're adding (which would be good).  We
> can't expect every feature patch to preserve the runtime of the tests
> absolutely unchanged; figuring out what can be optimized is a separate
> exercise from adding test coverage either for new things or for things
> that weren't previously covered.

Agreed.

One the improvement front, my observation is that we rarely are actually
cpu bound across processes. One thing I've been wondering is whether we
can get a pretty large win from just rescheduling
parallel_schedule. There definitely are individual testfiles that take a
lot longer than others, but their positining in groups doesn't
necessarily reflect that.

Besides manually reordering the schedule, I think it might be time that
we improve pg_regress's scheduling. One big first step would e.g. be to
not manually limit the number of parallel tests in a group to 20, but
instead allow larger groups and only run a limited number of them in
parallel. If done right we could start the next test in a group as soon
as *one* task in a group has finished, rather than waiting for all of
them to finish as we currently do for (sub-)groups.

Besides larger groups, starting the next test(s) earlier, another way to
gain pretty large improvements would be a test schedule feature that
allowed to stat dependencies between tests. So instead of manually
grouping the schedule, have 'numerology' state that it depends on int2,
int4, int8, float4, float8, which means it can actually be started
earlier than it currently can in many cases.

Greetings,

Andres Freund

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2018-01-24T18:28:41Z

Hi,

On 2018-01-24 13:11:22 -0500, Robert Haas wrote:
> So for me, the additional hash index tests don't cost anything
> measurable and the additional hash join tests cost about a second.  I
> think this probably accounts for why committers other than you keep
> "adding so much time to the regression tests".  On modern hardware,
> the costs just don't matter.

I very much agree with the general sentiment, but a second of a 25s test
certainly isn't nothing.  As I've just written a few messages upthread,
I think we can hide the overall timing costs to a much larger degree
than we're doing, but I don't think we need not pay attention at all.

> Now, how much should we care about the performance of software with a
> planned release date of 2018 on hardware discontinued in 2001,
> hardware that is apparently about 20 times slower than a modern
> laptop?  Some, perhaps, but maybe not a whole lot.  Removing tests
> that have found actual bugs because they cost runtime on ancient
> systems that nobody uses for serious work doesn't make sense to me.

I again agree with the sentiment. One caveat is that old machines also
somewhat approximate testing with more instrumentation / debugging
enabled (say valgrind, CLOBBER_CACHE_ALWAYS, etc). So removing excessive
test overhead has still quite some benefits. But I definitely do not
want to lower coverage to achieve it.

Greetings,

Andres Freund

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-24T19:31:47Z

Andres Freund <andres@anarazel.de> writes:
> On 2018-01-24 13:11:22 -0500, Robert Haas wrote:
>> Now, how much should we care about the performance of software with a
>> planned release date of 2018 on hardware discontinued in 2001,
>> hardware that is apparently about 20 times slower than a modern
>> laptop?  Some, perhaps, but maybe not a whole lot.  Removing tests
>> that have found actual bugs because they cost runtime on ancient
>> systems that nobody uses for serious work doesn't make sense to me.

> I again agree with the sentiment.

I find that to be a completely bogus straw-man argument.  The point of
looking at the prairiedog time series is just to see a data series in
which the noise level is small enough to discern the signal.  If anyone's
got years worth of data off a more modern machine, and they can extract
a signal from that, by all means let's consider that data instead.  But
there's no clear argument (or at least you have not made one) that says
that prairiedog's relative timings don't match what we'd get on more
modern machines.

Now, what *is* a relevant objection is that most of us care more about
the runtime of the parallelized regression tests than serial tests.
I did not use prairiedog's "make check" timings in these graphs because
that would include "make install" and initdb timings, adding noise and
overhead and probably making it harder to see what's going on.  But
it's perfectly fair to want to optimize that case not the serial case.

However ... if you spend any time looking at the behavior of that,
the hashjoin tests are still problematic.  I instrumented the parallel
tests by turning on log_disconnections so as to get per-test-script
timings, and what I find to be the slowest steps on my development
workstation are

[pg_regress/rowsecurity] 0.517
[pg_regress/partition_join] 0.535
[pg_regress/updatable_views] 0.546
[pg_regress/stats] 0.566
[pg_regress/triggers] 0.618
[pg_regress/foreign_data] 0.642
[pg_regress/stats_ext] 0.670
[pg_regress/select_parallel] 0.828
[pg_regress/create_index] 0.916
[pg_regress/alter_table] 1.187
[pg_regress/gist] 1.283
[pg_regress/join] 1.923
[pg_regress/plpgsql] 3.100

(The overall runtime for "make installcheck-parallel" on this machine
is about 17.3 seconds right now.)  The next slowest test script in
the join test's group is "update", at 0.373 seconds; so over 1.5 sec
of the total 17.3 sec runtime is being spent solely in the join script.

Running the same test on the v10 branch, the slowest steps are

[pg_regress/join] 0.521
[pg_regress/rowsecurity] 0.521
[pg_regress/updatable_views] 0.554
[pg_regress/triggers] 0.624
[pg_regress/foreign_data] 0.647
[pg_regress/stats_ext] 0.675
[pg_regress/select_parallel] 0.690
[pg_regress/create_index] 0.928
[pg_regress/gist] 1.020
[pg_regress/alter_table] 1.120
[pg_regress/plpgsql] 3.217

so join has gotten about 1 second slower since v10, and that time is
coming entirely out of developers' hides despite parallelism because
it was already the slowest in its group.

So I continue to maintain that an unreasonable fraction of the total
resources devoted to the regular regression tests is going into these
new hashjoin tests.

Based on these numbers, it seems like one easy thing we could do to
reduce parallel check time is to split the plpgsql test into several
scripts that could run in parallel.  But independently of that,
I think we need to make an effort to push hashjoin's time back down.

> One caveat is that old machines also
> somewhat approximate testing with more instrumentation / debugging
> enabled (say valgrind, CLOBBER_CACHE_ALWAYS, etc). So removing excessive
> test overhead has still quite some benefits. But I definitely do not
> want to lower coverage to achieve it.

I don't want to lower coverage either.  I do want some effort to be
spent on achieving test coverage intelligently, rather than just throwing
large test cases at the code without consideration of the costs.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-24T19:57:04Z

I wrote:
> I find that to be a completely bogus straw-man argument.  The point of
> looking at the prairiedog time series is just to see a data series in
> which the noise level is small enough to discern the signal.  If anyone's
> got years worth of data off a more modern machine, and they can extract
> a signal from that, by all means let's consider that data instead.

Just to make the point, I scraped the numbers for skink's "installcheck"
and "check" steps, which are data series I imagine at least Andres will
concede are worth paying attention to.  I made no attempt to clean
outliers, so these curves are pretty noisy, but I think there is a very
clear upward bump since mid-December.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2018-01-24T20:08:09Z

Hi,

On 2018-01-24 14:31:47 -0500, Tom Lane wrote:
> However ... if you spend any time looking at the behavior of that,
> the hashjoin tests are still problematic.

I think my main problem with your arguments is that you basically seem
to say that one of the more complex features in postgres can't increase
the test time. And I just don't agree with that.  If we can reduce some
unnecessary overhead (as Thomas iirc has done somwhere nearby) - great,
if we can hide the overhead by scheduling the test better or breaking it
up - also great. But if that's a good chunk of work I think it's
entirely reasonable to not necessarily consider that the best use of
time.

It doesn't seem too surprising that a test that relies on starting
multiple background processes in multiple places will be among the more
expensive ones.  We clearly would e.g. benefit from being able to reuse
workers, to avoid constantly starting/stopping them.

> (The overall runtime for "make installcheck-parallel" on this machine
> is about 17.3 seconds right now.)  The next slowest test script in
> the join test's group is "update", at 0.373 seconds; so over 1.5 sec
> of the total 17.3 sec runtime is being spent solely in the join script.

Might be worth breaking up join a bit, that won't get rid of all the
wall time overhead, but should reduce it. Reordering to run parallel to
other slow tests might also be worthwhile.

> So I continue to maintain that an unreasonable fraction of the total
> resources devoted to the regular regression tests is going into these
> new hashjoin tests.

> > One caveat is that old machines also
> > somewhat approximate testing with more instrumentation / debugging
> > enabled (say valgrind, CLOBBER_CACHE_ALWAYS, etc). So removing excessive
> > test overhead has still quite some benefits. But I definitely do not
> > want to lower coverage to achieve it.
> 
> I don't want to lower coverage either.  I do want some effort to be
> spent on achieving test coverage intelligently, rather than just throwing
> large test cases at the code without consideration of the costs.

I think this accusation is unfair. Are you really suggesting that nobody
else cares about the runtime of the new tests? Just because other
people's tradeoffs come down at a somewhat different place, doesn't mean
they add tests "without consideration of the costs".

> Based on these numbers, it seems like one easy thing we could do to
> reduce parallel check time is to split the plpgsql test into several
> scripts that could run in parallel.  But independently of that,
> I think we need to make an effort to push hashjoin's time back down.

If we had a dependency based system as I suggested nearby, we could have
pg_regress order the tests so that the slowest ones that have
dependencies fulfilled are started first...

Greetings,

Andres Freund

Re: pgsql: Add parallel-aware hash joins.

Alvaro Herrera <alvherre@alvh.no-ip.org> — 2018-01-24T20:18:26Z

Andres Freund wrote:

> Besides larger groups, starting the next test(s) earlier, another way to
> gain pretty large improvements would be a test schedule feature that
> allowed to stat dependencies between tests. So instead of manually
> grouping the schedule, have 'numerology' state that it depends on int2,
> int4, int8, float4, float8, which means it can actually be started
> earlier than it currently can in many cases.

Yeah, I proposed this a decade ago but never had the wits to write the
code.

It would be very useful for running tests standalone, too -- much as I
dislike 'make installcheck' taking half a minute, I dislike much more
having to take 5 minutes each time to figure out that create_table
depends on box, polygon, create_function, yadda yadda.

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Re: pgsql: Add parallel-aware hash joins.

Alvaro Herrera <alvherre@alvh.no-ip.org> — 2018-01-24T20:20:58Z

Thomas Munro wrote:
> On Wed, Jan 24, 2018 at 12:10 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

> > However, the trend over the last two months is very bad, and I do
> > not think that we can point to any large improvement in test
> > coverage that someone committed since November.
> 
> I'm not sure if coverage.postgresql.org has a way to view historical
> reports so we can see the actual percentage change,

It does not.  I have had that in my to-do list for a while, but haven't
gotten around to it.

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-24T20:36:35Z

Alvaro Herrera <alvherre@alvh.no-ip.org> writes:
> Andres Freund wrote:
>> Besides larger groups, starting the next test(s) earlier, another way to
>> gain pretty large improvements would be a test schedule feature that
>> allowed to stat dependencies between tests. So instead of manually
>> grouping the schedule, have 'numerology' state that it depends on int2,
>> int4, int8, float4, float8, which means it can actually be started
>> earlier than it currently can in many cases.

> Yeah, I proposed this a decade ago but never had the wits to write the
> code.

There'd be a lot of followup work to sanitize the tests better.  For
instance, if two tests transiently create tables named "foo", it doesn't
matter as long as they're not in the same group.  It would matter with
this.

There are things we could do to mitigate that --- one attractive idea
is to have each test create its own schema for transient objects.
The limiting factor is that we don't want the test scripts to change
so much that back-patching tests becomes impossible.  (Or at least,
I'd not like that.)

I'm concerned that we'd end up with a higher number of irreproducible
test failures with no good way to investigate them.

> It would be very useful for running tests standalone, too -- much as I
> dislike 'make installcheck' taking half a minute, I dislike much more
> having to take 5 minutes each time to figure out that create_table
> depends on box, polygon, create_function, yadda yadda.

Yeah, if we could say "run just this test and its needed precursors",
that'd be a huge win in a lot of situations.

Definitely seems like an idea worth pursuing.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2018-01-24T20:43:59Z

Hi,

On 2018-01-24 17:18:26 -0300, Alvaro Herrera wrote:
> Andres Freund wrote:
> > Besides larger groups, starting the next test(s) earlier, another way to
> > gain pretty large improvements would be a test schedule feature that
> > allowed to stat dependencies between tests. So instead of manually
> > grouping the schedule, have 'numerology' state that it depends on int2,
> > int4, int8, float4, float8, which means it can actually be started
> > earlier than it currently can in many cases.
> 
> Yeah, I proposed this a decade ago but never had the wits to write the
> code.

It shouldn't be too hard, right? Leaving defining the file format,
parsing it, creating the new schedule with depencencies and adapting
tests aside (hah), it mostly seems a relatively simple graph ordering /
topological sort problem, right?  If we keep the timings from an earlier
run somwhere, we can use the timing of runs as edge weights, making the
schedule better.

> It would be very useful for running tests standalone, too -- much as I
> dislike 'make installcheck' taking half a minute, I dislike much more
> having to take 5 minutes each time to figure out that create_table
> depends on box, polygon, create_function, yadda yadda.

Oh, that's a good point.

- Andres

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2018-01-24T20:47:33Z

Hi,

On 2018-01-24 15:36:35 -0500, Tom Lane wrote:
> There'd be a lot of followup work to sanitize the tests better.  For
> instance, if two tests transiently create tables named "foo", it doesn't
> matter as long as they're not in the same group.  It would matter with
> this.

Right. I suspect we'd initially end up with a schedule that'd had
dependencies pretty similar to what we have now as groups. I suspect
that even with a very small number of changes we'd get a lot better
timings.

> There are things we could do to mitigate that --- one attractive idea
> is to have each test create its own schema for transient objects.
> The limiting factor is that we don't want the test scripts to change
> so much that back-patching tests becomes impossible.  (Or at least,
> I'd not like that.)

I think a lot of temporary, potentially conflicting, objects are already
created as TEMPORARY. Adding a few more temporary markers shouldn't be
too hard.

> I'm concerned that we'd end up with a higher number of irreproducible
> test failures with no good way to investigate them.

Hm. We probably should dump the used ordering of tests somwhere upon
failure, to make it easier to debug.

Greetings,

Andres Freund

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-24T20:58:16Z

Andres Freund <andres@anarazel.de> writes:
> On 2018-01-24 17:18:26 -0300, Alvaro Herrera wrote:
>> Yeah, I proposed this a decade ago but never had the wits to write the
>> code.

> It shouldn't be too hard, right? Leaving defining the file format,
> parsing it, creating the new schedule with depencencies and adapting
> tests aside (hah), it mostly seems a relatively simple graph ordering /
> topological sort problem, right?

Yeah.  We already have topo sort code in pg_dump, maybe we could push that
into someplace like src/common or src/fe_utils?  Although pg_dump hasn't
got any need for edge weights, so maybe sharing code isn't worth it.

We could flush the existing schedule files and use a simple format like
	testname: list of earlier tests it depends on
(I guess there would be more properties than just the dependencies,
but still not hard to parse.)

> If we keep the timings from an earlier
> run somwhere, we can use the timing of runs as edge weights, making the
> schedule better.

I think we could just use constant values hand-coded in the schedule file.
It might occasionally be worth updating them, but realistically it's not
going to matter that they be very accurate.  Probably weights like 1, 2,
and 3 would be plenty ;-)

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-24T21:01:38Z

Andres Freund <andres@anarazel.de> writes:
> On 2018-01-24 15:36:35 -0500, Tom Lane wrote:
>> I'm concerned that we'd end up with a higher number of irreproducible
>> test failures with no good way to investigate them.

> Hm. We probably should dump the used ordering of tests somwhere upon
> failure, to make it easier to debug.

The progress-display output of pg_regress would need a complete rethink
anyhow.  First thought is to emit two lines per test, one when we
launch it and one when it finishes and we check the results:

foreign_data: launched
...
foreign_data: ok           (or FAILED)

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2018-01-24T21:07:07Z

Hi,

On 2018-01-24 15:58:16 -0500, Tom Lane wrote:
> Yeah.  We already have topo sort code in pg_dump, maybe we could push that
> into someplace like src/common or src/fe_utils?  Although pg_dump hasn't
> got any need for edge weights, so maybe sharing code isn't worth it.

I suspect it may be more work to share than worth it, but either way, it
shouldn't be too hard.  Hm, isn't dbObjectTypePriority kinda an edge
weight? Seems like we properly could implement it as that.

> We could flush the existing schedule files and use a simple format like
> 	testname: list of earlier tests it depends on
> (I guess there would be more properties than just the dependencies,
> but still not hard to parse.)

Yea, I think there'd need to be a few more. There's some tests that use
multiple connections, and I suspect it'll be useful to have "implicit"
ordering dependencies for a few test, like a "barrier". Otherwise
e.g. the tablespace test will be annoying to order.

> > If we keep the timings from an earlier
> > run somwhere, we can use the timing of runs as edge weights, making the
> > schedule better.
> 
> I think we could just use constant values hand-coded in the schedule file.
> It might occasionally be worth updating them, but realistically it's not
> going to matter that they be very accurate.  Probably weights like 1, 2,
> and 3 would be plenty ;-)

The reason I like the idea of using prior tests as scheduling input is
that the slowness actually depends a lot on the type of machine its run
on, and more importantly on things like valgrind, CCA, fsync=on/off,
jit=on/off (far most expensive tests is e.g. the recursion test in
errors.sql :)).

Greetings,

Andres Freund

Re: pgsql: Add parallel-aware hash joins.

Robert Haas <robertmhaas@gmail.com> — 2018-01-24T21:08:50Z

On Wed, Jan 24, 2018 at 2:31 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> I find that to be a completely bogus straw-man argument.  The point of
> looking at the prairiedog time series is just to see a data series in
> which the noise level is small enough to discern the signal.  If anyone's
> got years worth of data off a more modern machine, and they can extract
> a signal from that, by all means let's consider that data instead.  But
> there's no clear argument (or at least you have not made one) that says
> that prairiedog's relative timings don't match what we'd get on more
> modern machines.

There is no need to collect years of data in order to tell whether or
not the time to run the tests has increased by as much on developer
machines as it has on prairiedog.  You showed the time going from 3:36
to 8:09 between 2014 and the present.  That is a 2.26x increase.  It
is obvious from the numbers I posted before that no such increase has
taken place in the time it takes to run 'make check' on my relatively
modern laptop.  Whatever difference exists is measured in
milliseconds.

> so join has gotten about 1 second slower since v10, and that time is
> coming entirely out of developers' hides despite parallelism because
> it was already the slowest in its group.
>
> So I continue to maintain that an unreasonable fraction of the total
> resources devoted to the regular regression tests is going into these
> new hashjoin tests.

I think there is an affirmative desire on the part of many
contributors to have newer features tested more thoroughly than old
ones were.  That will tend to mean that features added more recently
have test suites that are longer-running compared to the value of the
feature they test than what we had in the past.  When this has been
discussed at developer meetings, everyone except you (and to a lesser
extent me) has been in favor of this.  Even if that meant that you had
to wait 1 extra second every time you run 'make check', I would judge
that worthwhile.  But it probably doesn't, because there are a lot of
things that can be done to improve this situation, such as...

> Based on these numbers, it seems like one easy thing we could do to
> reduce parallel check time is to split the plpgsql test into several
> scripts that could run in parallel.  But independently of that,
> I think we need to make an effort to push hashjoin's time back down.

...this.  Also, the same technique could probably be applied to the
join test itself.  I think Thomas just added the tests to that file
because it already existed, but there's nothing to say that the file
couldn't be split into several chunks.  On a quick look, it looks to
me as though that file is testing a lot of pretty different things,
and it's one of the largest test case files, accounting for ~3% of the
total test suite by itself.

Another thing you could do is consider applying the patch Thomas
already posted to reduce the size of the tables involved.  The problem
is that, for you and the buildfarm to be happy, the tests have to (1)
run near-instantaneously even on thoroughly obsolete hardware, (2)
give exactly the same answers on 32-bit systems, 64-bit systems,
Linux, Windows, AIX, HP-UX, etc., and (3) give those same exact
answers 100% deterministically on all of those platforms.  Parallel
query is inherently non-deterministic about things like how much work
goes to each worker, and I think that really small tests will tend to
show more edge cases like one worker not doing anything.  So it might
be that if we cut down the sizes of the test cases we'll spend more
time troubleshooting the resulting instability than any developer time
we would've saved by reducing the runtime.  But we can try it.

>> One caveat is that old machines also
>> somewhat approximate testing with more instrumentation / debugging
>> enabled (say valgrind, CLOBBER_CACHE_ALWAYS, etc). So removing excessive
>> test overhead has still quite some benefits. But I definitely do not
>> want to lower coverage to achieve it.
>
> I don't want to lower coverage either.  I do want some effort to be
> spent on achieving test coverage intelligently, rather than just throwing
> large test cases at the code without consideration of the costs.

I don't believe that any such thing is occurring, and I think it's
wrong of you to imply that these test cases were added
unintelligently.  To me, that seems like an ad hominum attack on both
Thomas (who spent a year or more developing the feature those test
cases exercise) and Andres (who committed them).

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Re: pgsql: Add parallel-aware hash joins.

Robert Haas <robertmhaas@gmail.com> — 2018-01-24T21:09:56Z

On Wed, Jan 24, 2018 at 4:01 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> The progress-display output of pg_regress would need a complete rethink
> anyhow.  First thought is to emit two lines per test, one when we
> launch it and one when it finishes and we check the results:
>
> foreign_data: launched
> ...
> foreign_data: ok           (or FAILED)

I suspect that first line would only be interesting on the very rare
occasions when test hangs.  I'm not sure it would be good to add that
much chatter.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Re: pgsql: Add parallel-aware hash joins.

Andres Freund <andres@anarazel.de> — 2018-01-24T21:29:16Z

Hi,

On 2018-01-22 23:17:47 +1300, Thomas Munro wrote:
> On Thu, Dec 28, 2017 at 5:26 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Here is a patch that halves the size of the test tables used.  I don't
> want them to be too small because I want some some real parallel
> processing at least sometimes.  On my slowest system with assertions
> enabled this brings "time make check" from ~37.5s to ~36.9s.  I'm a
> bit worried about choosing parameters that lead to instability across
> the buildfarm, until I make the size estimation code a bit smarter[1],
> so I tested a few variations that affect the alignment and size of
> things (-m32, -malign-double, --disable-atomics, --disable-spinlocks)
> and didn't see failures.  Does this pass repeatedly on gaur?

I'd say, let's just commit it and see?

Will do so soon if nobody protests.

Greetings,

Andres Freund

reducing isolation tests runtime

Alvaro Herrera <alvherre@alvh.no-ip.org> — 2018-01-24T23:10:06Z

On the subject of test total time, we could paralelize isolation tests.
Right now "make check" in src/test/isolation takes 1:16 on my machine.
Test "timeouts" takes full 40s of that, with nothing running in parallel
-- the machine is completely idle.

Seems like we can have a lot of time back just by changing the schedule
to use multiple tests per line (in particular, put the other slow tests
together with timeouts), per the attached; with this new schedule,
isolation takes 44 seconds in my machine -- a win of 32 seconds.  We can
win a couple of additional second by grouping a few other lines, but
this is the biggest win.

(This needs to be adjusted because some table names in the specs
conflict.)

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Re: reducing isolation tests runtime

Robert Haas <robertmhaas@gmail.com> — 2018-01-24T23:30:20Z

On Wed, Jan 24, 2018 at 6:10 PM, Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:
> On the subject of test total time, we could paralelize isolation tests.
> Right now "make check" in src/test/isolation takes 1:16 on my machine.
> Test "timeouts" takes full 40s of that, with nothing running in parallel
> -- the machine is completely idle.
>
> Seems like we can have a lot of time back just by changing the schedule
> to use multiple tests per line (in particular, put the other slow tests
> together with timeouts), per the attached; with this new schedule,
> isolation takes 44 seconds in my machine -- a win of 32 seconds.  We can
> win a couple of additional second by grouping a few other lines, but
> this is the biggest win.
>
> (This needs to be adjusted because some table names in the specs
> conflict.)

Oh, cool.  Yes, the time the isolation tests take to run is quite
annoying.  I didn't realize it would be so easy to run it in parallel.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Re: reducing isolation tests runtime

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-24T23:35:00Z

Robert Haas <robertmhaas@gmail.com> writes:
> On Wed, Jan 24, 2018 at 6:10 PM, Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:
>> On the subject of test total time, we could paralelize isolation tests.

> Oh, cool.  Yes, the time the isolation tests take to run is quite
> annoying.  I didn't realize it would be so easy to run it in parallel.

+1 to both --- I hadn't realized we had enough infrastructure to do this
in parallel, either.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-24T23:37:18Z

Andres Freund <andres@anarazel.de> writes:
> On 2018-01-22 23:17:47 +1300, Thomas Munro wrote:
>> Here is a patch that halves the size of the test tables used.
>> ... Does this pass repeatedly on gaur?

> I'd say, let's just commit it and see?

Oh, sorry, I forgot I was on the hook to check that.  The news isn't
good: I got one pass, and then this on the second iteration:

*** /home/postgres/pgsql/src/test/regress/expected/join.out     Wed Jan 24 18:07:42 2018
--- /home/postgres/pgsql/src/test/regress/results/join.out      Wed Jan 24 18:26:53 2018
***************
*** 6122,6128 ****
  $$);
   initially_multibatch | increased_batches 
  ----------------------+-------------------
!  t                    | f
  (1 row)
  
  rollback to settings;
--- 6122,6128 ----
  $$);
   initially_multibatch | increased_batches 
  ----------------------+-------------------
!  t                    | t
  (1 row)
  
  rollback to settings;

======================================================================

			regards, tom lane

Re: reducing isolation tests runtime

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-24T23:46:59Z

Alvaro Herrera <alvherre@alvh.no-ip.org> writes:
> On the subject of test total time, we could paralelize isolation tests.
> Right now "make check" in src/test/isolation takes 1:16 on my machine.
> Test "timeouts" takes full 40s of that, with nothing running in parallel
> -- the machine is completely idle.

BTW, one small issue there is that the reason the timeouts test is so
slow is that we have to use multi-second timeouts to be sure slower
buildfarm critters (eg valgrind animals) will get the expected results.
So I'm worried that if the machine isn't otherwise idle, we will get
random failures.

We could parallelize the rest of those tests and leave timeouts in its own
group.  That cuts the payback a lot :-( but might still be worth doing.
Or maybe tweak things so that the buildfarm runs a serial schedule but
manual testing doesn't.  Or we could debate how important the timeout
tests really are ... or think harder about how to make them reproducible.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-25T04:02:28Z

Robert Haas <robertmhaas@gmail.com> writes:
> There is no need to collect years of data in order to tell whether or
> not the time to run the tests has increased by as much on developer
> machines as it has on prairiedog.  You showed the time going from 3:36
> to 8:09 between 2014 and the present.  That is a 2.26x increase.  It
> is obvious from the numbers I posted before that no such increase has
> taken place in the time it takes to run 'make check' on my relatively
> modern laptop.  Whatever difference exists is measured in
> milliseconds.

I may be wasting my breath here, but in one more attempt to convince
you that "time make check" on your laptop is not the only number that
anyone should be interested in, here are some timings off my development
workstation.  These are timings off current tip of each release branch,
all the same build options etc, so very comparable:

9.4
[ don't remember the equivalent to top-level make temp-install here ]
top-level make check 24.725s
installcheck-parallel 15.383s
installcheck 27.560s

9.5
make temp-install 3.702s
initdb 2.328s
top-level make check 24.709s
installcheck-parallel 16.632s
installcheck 32.427s

9.6
make temp-install 3.971s
initdb 2.178s
top-level make check 24.048s
installcheck-parallel 15.889s
installcheck 32.775s

10
make temp-install 4.051s
initdb 1.363s
top-level make check 21.784s
installcheck-parallel 15.209s
installcheck 31.938s

HEAD
make temp-install 4.048s
initdb 1.361s
top-level make check 24.027s
installcheck-parallel 16.914s
installcheck 35.745s

I copied-and-pasted the "real time" results of time(1) for each of these,
not bothering to round them off; but the numbers are only reproducible
to half a second or so, so there's no significance in the last couple
digits.  Most numbers above are the minimum of 2 or more runs.

What I take away here is that there's been a pretty steep cost increase
for the regression tests since v10, and that is *not* in line with the
historical average.  In fact, in most years we've bought enough speedup
through performance improvements to pay for the test cases we added.
This is masked if you just eyeball "make check" compared to several years
ago.  But to do that, you have to ignore the fact that we made substantial
improvements in the runtime of initdb as well as the regression tests
proper circa v10, and we've now thrown that away and more.

So I remain dissatisfied with these results, particularly because in
my own work habits, the time for "make installcheck-parallel" is way
more interesting than "make check".  I avoid redoing installs and
initdbs if I don't need them.

> ... Even if that meant that you had
> to wait 1 extra second every time you run 'make check', I would judge
> that worthwhile.

I think this is a bad way of looking at it.  Sure, in terms of
one developer doing one test run, a second or two means nothing.
But for instance, if you want to do 100 test runs in hope of catching
a seldom-reproduced bug, it adds up.  It also adds up when you consider
the aggregate effort expended by the buildfarm, or the time you have
to wait to see buildfarm results.

> Another thing you could do is consider applying the patch Thomas
> already posted to reduce the size of the tables involved.

Yeah.  What I thought this argument was about was convincing *you*
that that would be a reasonable patch to apply.  It seems from my
experiment on gaur that that patch makes the results unstable, so
if we can do it at all it will need more work.  But I do think
it's worth putting in some more sweat here.  In the long run the
time savings will add up.

			regards, tom lane

Re: pgsql: Add parallel-aware hash joins.

Robert Haas <robertmhaas@gmail.com> — 2018-01-25T04:39:26Z

On Wed, Jan 24, 2018 at 11:02 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> I may be wasting my breath here, but in one more attempt to convince
> you that "time make check" on your laptop is not the only number that
> anyone should be interested in, ...

Now that is not what I said, or at least not what I intended to say.
I'm taking the position that what happens on a developer laptop is
more relevant than what happens on an ancient buildfarm critter.  I am
NOT taking the position that my particular laptop or even developer
laptops generally are the *only* thing that matters.  I gave the
numbers from my laptop because it's the one I can test.  I cannot
easily test yours.

> What I take away here is that there's been a pretty steep cost increase
> for the regression tests since v10, and that is *not* in line with the
> historical average.  In fact, in most years we've bought enough speedup
> through performance improvements to pay for the test cases we added.
> This is masked if you just eyeball "make check" compared to several years
> ago.  But to do that, you have to ignore the fact that we made substantial
> improvements in the runtime of initdb as well as the regression tests
> proper circa v10, and we've now thrown that away and more.

OK, I can see some increase there.  It's definitely more for you than
it is for me, since you see something like a 10% slowdown between 10
and master and I see basically no difference.  I don't know why that
should be, but I'm not doubting you.

> So I remain dissatisfied with these results, particularly because in
> my own work habits, the time for "make installcheck-parallel" is way
> more interesting than "make check".  I avoid redoing installs and
> initdbs if I don't need them.

I'm not that efficient, but noted.

>> ... Even if that meant that you had
>> to wait 1 extra second every time you run 'make check', I would judge
>> that worthwhile.
>
> I think this is a bad way of looking at it.  Sure, in terms of
> one developer doing one test run, a second or two means nothing.
> But for instance, if you want to do 100 test runs in hope of catching
> a seldom-reproduced bug, it adds up.  It also adds up when you consider
> the aggregate effort expended by the buildfarm, or the time you have
> to wait to see buildfarm results.

Sure, but as Andres said, you also have to consider how much developer
time it takes to recoup the savings.  If it takes a day of development
time to save a second of regression test time, that might be worth it;
if it takes a month, color me doubtful, especially if the result is a
more fragile test that happens to pass on all of the buildfarm
critters we have now but might fail spuriously when somebody adds a
new one.

> Yeah.  What I thought this argument was about was convincing *you*
> that that would be a reasonable patch to apply.  It seems from my
> experiment on gaur that that patch makes the results unstable, so
> if we can do it at all it will need more work.  But I do think
> it's worth putting in some more sweat here.  In the long run the
> time savings will add up.

Why me?  Thomas wrote the patch, Andres committed it, and you
complained about it.  I'm just along for the ride.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Re: reducing isolation tests runtime

Alvaro Herrera <alvherre@alvh.no-ip.org> — 2018-01-25T14:37:26Z

Tom Lane wrote:
> Alvaro Herrera <alvherre@alvh.no-ip.org> writes:
> > On the subject of test total time, we could paralelize isolation tests.
> > Right now "make check" in src/test/isolation takes 1:16 on my machine.
> > Test "timeouts" takes full 40s of that, with nothing running in parallel
> > -- the machine is completely idle.
> 
> BTW, one small issue there is that the reason the timeouts test is so
> slow is that we have to use multi-second timeouts to be sure slower
> buildfarm critters (eg valgrind animals) will get the expected results.
> So I'm worried that if the machine isn't otherwise idle, we will get
> random failures.

I think we could solve this by putting in the same parallel group only
slow tests that mostly sleeps, ie. nothing that would monopolize CPU for
long enough to cause a problem.  Concretely:

test: timeouts tuplelock-update deadlock-hard deadlock-soft-2

all of these tests have lots of sleeps and don't go through a lot of
data.  (Compared to the previous patch, I removed alter-table-1, which
uses a thousand tuples, and multiple-row-versions, which uses 100k; also
removed receipt-report which uses a large number of permutations.)

Timings:
	timeouts		40.3s
	tuplelock-update	10.5s
	deadlock-hard		10.9s
	deadlock-soft-2		5.4s

alter-table-1 takes 1.5s, receipt-report 1.2s and there's nothing else
that takes above 1s, so I think this is good enough -- we can still have
the whole thing run in ~45 seconds without the hazard you describe.

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Re: reducing isolation tests runtime

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-25T15:01:19Z

Alvaro Herrera <alvherre@alvh.no-ip.org> writes:
> Tom Lane wrote:
>> Alvaro Herrera <alvherre@alvh.no-ip.org> writes:
>>> On the subject of test total time, we could paralelize isolation tests.

>> BTW, one small issue there is that the reason the timeouts test is so
>> slow is that we have to use multi-second timeouts to be sure slower
>> buildfarm critters (eg valgrind animals) will get the expected results.
>> So I'm worried that if the machine isn't otherwise idle, we will get
>> random failures.

> I think we could solve this by putting in the same parallel group only
> slow tests that mostly sleeps, ie. nothing that would monopolize CPU for
> long enough to cause a problem.  Concretely:
> test: timeouts tuplelock-update deadlock-hard deadlock-soft-2

OK, but there'd better be a comment there explaining the concern
very precisely, or somebody will break it.

			regards, tom lane

Re: reducing isolation tests runtime

Alvaro Herrera <alvherre@alvh.no-ip.org> — 2018-01-25T20:34:15Z

Tom Lane wrote:
> Alvaro Herrera <alvherre@alvh.no-ip.org> writes:

> > I think we could solve this by putting in the same parallel group only
> > slow tests that mostly sleeps, ie. nothing that would monopolize CPU for
> > long enough to cause a problem.  Concretely:
> > test: timeouts tuplelock-update deadlock-hard deadlock-soft-2
> 
> OK, but there'd better be a comment there explaining the concern
> very precisely, or somebody will break it.

Here's a concrete proposal.  Runtime is 45.7 seconds on my laptop.  It
can be further reduced, but not by more than a second or two unless you
get in the business of modifying other tests.  (I only modified
deadlock-soft-2 because it saves 5 seconds).

Admittedly the new isolation_schedule file is a bit ugly.

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Re: reducing isolation tests runtime

Tom Lane <tgl@sss.pgh.pa.us> — 2018-01-25T20:58:04Z

Alvaro Herrera <alvherre@alvh.no-ip.org> writes:
> Here's a concrete proposal.  Runtime is 45.7 seconds on my laptop.  It
> can be further reduced, but not by more than a second or two unless you
> get in the business of modifying other tests.  (I only modified
> deadlock-soft-2 because it saves 5 seconds).

Looks reasonable to me, but do we want to set any particular convention
about the max number of tests to run in parallel?  If so there should
be at least a comment saying what.

> Admittedly the new isolation_schedule file is a bit ugly.

Meh, seems fine.

We won't know if this really works till it hits the buildfarm,
I suppose.

			regards, tom lane

Re: reducing isolation tests runtime

Alvaro Herrera <alvherre@alvh.no-ip.org> — 2018-01-25T21:27:28Z

Tom Lane wrote:
> Alvaro Herrera <alvherre@alvh.no-ip.org> writes:
> > Here's a concrete proposal.  Runtime is 45.7 seconds on my laptop.  It
> > can be further reduced, but not by more than a second or two unless you
> > get in the business of modifying other tests.  (I only modified
> > deadlock-soft-2 because it saves 5 seconds).
> 
> Looks reasonable to me, but do we want to set any particular convention
> about the max number of tests to run in parallel?  If so there should
> be at least a comment saying what.

Hmm, I ran this in a limited number of connections and found that it
fails with less than 27; and there's no MAX_CONNECTIONS like there is
for pg_regress.  So I'll put this back on the drawing board until I'm
back from vacations ...

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Re: reducing isolation tests runtime

Andres Freund <andres@anarazel.de> — 2018-12-04T19:42:16Z

Hi,

On 2018-01-25 18:27:28 -0300, Alvaro Herrera wrote:
> Tom Lane wrote:
> > Alvaro Herrera <alvherre@alvh.no-ip.org> writes:
> > > Here's a concrete proposal.  Runtime is 45.7 seconds on my laptop.  It
> > > can be further reduced, but not by more than a second or two unless you
> > > get in the business of modifying other tests.  (I only modified
> > > deadlock-soft-2 because it saves 5 seconds).
> > 
> > Looks reasonable to me, but do we want to set any particular convention
> > about the max number of tests to run in parallel?  If so there should
> > be at least a comment saying what.
> 
> Hmm, I ran this in a limited number of connections and found that it
> fails with less than 27; and there's no MAX_CONNECTIONS like there is
> for pg_regress.  So I'll put this back on the drawing board until I'm
> back from vacations ...

I'd like to see this revived, getting a bit tired waiting longer and
longer to see isolationtester complete.  Is it really a problem that we
require a certain number of connections? Something on the order of 30-50
connections ought not to be a real problem for realistic machines, and
if it's a problem for one, they can use a serialized schedule?

Greetings,

Andres Freund

Re: reducing isolation tests runtime

Alvaro Herrera <alvherre@2ndquadrant.com> — 2018-12-04T20:17:55Z

On 2018-Dec-04, Andres Freund wrote:

> Hi,
> 
> I'd like to see this revived, getting a bit tired waiting longer and
> longer to see isolationtester complete.  Is it really a problem that we
> require a certain number of connections? Something on the order of 30-50
> connections ought not to be a real problem for realistic machines, and
> if it's a problem for one, they can use a serialized schedule?

Hello

Yeah, me too.  Let me see about it.

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Re: reducing isolation tests runtime

Tom Lane <tgl@sss.pgh.pa.us> — 2018-12-04T20:45:39Z

Andres Freund <andres@anarazel.de> writes:
> I'd like to see this revived, getting a bit tired waiting longer and
> longer to see isolationtester complete.  Is it really a problem that we
> require a certain number of connections? Something on the order of 30-50
> connections ought not to be a real problem for realistic machines, and
> if it's a problem for one, they can use a serialized schedule?

The longstanding convention in the main regression tests is 20 max.
Is there a reason to be different here?

			regards, tom lane

Re: reducing isolation tests runtime

Andres Freund <andres@anarazel.de> — 2018-12-04T20:50:06Z

Hi,

On 2018-12-04 15:45:39 -0500, Tom Lane wrote:
> Andres Freund <andres@anarazel.de> writes:
> > I'd like to see this revived, getting a bit tired waiting longer and
> > longer to see isolationtester complete.  Is it really a problem that we
> > require a certain number of connections? Something on the order of 30-50
> > connections ought not to be a real problem for realistic machines, and
> > if it's a problem for one, they can use a serialized schedule?
> 
> The longstanding convention in the main regression tests is 20 max.
> Is there a reason to be different here?

It's a bit less obvious from the outside how many connections a test
spawn - IOW, it might be easier to maintain the schedule if the cap
isn't as tight.  And I'm doubtful that there's a good reason for the 20
limit these days, so going a bit higher seems reasonable.

Greetings,

Andres Freund

Re: reducing isolation tests runtime

Andres Freund <andres@anarazel.de> — 2019-02-13T07:06:17Z

Hi,

On 2018-01-25 17:34:15 -0300, Alvaro Herrera wrote:
> Tom Lane wrote:
> > Alvaro Herrera <alvherre@alvh.no-ip.org> writes:
> 
> > > I think we could solve this by putting in the same parallel group only
> > > slow tests that mostly sleeps, ie. nothing that would monopolize CPU for
> > > long enough to cause a problem.  Concretely:
> > > test: timeouts tuplelock-update deadlock-hard deadlock-soft-2
> > 
> > OK, but there'd better be a comment there explaining the concern
> > very precisely, or somebody will break it.
> 
> Here's a concrete proposal.  Runtime is 45.7 seconds on my laptop.  It
> can be further reduced, but not by more than a second or two unless you
> get in the business of modifying other tests.  (I only modified
> deadlock-soft-2 because it saves 5 seconds).

I'm working an updated version of this. Adding the new tests is a bit
painful because of conflicting names making it harder than necessary to
schedule tests. While it's possible to work out a schedule that doesn't
conflict, it's pretty annoying to do and more importantly seems fragile
- it's very easy to create schedules that succeed on one machine, and
not on another, based on how slow which tests are.

I'm more inclined to be a bit more aggressive in renaming tables -
there's not much point in having a lot of "foo"s around.  So I'm
inclined to rename some of the names that are more likely to
conflict. If we agree on doing that, I'd like to do that first, and
commit that more aggressively than the schedule itself.

An alternative approach would be to have isolationtester automatically
create a schema with the specfile's name, and place it in the search
path. But that'd make it impossible to use isolationtester against a
standby - which I think we currently don't do, but which probably would
be a good idea.

With regard to the schedule, I'm inclined to order it so that faster
test groups are earlier on, just to make it more likely to reach the
tests one is debugging faster.  Does that sound sane?

Do we want to maintain a serial version of the schedule too? I'm
wondering if we should just generate both the isolationtester and plain
regression test schedule by either adding an option to pg_regress that
serializes test groups, or by generating the serial schedule file in a
few lines of perl.

Greetings,

Andres Freund

Re: reducing isolation tests runtime

Tom Lane <tgl@sss.pgh.pa.us> — 2019-02-13T14:34:35Z

Andres Freund <andres@anarazel.de> writes:
> I'm working an updated version of this. Adding the new tests is a bit
> painful because of conflicting names making it harder than necessary to
> schedule tests. While it's possible to work out a schedule that doesn't
> conflict, it's pretty annoying to do and more importantly seems fragile
> - it's very easy to create schedules that succeed on one machine, and
> not on another, based on how slow which tests are.

> I'm more inclined to be a bit more aggressive in renaming tables -
> there's not much point in having a lot of "foo"s around.  So I'm
> inclined to rename some of the names that are more likely to
> conflict. If we agree on doing that, I'd like to do that first, and
> commit that more aggressively than the schedule itself.

+1

> Do we want to maintain a serial version of the schedule too?

Some of the slower buildfarm critters use MAX_CONNECTIONS to limit
the load on their hosts.  As long as the isolation tests honor that,
I don't see a real need for a separate serial schedule.

(We've talked about retiring the serial sched for the main regression
tests, and while that trigger's not been pulled yet, I think it's
just a matter of time.  So making the isolation tests follow that
precedent seems wrong anyway.)

			regards, tom lane

Re: reducing isolation tests runtime

Alvaro Herrera <alvherre@2ndquadrant.com> — 2019-02-13T15:40:08Z

On 2019-Feb-13, Tom Lane wrote:

> Andres Freund <andres@anarazel.de> writes:
> > I'm working an updated version of this. Adding the new tests is a bit
> > painful because of conflicting names making it harder than necessary to
> > schedule tests. While it's possible to work out a schedule that doesn't
> > conflict, it's pretty annoying to do and more importantly seems fragile
> > - it's very easy to create schedules that succeed on one machine, and
> > not on another, based on how slow which tests are.
> 
> > I'm more inclined to be a bit more aggressive in renaming tables -
> > there's not much point in having a lot of "foo"s around.  So I'm
> > inclined to rename some of the names that are more likely to
> > conflict. If we agree on doing that, I'd like to do that first, and
> > commit that more aggressively than the schedule itself.
> 
> +1

+1

(Using separate schemas sounds a useful idea if we accumulate dozens of
tests, so I suggest that we do that for future tests, but for the time
being I wouldn't bother.)

> > Do we want to maintain a serial version of the schedule too?
> 
> Some of the slower buildfarm critters use MAX_CONNECTIONS to limit
> the load on their hosts.  As long as the isolation tests honor that,
> I don't see a real need for a separate serial schedule.

MAX_CONNECTIONS was the only reason I didn't push this through.  Do you
(Andres) have any solution to that?

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Re: reducing isolation tests runtime

Tom Lane <tgl@sss.pgh.pa.us> — 2019-02-13T15:58:50Z

Alvaro Herrera <alvherre@2ndquadrant.com> writes:
> On 2019-Feb-13, Tom Lane wrote:
>> Some of the slower buildfarm critters use MAX_CONNECTIONS to limit
>> the load on their hosts.  As long as the isolation tests honor that,
>> I don't see a real need for a separate serial schedule.

> MAX_CONNECTIONS was the only reason I didn't push this through.  Do you
> (Andres) have any solution to that?

Doesn't the common pg_regress.c infrastructure handle that?
We might need to improve isolation_main.c and/or the isolation
Makefile to make it accessible.

I suppose that in what I'm thinking about, MAX_CONNECTIONS would be
interpreted as "max number of concurrent isolation scripts", which
is not exactly number of connections.  A quick and dirty answer
would be to have isolation_main.c divide the limit by a factor of 4
or so.

			regards, tom lane

Re: reducing isolation tests runtime

Andres Freund <andres@anarazel.de> — 2019-02-13T17:03:39Z

On 2019-02-13 10:58:50 -0500, Tom Lane wrote:
> Alvaro Herrera <alvherre@2ndquadrant.com> writes:
> > On 2019-Feb-13, Tom Lane wrote:
> >> Some of the slower buildfarm critters use MAX_CONNECTIONS to limit
> >> the load on their hosts.  As long as the isolation tests honor that,
> >> I don't see a real need for a separate serial schedule.
> 
> > MAX_CONNECTIONS was the only reason I didn't push this through.  Do you
> > (Andres) have any solution to that?
> 
> Doesn't the common pg_regress.c infrastructure handle that?
> We might need to improve isolation_main.c and/or the isolation
> Makefile to make it accessible.

> I suppose that in what I'm thinking about, MAX_CONNECTIONS would be
> interpreted as "max number of concurrent isolation scripts", which
> is not exactly number of connections.  A quick and dirty answer
> would be to have isolation_main.c divide the limit by a factor of 4
> or so.

I guess that could work, although it's certainly not too pretty.
Alternatively we could pre-parse the spec files, but that's a bit
annoying given isolationtester.c is a separate c file...

Do you have an idea why we have both max_concurrent_tests *and*
max_connections in pg_regress? ISTM the former isn't really useful given
the latter?

Greetings,

Andres Freund

Re: reducing isolation tests runtime

Tom Lane <tgl@sss.pgh.pa.us> — 2019-02-13T17:41:41Z

Andres Freund <andres@anarazel.de> writes:
> Do you have an idea why we have both max_concurrent_tests *and*
> max_connections in pg_regress? ISTM the former isn't really useful given
> the latter?

No, the former is a static restriction on what the schedule file is
allowed to contain, the latter is a dynamic restriction (that typically
is unlimited anyway).

			regards, tom lane

Re: reducing isolation tests runtime

Andres Freund <andres@anarazel.de> — 2019-02-13T17:46:50Z

Hi,

On 2019-02-13 12:41:41 -0500, Tom Lane wrote:
> Andres Freund <andres@anarazel.de> writes:
> > Do you have an idea why we have both max_concurrent_tests *and*
> > max_connections in pg_regress? ISTM the former isn't really useful given
> > the latter?
> 
> No, the former is a static restriction on what the schedule file is
> allowed to contain, the latter is a dynamic restriction (that typically
> is unlimited anyway).

Right, but why don't we allow for more tests in a group, and then use a
default max_connections to limit concurrency? Having larger groups is
advantageous wrt test runtime - it reduces the number of artificial
serialization point where the slowest test slows things down.  Obviously
there's still a few groups that are needed for test interdependency
management, but that's comparatively rare. We have have plenty groups
that are just broken up to stay below max_concurrent_tests.

Greetings,

Andres Freund

Re: reducing isolation tests runtime

Tom Lane <tgl@sss.pgh.pa.us> — 2019-02-13T18:01:52Z

Andres Freund <andres@anarazel.de> writes:
> Right, but why don't we allow for more tests in a group, and then use a
> default max_connections to limit concurrency? Having larger groups is
> advantageous wrt test runtime - it reduces the number of artificial
> serialization point where the slowest test slows things down.  Obviously
> there's still a few groups that are needed for test interdependency
> management, but that's comparatively rare. We have have plenty groups
> that are just broken up to stay below max_concurrent_tests.

Meh.  That would also greatly increase the scope for hard-to-reproduce
conflicts between concurrent tests.  I'm not especially excited about
going there.

			regards, tom lane