Re: initdb caching during tests

Hi,

On 2023-08-05 16:58:38 -0400, Tom Lane wrote:
> Andres Freund <andres(at)anarazel(dot)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 187 subtests passed
259/265 postgresql:subscription / subscription/100_bugs OK 6.69s 12 subtests passed
260/265 postgresql:regress / regress/regress OK 24.95s 215 subtests passed
261/265 postgresql:ssl / ssl/001_ssltests OK 7.97s 205 subtests passed
262/265 postgresql:pg_dump / pg_dump/002_pg_dump OK 19.65s 11262 subtests passed
263/265 postgresql:recovery / recovery/027_stream_regress OK 29.34s 6 subtests passed
264/265 postgresql:isolation / isolation/isolation OK 33.94s 112 subtests passed
265/265 postgresql:pg_upgrade / pg_upgrade/002_pg_upgrade OK 38.22s 18 subtests passed

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