Обсуждение: BUG #18944: Assertion Failure in psql with idle_session_timeout Set

The following bug has been logged on the website:

Bug reference:      18944
Logged by:          Nikita Kalinin
Email address:      n.kalinin@postgrespro.ru
PostgreSQL version: 18beta1
Operating system:   ubuntu 22.04
Description:

Hello! When I execute the following query:
psql <<EOF
CREATE TABLE psql_pipeline(a INTEGER PRIMARY KEY, s TEXT);
\startpipeline
COPY psql_pipeline FROM STDIN;
\syncpipeline
\endpipeline
EOF
with `idle_session_timeout` set to, for example, 10000, I get the following
error:
FATAL:  terminating connection due to idle-session timeout
psql: common.c:1501: discardAbortedPipelineResults: Assertion
`pset.available_results > 0' failed.
[1]    1747708 abort (core dumped)  psql <<<''
Coredump:
#0  __pthread_kill_implementation (threadid=278301224788256,
signo=signo@entry=6, no_tid=no_tid@entry=0) at ./nptl/pthread_kill.c:44
#1  0x0000fd1d0d757670 in __pthread_kill_internal (signo=6,
threadid=<optimized out>) at ./nptl/pthread_kill.c:78
#2  0x0000fd1d0d70cb3c in __GI_raise (sig=sig@entry=6) at
../sysdeps/posix/raise.c:26
#3  0x0000fd1d0d6f7e00 in __GI_abort () at ./stdlib/abort.c:79
#4  0x0000fd1d0d705cc0 in __assert_fail_base (fmt=0xfd1d0d82c770 "%s%s%s:%u:
%s%sAssertion `%s' failed.\n%n",
    assertion=assertion@entry=0xb9a5a2d96080 "pset.available_results > 0",
file=file@entry=0xb9a5a2d95fa0 "common.c", line=line@entry=1501,
    function=function@entry=0xb9a5a2dc4138 <__PRETTY_FUNCTION__.3>
"discardAbortedPipelineResults") at ./assert/assert.c:96
#5  0x0000fd1d0d705d30 in __assert_fail
(assertion=assertion@entry=0xb9a5a2d96080 "pset.available_results > 0",
    file=file@entry=0xb9a5a2d95fa0 "common.c", line=line@entry=1501,
    function=function@entry=0xb9a5a2dc4138 <__PRETTY_FUNCTION__.3>
"discardAbortedPipelineResults") at ./assert/assert.c:105
#6  0x0000b9a5a2d3ec10 in discardAbortedPipelineResults () at common.c:1501
#7  ExecQueryAndProcessResults (query=query@entry=0xb9a5bfbe5690 "COPY
psql_pipeline FROM STDIN;",
    elapsed_msec=elapsed_msec@entry=0xffffe844e8a0,
svpt_gone_p=svpt_gone_p@entry=0xffffe844e89f, is_watch=is_watch@entry=false,
    min_rows=min_rows@entry=0, opt=opt@entry=0x0,
printQueryFout=printQueryFout@entry=0x0) at common.c:1828
#8  0x0000b9a5a2d3cc20 in SendQuery (query=0xb9a5bfbe5690 "COPY
psql_pipeline FROM STDIN;") at common.c:1212
#9  0x0000b9a5a2d52c14 in MainLoop (source=source@entry=0xfd1d0d880880
<_IO_2_1_stdin_>) at mainloop.c:515
#10 0x0000b9a5a2d375b0 in process_file (filename=0x0,
use_relative_path=use_relative_path@entry=false) at command.c:4870
#11 0x0000b9a5a2d31bc4 in main (argc=<optimized out>, argv=<optimized out>)
at startup.c:420
It appears to be a continuation of this thread:
https://www.postgresql.org/message-id/ebf6ce77-b180-4d6b-8eab-71f641499ddf@postgrespro.ru
--
Nikita Kalinin
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company

On Mon, Jun 2, 2025 at 10:13 AM Michael Paquier <michael@paquier.xyz> wrote:
> Reproduced here, thanks for the report.  In this case, we are in a
> PGRES_FATAL_ERROR state due to the timeout triggered by the backend,
> and the loop discarding the results in discardAbortedPipelineResults()
> does not take into account this case scenario: we don't have a result
> to process yet, think that there is one, and kaboom.  It seems to me
> that we should just add an extra case for the result = NULL case as
> there is nothing pending.  A FATAL means that we need to give up
> anyway.
>
> Anthonin, what do you think?

Also reproduced. On a cursory look (I should be able to dig into this
deeper tomorrow), it seems like we're missing a ReadyForQuery response
from the server.

A sync message is normally answered by a ReadyForQuery which is
translated to a PGRES_PIPELINE_SYNC in pqParseInput3. This is why we
add the number of piped_syncs to the requested_results as we need to
consume the generated PGRES_PIPELINE_SYNC with PQgetResult.

With the \sendsync following a COPY, we have two Sync messages but
only receive a single ReadyForQuery response. We have a similar issue
running the following:

\startpipeline
COPY psql_pipeline FROM STDIN;
\syncpipeline
\endpipeline
Enter data to be copied followed by a newline.
End with a backslash and a period on a line by itself, or an EOF signal.
>> COPY 0

The psql session gets stuck in PQgetResult as we're trying to read a
sync response that doesn't exist. Looking at CopyGetData, it seems
like Sync messages are consumed and ignored:

    case PqMsg_Sync:
        /*
         * Ignore Flush/Sync for the convenience of client
         * libraries (such as libpq) that may send those
         * without noticing that the command they just
         * sent was COPY.
         */
        goto readmessage;

So if that's expected, we may need additional logic to avoid
increasing piped_syncs when we're after a COPY? On the other hand,
ignoring the SYNC seems to break the protocol spec expectation that
"there is one and only one ReadyForQuery sent for each Sync".