Re: initdb caching during tests

Hi,

On 2023-08-05 16:58:38 -0400, Tom Lane wrote:
> Andres Freund <andres@anarazel.de> writes:
> > Times for running all tests under meson, on my workstation (20 cores / 40
> > threads):
> 
> > cassert build -O2:
> 
> > Before:
> > real    0m44.638s
> > user    7m58.780s
> > sys    2m48.773s
> 
> > After:
> > real    0m38.938s
> > user    2m37.615s
> > sys    2m0.570s
> 
> Impressive results.  Even though your bottom-line time doesn't change that
> much

Unfortunately we have a few tests that take quite a while - for those the
initdb removal doesn't make that much of a difference. Particularly because
this machine has enough CPUs to not be fully busy except for the first few
seconds...

E.g. for a run with the patch applied:

258/265 postgresql:pg_basebackup / pg_basebackup/010_pg_basebackup                         OK               16.58s
187subtests passed
 
259/265 postgresql:subscription / subscription/100_bugs                                    OK                6.69s   12
subtestspassed
 
260/265 postgresql:regress / regress/regress                                               OK               24.95s
215subtests passed
 
261/265 postgresql:ssl / ssl/001_ssltests                                                  OK                7.97s
205subtests passed
 
262/265 postgresql:pg_dump / pg_dump/002_pg_dump                                           OK               19.65s
11262subtests passed
 
263/265 postgresql:recovery / recovery/027_stream_regress                                  OK               29.34s   6
subtestspassed
 
264/265 postgresql:isolation / isolation/isolation                                         OK               33.94s
112subtests passed
 
265/265 postgresql:pg_upgrade / pg_upgrade/002_pg_upgrade                                  OK               38.22s   18
subtestspassed
 

The pg_upgrade test is faster in isolation (29s), but not that much. The
overall runtime is reduces due to the reduced "competing" cpu usage, but other
than that...


Looking at where the time is spent when running the pg_upgrade test on its own:

grep -E '^\[' testrun/pg_upgrade/002_pg_upgrade/log/regress_log_002_pg_upgrade |sed -E -e 's/.*\(([0-9.]+)s\)(.*)/\1
\2/g'|sort-n -r
 

cassert:
13.094  ok 5 - regression tests pass
6.147  ok 14 - run of pg_upgrade for new instance
2.340  ok 6 - dump before running pg_upgrade
1.638  ok 17 - dump after running pg_upgrade
1.375  ok 12 - run of pg_upgrade --check for new instance
0.798  ok 1 - check locales in original cluster
0.371  ok 9 - invalid database causes failure status (got 1 vs expected 1)
0.149  ok 7 - run of pg_upgrade --check for new instance with incorrect binary path
0.131  ok 16 - check that locales in new cluster match original cluster

optimized:
8.372  ok 5 - regression tests pass
3.641  ok 14 - run of pg_upgrade for new instance
1.371  ok 12 - run of pg_upgrade --check for new instance
1.104  ok 6 - dump before running pg_upgrade
0.636  ok 17 - dump after running pg_upgrade
0.594  ok 1 - check locales in original cluster
0.359  ok 9 - invalid database causes failure status (got 1 vs expected 1)
0.148  ok 7 - run of pg_upgrade --check for new instance with incorrect binary path
0.127  ok 16 - check that locales in new cluster match original cluster


The time for "dump before running pg_upgrade" is misleadingly high - there's
no output between starting initdb and the dump, so the timing includes initdb
and a bunch of other work.  But it's still not fast (1.637s) after.

A small factor is that the initdb times are not insignificant, because the
template initdb can't be used due to a bunch of parameters passed to initdb :)


> the big reduction in CPU time should translate to a nice speedup on slower
> buildfarm animals.

Yea. It's a particularly large win when using valgrind. Under valgrind, a very
large portion of the time for many tests is just spent doing initdb... So I am
hoping to see some nice gains for skink.

Greetings,

Andres Freund