Re: [HACKERS] TAP tests take a long time - Mailing list pgsql-hackers

On 12 April 2017 at 08:22, Michael Paquier <michael.paquier@gmail.com> wrote:
> On Wed, Apr 12, 2017 at 9:12 AM, Craig Ringer
> <craig.ringer@2ndquadrant.com> wrote:
>> Well, you can get a lot of information on timings in crake's latest
>> builds for example, or nightjar's.
>>
>> Here's an interesting fact: almost all the time taken up in the scripts
>> test set seems to be consumed in running initdb over and over.
>>
>> Is it worth adding an init(cache => 1) option to PostgresNode, where we
>> stash an initdb'd db in tmp_check/  and just do a simple fs copy of it ?
>
> This looks like a good idea to me, but I don't like much the idea of
> an option in the init() routine as that's hard to maintain.

How so?

> It would
> make sense to me to be able to override the initialization with an
> environment variable instead

Yeah, that's reasonable.

Patch attached. It supports setting CACHE_INITDB=0 to disable the cache.

With cache: 3m55.063s (user 7.7s, sys 0m11.833s)

Without cache:  4m11.229s (user 0m16.963s, sys 0m12.384s)

so in a serial run it doesn't make a ton of difference.

Adding some timing on initdb runs shows that initdb takes about 1s, a
cached copy about 0.1s with our Perl based recursive copy code. So
it's hardly an overwhelming benefit, but might be more beneficial with
prove -j .


BTW, I suggest adding --timer to our default PROVE_FLAGS, so we can
collect more data from the buildfarm on what takes a while. Sample
output:

[13:20:47] t/001_stream_rep.pl .................. ok    50445 ms (
0.01 usr  0.00 sys +  2.16 cusr  3.57 csys =  5.74 CPU)
[13:21:38] t/002_archiving.pl ................... ok     5883 ms (
0.01 usr  0.00 sys +  0.19 cusr  0.45 csys =  0.65 CPU)
[13:21:44] t/003_recovery_targets.pl ............ ok    26197 ms (
0.00 usr  0.00 sys +  0.70 cusr  1.75 csys =  2.45 CPU)
[13:22:10] t/004_timeline_switch.pl ............. ok    10049 ms (
0.01 usr  0.00 sys +  0.24 cusr  0.53 csys =  0.78 CPU)
[13:22:20] t/005_replay_delay.pl ................ ok    10224 ms (
0.00 usr  0.01 sys +  0.18 cusr  0.43 csys =  0.62 CPU)
[13:22:30] t/006_logical_decoding.pl ............ ok     7570 ms (
0.00 usr  0.00 sys +  0.25 cusr  0.32 csys =  0.57 CPU)
[13:22:38] t/007_sync_rep.pl .................... ok    20693 ms (
0.00 usr  0.00 sys +  0.51 cusr  1.24 csys =  1.75 CPU)
[13:22:58] t/008_fsm_truncation.pl .............. ok    25399 ms (
0.01 usr  0.00 sys +  0.26 cusr  0.52 csys =  0.79 CPU)
[13:23:24] t/009_twophase.pl .................... ok    58531 ms (
0.01 usr  0.00 sys +  0.49 cusr  0.92 csys =  1.42 CPU)
[13:24:22] t/010_logical_decoding_timelines.pl .. ok     8135 ms (
0.00 usr  0.01 sys +  0.34 cusr  0.76 csys =  1.11 CPU)
[13:24:30] t/011_crash_recovery.pl .............. ok     4334 ms (
0.00 usr  0.00 sys +  0.12 cusr  0.16 csys =  0.28 CPU)


-- 
 Craig Ringer                   http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers