Re: Recording test runtimes with the buildfarm

On 6/10/20 8:58 AM, David Rowley wrote:
> Hi,
>
> I've just had some thoughts about the possible usefulness of having
> the buildfarm record the run-time of each regression test to allow us
> to have some sort of ability to track the run-time history of each
> test.
>
> I thought the usefulness might be two-fold:
>
> 1. We could quickly identify when someone adds some overly complex
> test and slows down the regression tests too much.
> 2. We might get some faster insight into performance regressions.
>
> I can think of about 3 reasons that a test might slow down.
>
> a) Someone adds some new tests within the test file.
> b) Actual performance regression in Postgres
> c) Animal busy with other work.
>
> We likely could do a semi-decent job of telling a) and b) apart by
> just recording the latest commit that changed the .sql file for the
> test. We could also likely see when c) is at play by the results
> returning back to normal again a few runs after some spike.  We'd only
> want to pay attention to consistent slowdowns. Perhaps there would be
> too much variability with the parallel tests, but maybe we could just
> record it for the serial tests in make check-world.
>
> I only thought of this after reading [1]. If we went ahead with that,
> as of now, it feels like someone could quite easily break that
> optimisation and nobody would notice for a long time.
>
> I admit to not having looked at the buildfarm code to determine how
> practical such a change would be. I've assumed there is a central
> database that stores all the results.
>

David,


Yes we have a central database. But we don't have anything that digs
into each step. In fact, on the server side the code isn't even really
aware that it's Postgres that's being tested.


The basic structures are:


    buildsystems - one row per animal

    build_status - one row per run

    build_status_log - one row per step within each run


The last table has a blob containing the output of the step (e.g. "make
check") plus any relevant files (like the postmaster.log).

But we don't have any structure corresponding to an individual
regression test.

Architecturally, we could add a table for named times, and have the
client extract and report them.

Alternatively, people with access to the database could extract the logs
and post-process them using perl or python. That would involve no work
on my part :-) But it would not be automated.

What we do record (in build_status_log) is the time each step took. So
any regression test that suddenly blew out should likewise cause a
blowout in the time the whole "make check" took. It might be possible to
create a page that puts stats like that up. I think that's probably a
better way to go.

Tying results to an individual commit is harder. There could be dozens
of commits that happened between the current run and the previous run on
a given animal. But usually what has caused any event is fairly clear
when you look at it.


cheers


andrew


-- 

Andrew Dunstan                https://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services