On 4/1/22 13:44, Nathan Bossart wrote: > On Fri, Apr 01, 2022 at 10:21:50AM -0700, Andres Freund wrote: >> 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_*). > +1 >
Maybe one way would be to make a change in src/test/perl/PostgreSQL/Test/SimpleTee.pm. The simplest thing would just be to add a timestamp, the other things would involve a bit more bookkeeping. It should also be checked to make sure it doesn't add too much overhead, although I would be surprised if it did. cheers andrew -- Andrew Dunstan EDB: https://www.enterprisedb.com