Feedback-ID: i0fe9450f:Fastmail
Date: Wed, 23 Apr 2025 16:13:14 +0900
From: Michael Paquier <michael@paquier.xyz>
To: Anthonin Bonnefoy <anthonin.bonnefoy@datadoghq.com>
Cc: "a.kozhemyakin" <a.kozhemyakin@postgrespro.ru>,
	Daniel Verite <daniel@manitou-mail.org>,
	Jelte Fennema-Nio <postgres@jeltef.nl>,
	PostgreSQL Hackers <pgsql-hackers@postgresql.org>
Subject: Re: Add Pipelining support in psql
Message-ID: <aAiTCkrKRroAPJOq@paquier.xyz>
References: <CAO6_Xqroaof=Gu_NCg4bZfpdgwOjNW9fg753cuuts-FBnv9UGw@mail.gmail.com>
 <a96682c3-9505-456f-b5c7-1b9d1e6303b4@manitou-mail.org>
 <Z8kilUVjYAHko17g@paquier.xyz>
 <ebf6ce77-b180-4d6b-8eab-71f641499ddf@postgrespro.ru>
 <Z__YOQJqBJYhezm2@paquier.xyz>
 <aAXkJIOildLUA7vQ@paquier.xyz>
 <aAbdfKU2ZWeuAnIG@paquier.xyz>
 <CAO6_XqoQaZVHEw1dFgvOxwectqsNo4QE1tQ6rLD-YUzFpT_+3g@mail.gmail.com>
MIME-Version: 1.0
Content-Type: multipart/signed; micalg=pgp-sha512;
	protocol="application/pgp-signature"; boundary="i0AeXu7IGQYqOUsj"
Content-Disposition: inline
In-Reply-To: <CAO6_XqoQaZVHEw1dFgvOxwectqsNo4QE1tQ6rLD-YUzFpT_+3g@mail.gmail.com>
Archived-At: <https://www.postgresql.org/message-id/aAiTCkrKRroAPJOq%40paquier.xyz>
Precedence: bulk


--i0AeXu7IGQYqOUsj
Content-Type: multipart/mixed; boundary="ePB6ZxRZ8Uz4LhlU"
Content-Disposition: inline


--ePB6ZxRZ8Uz4LhlU
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline

On Tue, Apr 22, 2025 at 02:37:19PM +0200, Anthonin Bonnefoy wrote:
> Also, we still have a triggered assertion failure with the following:
> CREATE TABLE psql_pipeline(a text);
> \startpipeline
> COPY psql_pipeline FROM STDIN;
> SELECT 'val1';
> \syncpipeline
> \endpipeline
> ...
> Assertion failed: (pset.piped_syncs == 0), function
> ExecQueryAndProcessResults, file common.c, line 2153.

Right.  I didn't think about the case of a \endpipeline that fetches
all the results by itself.

> A possible alternative could be to abort discardAbortedPipelineResults
> when we encounter a res != NULL + FATAL error and let the outer loop
> handle it. As you said, the pipeline flow is borked so there's not
> much to salvage. The outer loop would read and print all error
> messages until the closed connection is detected. Then,
> CheckConnection will reset the connection which will reset the
> pipeline state.

Sounds like a better idea seen from here, yes.

> While testing this change, I was initially looking for the "FATAL:
> terminating connection because protocol synchronization was lost"
> message in the tests. However, this was failing on Windows[1] as the
> FATAL message wasn't reported on stderr. I'm not sure why yet.

Hmm.  I vaguely recall that there could be some race condition here
with the attempt to catch up the FATAL message once the server tries
to shut down the connection..

Anyway, I agree that it would be nice to track that this specific
error message is generated in the server.  How about checking the
server logs instead, using a slurp_file() with an offset of the log
file before running each pipeline sequence?  We should use a few
wait_for_log() calls, I think, to be extra careful with the timings
where psql_fails_like() gives up, and I'm worried that this could be
unstable on slow machines.  Something like the attached seems stable
enough here.  What do you think?

The tweak for psql_fails_like() was kind of independent of the rest of
the fix, so I have applied that as a commit of its own.  I am not
convinced about the addition of a 4th test where we use the queries
with semicolons without a \getresults between the sync and the end.
--
Michael

--ePB6ZxRZ8Uz4LhlU
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v3-0001-psql-Fix-assertion-failure-with-pipeline-mode.patch"
Content-Transfer-Encoding: quoted-printable

=46rom 2641356ffacc0c69779a6252a8072f41521c0f3f Mon Sep 17 00:00:00 2001
=46rom: Michael Paquier <michael@paquier.xyz>
Date: Wed, 23 Apr 2025 15:52:24 +0900
Subject: [PATCH v3] psql: Fix assertion failure with pipeline mode

---
 src/bin/psql/common.c       | 17 +++++++++++++
 src/bin/psql/t/001_basic.pl | 49 +++++++++++++++++++++++++++++++++++++
 2 files changed, 66 insertions(+)

diff --git a/src/bin/psql/common.c b/src/bin/psql/common.c
index 21d660a8961a..0aab02ee32e6 100644
--- a/src/bin/psql/common.c
+++ b/src/bin/psql/common.c
@@ -1478,6 +1478,23 @@ discardAbortedPipelineResults(void)
 			 */
 			return res;
 		}
