Can we automatically add elapsed times to tap test log?

From: Andres Freund <andres(at)anarazel(dot)de>
To: pgsql-hackers(at)postgresql(dot)org
Subject: Can we automatically add elapsed times to tap test log?
Date: 2022-04-01 17:21:50
Message-ID: 20220401172150.rsycz4lrn7ewruil@alap3.anarazel.de
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

Hi,

right now I am looking at a test added in the shmstats patch that's slow on
CI, on windows only. Unfortunately the regress_log_* output is useless as-is
to figure out where things hang.

I've hit this several times before. Of course it's not too hard to hack up
something printing elapsed time. But ISTM that it'd be better if we were able
to prefix the logging into regress_log_* with something like
[timestamp + time since start of test]
or
[timestamp + time since start of test + time since last log message]

This isn't just useful to figure out what parts of test are slow, but also
helps correlate server logs with the regress_log_* output. Which right now is
hard and inaccurate, requiring manually correlating statements between server
log and the tap test (often there's no logging for statements in the
regress_log_*).

Greetings,

Andres Freund

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Robert Haas 2022-04-01 17:22:05 PostgreSQL shutdown modes
Previous Message Jesper Pedersen 2022-04-01 17:00:05 Re: GSoC: pgmoneta: Write-Ahead Log (WAL) infrastructure (2022)