Date: Sun, 16 Feb 2025 15:58:43 -0800
From: Noah Misch <noah@leadboat.com>
To: Tom Lane <tgl@sss.pgh.pa.us>
Cc: Andres Freund <andres@anarazel.de>, pgsql-hackers@postgresql.org
Subject: Re: BackgroundPsql swallowing errors on windows
Message-ID: <20250216235843.7c.nmisch@google.com>
References: <wmovm6xcbwh7twdtymxuboaoarbvwj2haasd3sikzlb3dkgz76@n45rzycluzft>
 <20250216173943.b6.nmisch@google.com>
 <h6t2voqv6vm4xk4oh5q6og676h7ehv2opbvr2id7m2xot3adh5@t7su2dmuo3bs>
 <20250216184740.55.nmisch@google.com>
 <qo3x3ycl5fokh4tumm3lo6rn6ijvl7mmes7k24fm3kuv4xaupt@px4vl5ocnvth>
 <20250216223951.a3.nmisch@google.com>
 <684214.1739747924@sss.pgh.pa.us>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <684214.1739747924@sss.pgh.pa.us>
User-Agent: Mutt/2.2.12 (2023-09-09)
Archived-At: <https://www.postgresql.org/message-id/20250216235843.7c.nmisch%40google.com>
Precedence: bulk

On Sun, Feb 16, 2025 at 06:18:44PM -0500, Tom Lane wrote:
> Noah Misch <noah@leadboat.com> writes:
> > From the slow proxy's perspective, it can't rule out the program under test
> > having done those two write() calls.  The proxy doesn't have enough
> > information to reconstruct the original four write() calls.  What prevents
> > that anomaly?
> 
> Yeah, I think it's hopeless to expect that we can disambiguate the
> order of writes to two different pipes.  For the problem at hand,
> though, it seems like we don't really need to do that.  Rather, the
> question is "when we detect that the program-under-test has exited,
> can we be sure we have collected all of its output?".

In the BackgroundPsql case, we have output collection moments for every query
while the psql-under-test is running, not just after exit.  If I understand
the original post right, the specifics are as follows.  If $stdout witnesses
the result of '\echo BANNER', $stderr should contain anything from psql
commands before the \echo.  That holds on non-Windows, but the IPC::Run proxy
makes it not hold on Windows.

> I think that
> IPC::Run may be screwing up here, because I have seen non-Windows
> CI failures that look like it didn't read all the stderr output.
> For example, this pgbench test failure on macOS from [1]:
> 
> # Running: pgbench -n -t 1 -Dfoo=bla -Dnull=null -Dtrue=true -Done=1 -Dzero=0.0 -Dbadtrue=trueXXX -Dmaxint=9223372036854775807 -Dminint=-9223372036854775808 -M prepared -f /Users/admin/pgsql/build/testrun/pgbench/001_pgbench_with_server/data/t_001_pgbench_with_server_main_data/001_pgbench_error_shell_bad_command
> [17:27:47.408](0.061s) ok 273 - pgbench script error: shell bad command status (got 2 vs expected 2)
> [17:27:47.409](0.000s) ok 274 - pgbench script error: shell bad command stdout /(?^:processed: 0/1)/
> [17:27:47.409](0.000s) not ok 275 - pgbench script error: shell bad command stderr /(?^:\(shell\) .* meta-command failed)/
> [17:27:47.409](0.000s) #   Failed test 'pgbench script error: shell bad command stderr /(?^:\(shell\) .* meta-command failed)/'
> #   at /Users/admin/pgsql/src/bin/pgbench/t/001_pgbench_with_server.pl line 1466.
> #                   ''
> #     doesn't match '(?^:\(shell\) .* meta-command failed)'
> 
> The program's exited with a failure code as expected, and we saw (some
> of?) the expected stdout output, but stderr output is reported to be
> empty.

https://github.com/cpan-authors/IPC-Run/commit/2128df3bbcac7e733ac46302c4b1371ffb88fe14
fixed that one.

> [1] https://cirrus-ci.com/task/6221238034497536