+		else if (res !=3D NULL && result_status =3D=3D PGRES_FATAL_ERROR)
+		{
+			/*
+			 * We have a fatal error sent by the backend and we can't recover
+			 * from this state. Instead, return the last fatal error and let
+			 * the outer loop handle it.
+			 */
+			PGresult   *fatal_res PG_USED_FOR_ASSERTS_ONLY;
+
+			/*
+			 * Fetch result to consume the end of the current query being
+			 * processed.
+			 */
+			fatal_res =3D PQgetResult(pset.db);
+			Assert(fatal_res =3D=3D NULL);
+			return res;
+		}
 		else if (res =3D=3D NULL)
 		{
 			/* A query was processed, decrement the counters */
diff --git a/src/bin/psql/t/001_basic.pl b/src/bin/psql/t/001_basic.pl
index b0e4919d4d71..3cada3ba959b 100644
--- a/src/bin/psql/t/001_basic.pl
+++ b/src/bin/psql/t/001_basic.pl
@@ -483,4 +483,53 @@ psql_like($node, "copy (values ('foo'),('bar')) to std=
out \\g | $pipe_cmd",
 my $c4 =3D slurp_file($g_file);
 like($c4, qr/foo.*bar/s);
=20
+# Tests with pipelines.  These trigger FATAL failures in the backend,
+# so they cannot be tested through the SQL regression tests.
+$node->safe_psql('postgres', 'CREATE TABLE psql_pipeline()');
+my $log_location =3D -s $node->logfile;
+psql_fails_like(
+	$node,
+	qq{\\startpipeline
+COPY psql_pipeline FROM STDIN;
+SELECT 'val1';
+\\syncpipeline
+\\getresults
+\\endpipeline},
+	qr/server closed the connection unexpectedly/,
+	'protocol sync loss in pipeline: direct COPY, SELECT, sync and getresult'
+);
+$node->wait_for_log(
+	qr/FATAL: .*terminating connection because protocol synchronization was l=
ost/,
+	$log_location);
+
+$log_location =3D -s $node->logfile;
+psql_fails_like(
+	$node,
+	qq{\\startpipeline
+COPY psql_pipeline FROM STDIN \\bind \\sendpipeline
+SELECT 'val1' \\bind \\sendpipeline
+\\syncpipeline
+\\getresults
+\\endpipeline},
+	qr/server closed the connection unexpectedly/,
+	'protocol sync loss in pipeline: bind COPY, SELECT, sync and getresult');
+$node->wait_for_log(
+	qr/FATAL: .*terminating connection because protocol synchronization was l=
ost/,
+	$log_location);
+
+# This time, test without the \getresults.
+$log_location =3D -s $node->logfile;
+psql_fails_like(
+	$node,
+	qq{\\startpipeline
+COPY psql_pipeline FROM STDIN;
+SELECT 'val1';
+\\syncpipeline
+\\endpipeline},
+	qr/server closed the connection unexpectedly/,
+	'protocol sync loss in pipeline: COPY, SELECT and sync');
+$node->wait_for_log(
+	qr/FATAL: .*terminating connection because protocol synchronization was l=
ost/,
+	$log_location);
+
 done_testing();
--=20
2.49.0


--ePB6ZxRZ8Uz4LhlU--

--i0AeXu7IGQYqOUsj
Content-Type: application/pgp-signature; name="signature.asc"

-----BEGIN PGP SIGNATURE-----

iQIzBAABCgAdFiEEG72nH6vTowiyblFKnvQgOdbyQH0FAmgIkwoACgkQnvQgOdby
QH2H1w/+PLHTupAji+JTIoW0/BJx+D82dDwQG4tUf/tUgW6iJErb/8UlSDKhXwDv
CVpBFChI+xlqXS3DUru+TU6qWWmYVsqqaQINqGOxjDBm2vw0FNM79RaIIy1QZOYD
WtnQLG16kRwXWLaNddH6ntsgYTepEa3u1GlIb2RpnhU8KyVNMWF8taxcl2elZLyp
VxCRKdYNM1ynSWqtYRaOH7qBHOWpexLCN4NRX6JlQM6gjLH52aQlR7dYRHXbQB40
JW6VkY1rD5ouZpjS6fsXFtZiN3m63fAkm1Hm8kA9PFShwhhSsKzno/3utndIqpJs
Lpi6WHT0u3JDm8Dff9nIbGF+2snGLHX5Q15ijrXm/uiXJfSEKMy//9uHEeTBGlDj
5YP7RsKYby4UT+OdzzU/CdSWUFyYcg7znpUdxeIJpBNxJDaBFD6V/AR7i6S6wdrI
wENyCm/1RO7eakjDbX1IenCxesl6ORrxXn47fz5WYN9MHZUqXh/0/8SzFTimPzp3
bMFmD5resUyfms2t9vGvXy8pgS3sT1tBK+YXYS4o8fOAVr4fIbDOI1/KBR30hyHK
4kbr3hta3xB3PBHOfkYi4W8fIjqIDKTwjVh07BxO5GaT6FuKdzcCPm9yidZVaDuR
3qFy8Hx5ehbMxoqAi/37m16BtxtJzwLs1MuMdDI1R52eBxSckO8=
=zTGw
-----END PGP SIGNATURE-----

--i0AeXu7IGQYqOUsj--