IPC::Run::time[r|out] vs our TAP tests
Tom Lane <tgl@sss.pgh.pa.us>
From: Tom Lane <tgl@sss.pgh.pa.us>
To: pgsql-hackers@lists.postgresql.org
Date: 2024-04-04T21:24:05Z
Lists: pgsql-hackers
Attachments
- use-timer-not-timeout-in-BackgroundPsql.patch (text/x-diff) patch
TIL that IPC::Run::timer is not the same as IPC::Run::timeout. With a timer object you have to check $timer->is_expired to see if the timeout has elapsed, but with a timeout object you don't because it will throw a Perl exception upon timing out, probably killing your test program. It appears that a good chunk of our TAP codebase has not read this memo, because I see plenty of places that are checking is_expired in the naive belief that they'll still have control after a timeout has fired. The particular thing that started me down this road was wondering why we are getting no useful failure details from buildfarm member tanager's struggles with the tab-completion test case added by commit 927332b95 [1]. Apparently it's not seeing a match to what it expects so it eventually times out, but all we get in the log is [03:03:42.595](0.002s) ok 82 - complete an interpolated psql variable name [03:03:42.597](0.002s) ok 83 - \\r works IPC::Run: timeout on timer #1 at /usr/share/perl5/IPC/Run.pm line 2944. # Postmaster PID for node "main" is 17308 ### Stopping node "main" using mode immediate We would have learned something useful if control had returned to pump_until, or even better 010_tab_completion.pl's check_completion, but it doesn't. A minimum fix that seems to make this work better is as attached, but I feel like somebody ought to examine all the IPC::Run::timer and IPC::Run::timeout calls and see which ones are mistaken. It's a little scary to convert a timeout to a timer because of the hazard that someplace that would need to be checking for is_expired isn't. Also, the debug printout code at the bottom of check_completion is quite useless, because control can never reach it since BackgroundPsql::query_until will "die" on failure. I think that that code worked when written, and I'm suspicious that 664d75753 broke it, but I've not dug deeply into the history. regards, tom lane [1] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=tanager&dt=2024-04-04%2016%3A56%3A14
Commits
-
Restart BackgroundPsql's timer more nicely.
- 53c6bd0aa3de 19 (unreleased) landed
-
Implement pg_wal_replay_wait() stored procedure
- 3c5db1d6b016 18.0 cited
-
psql: fix variable existence tab completion
- 927332b95e77 17.0 cited