Thread: Re: Using PQexecQuery in pipeline mode produces unexpected Close messages

Re: Using PQexecQuery in pipeline mode produces unexpected Close messages

From
Kyotaro Horiguchi
Date:
(Moved to -hackers)

At Wed, 8 Jun 2022 17:08:47 +0200, Alvaro Herrera <alvherre@alvh.no-ip.org> wrote in 
> What that Close message is doing is closing the unnamed portal, which
> is otherwise closed implicitly when the next one is opened.  That's how
> single-query mode works: if you run a single portal, it'll be kept open.
> 
> I believe that the right fix is to not send that Close message in
> PQsendQuery.

Agreed. At least Close message in that context is useless and
PQsendQueryGuts doesn't send it. And removes the Close message surely
fixes the issue.

The doc [1] says:

[1] https://www.postgresql.org/docs/14/protocol-flow.html

> The simple Query message is approximately equivalent to the series
> Parse, Bind, portal Describe, Execute, Close, Sync, using the
> unnamed prepared statement and portal objects and no parameters. One

The current implement of PQsendQueryInternal looks like the result of
a misunderstanding of the doc.  In the regression tests, that path is
excercised only for an error case, where no CloseComplete comes.

The attached adds a test for the normal-path of pipelined
PQsendQuery() to simple_pipeline test then modifies that function not
to send Close message. Without the fix, the test fails by "unexpected
notice" even if the trace matches the "expected" content.

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center

Attachment

Re: Using PQexecQuery in pipeline mode produces unexpected Close messages

From
Kyotaro Horiguchi
Date:
At Fri, 10 Jun 2022 15:25:44 +0900 (JST), Kyotaro Horiguchi <horikyota.ntt@gmail.com> wrote in 
> The current implement of PQsendQueryInternal looks like the result of
> a misunderstanding of the doc.  In the regression tests, that path is
> excercised only for an error case, where no CloseComplete comes.
> 
> The attached adds a test for the normal-path of pipelined
> PQsendQuery() to simple_pipeline test then modifies that function not
> to send Close message. Without the fix, the test fails by "unexpected
> notice" even if the trace matches the "expected" content.

And, as a matter of course, this fix should be back-patched to 14.

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center



Re: Using PQexecQuery in pipeline mode produces unexpected Close messages

From
Álvaro Herrera
Date:
On Fri, Jun 10, 2022, at 8:25 AM, Kyotaro Horiguchi wrote:

The current implement of PQsendQueryInternal looks like the result of
a misunderstanding of the doc.  In the regression tests, that path is
excercised only for an error case, where no CloseComplete comes.

The attached adds a test for the normal-path of pipelined
PQsendQuery() to simple_pipeline test then modifies that function not
to send Close message. Without the fix, the test fails by "unexpected
notice" even if the trace matches the "expected" content.

Hah, the patch I wrote is almost identical to yours, down to the notice processor counting the number of notices received.  The only difference is that I put my test in pipeline_abort.

Sadly, it looks like I won't be able to get this patched pushed for 14.4.


=?UTF-8?Q?=C3=81lvaro_Herrera?= <alvherre@alvh.no-ip.org> writes:
> Sadly, it looks like I won't be able to get this patched pushed for 14.4.

I think that's a good thing actually; this isn't urgent enough to
risk a last-minute commit.  Please wait till the release freeze
lifts.

            regards, tom lane



Re: Using PQexecQuery in pipeline mode produces unexpected Close messages

From
Alvaro Herrera
Date:
On 2022-Jun-10, Kyotaro Horiguchi wrote:

> (Moved to -hackers)
> 
> At Wed, 8 Jun 2022 17:08:47 +0200, Alvaro Herrera <alvherre@alvh.no-ip.org> wrote in 
> > What that Close message is doing is closing the unnamed portal, which
> > is otherwise closed implicitly when the next one is opened.  That's how
> > single-query mode works: if you run a single portal, it'll be kept open.
> > 
> > I believe that the right fix is to not send that Close message in
> > PQsendQuery.
> 
> Agreed. At least Close message in that context is useless and
> PQsendQueryGuts doesn't send it. And removes the Close message surely
> fixes the issue.

So, git archaeology led me to this thread
https://postgr.es/m/202106072107.d4i55hdscxqj@alvherre.pgsql
which is why we added that message in the first place.

I was about to push the attached patch (a merged version of Kyotaro's
and mine), but now I'm wondering if that's the right approach.

Alternatives:

- Have the client not complain if it gets CloseComplete in idle state.
  (After all, it's a pretty useless message, since we already do nothing
  with it if we get it in BUSY state.)

- Have the server not send CloseComplete at all in the cases where
  the client is not expecting it.  Not sure how this would be
  implemented.

- Other ideas?

-- 
Álvaro Herrera               48°01'N 7°57'E  —  https://www.EnterpriseDB.com/
"That sort of implies that there are Emacs keystrokes which aren't obscure.
I've been using it daily for 2 years now and have yet to discover any key
sequence which makes any sense."                        (Paul Thomas)

Attachment
Alvaro Herrera <alvherre@alvh.no-ip.org> writes:
> So, git archaeology led me to this thread
> https://postgr.es/m/202106072107.d4i55hdscxqj@alvherre.pgsql
> which is why we added that message in the first place.

Um.  Good thing you looked.  I doubt we want to revert that change now.

> Alternatives:
> - Have the client not complain if it gets CloseComplete in idle state.
>   (After all, it's a pretty useless message, since we already do nothing
>   with it if we get it in BUSY state.)

ISTM the actual problem here is that we're reverting to IDLE state too
soon.  I didn't try to trace down exactly where that's happening, but
I notice that in the non-pipeline case we don't go to IDLE till we've
seen 'Z' (Sync).  Something in the pipeline logic must be jumping the
gun on that state transition.

            regards, tom lane



Re: Using PQexecQuery in pipeline mode produces unexpected Close messages

From
Kyotaro Horiguchi
Date:
At Wed, 15 Jun 2022 14:56:42 -0400, Tom Lane <tgl@sss.pgh.pa.us> wrote in 
> Alvaro Herrera <alvherre@alvh.no-ip.org> writes:
> > So, git archaeology led me to this thread
> > https://postgr.es/m/202106072107.d4i55hdscxqj@alvherre.pgsql
> > which is why we added that message in the first place.
> 
> Um.  Good thing you looked.  I doubt we want to revert that change now.
> 
> > Alternatives:
> > - Have the client not complain if it gets CloseComplete in idle state.
> >   (After all, it's a pretty useless message, since we already do nothing
> >   with it if we get it in BUSY state.)
> 
> ISTM the actual problem here is that we're reverting to IDLE state too
> soon.  I didn't try to trace down exactly where that's happening, but

Yes. I once visited that fact but also I thought that in the
comparison with non-pipelined PQsendQuery, the three messages look
extra.  Thus I concluded (at the time) that removing Close is enough
here.

> I notice that in the non-pipeline case we don't go to IDLE till we've
> seen 'Z' (Sync).  Something in the pipeline logic must be jumping the
> gun on that state transition.

PQgetResult() resets the state to IDLE when not in pipeline mode.

fe-exec.c:2171

>            if (conn->pipelineStatus != PQ_PIPELINE_OFF)
>            {
>                /*
>                 * We're about to send the results of the current query.  Set
>                 * us idle now, and ...
>                 */
>                conn->asyncStatus = PGASYNC_IDLE;

And actually that code let the connection state enter to IDLE before
CloseComplete.  In the test case I posted, the following happens.

  PQsendQuery(conn, "SELECT 1;");
  PQsendFlushRequest(conn);
  PQgetResult(conn);      // state enters IDLE, reads down to <CommandComplete>
  PQgetResult(conn);      // reads <CloseComplete comes>
  PQpipelineSync(conn);   // sync too late

Pipeline feature seems intending to allow PQgetResult called before
PQpipelineSync. And also seems allowing to call QPpipelineSync() after
PQgetResult().

I haven't come up with a valid *fix* of this flow..

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center



Re: Using PQexecQuery in pipeline mode produces unexpected Close messages

From
Kyotaro Horiguchi
Date:
At Thu, 16 Jun 2022 10:34:22 +0900 (JST), Kyotaro Horiguchi <horikyota.ntt@gmail.com> wrote in 
> At Wed, 15 Jun 2022 14:56:42 -0400, Tom Lane <tgl@sss.pgh.pa.us> wrote in 
> > Alvaro Herrera <alvherre@alvh.no-ip.org> writes:
> > > So, git archaeology led me to this thread
> > > https://postgr.es/m/202106072107.d4i55hdscxqj@alvherre.pgsql
> > > which is why we added that message in the first place.
> > 
> > Um.  Good thing you looked.  I doubt we want to revert that change now.
> > 
> > > Alternatives:
> > > - Have the client not complain if it gets CloseComplete in idle state.
> > >   (After all, it's a pretty useless message, since we already do nothing
> > >   with it if we get it in BUSY state.)
> > 
> > ISTM the actual problem here is that we're reverting to IDLE state too
> > soon.  I didn't try to trace down exactly where that's happening, but
> 
> Yes. I once visited that fact but also I thought that in the
> comparison with non-pipelined PQsendQuery, the three messages look
> extra.  Thus I concluded (at the time) that removing Close is enough
> here.
> 
> > I notice that in the non-pipeline case we don't go to IDLE till we've
> > seen 'Z' (Sync).  Something in the pipeline logic must be jumping the
> > gun on that state transition.
> 
- PQgetResult() resets the state to IDLE when not in pipeline mode.

D... the "not" should not be there.

+ PQgetResult() resets the state to IDLE while in pipeline mode.

> fe-exec.c:2171
> 
> >            if (conn->pipelineStatus != PQ_PIPELINE_OFF)
> >            {
> >                /*
> >                 * We're about to send the results of the current query.  Set
> >                 * us idle now, and ...
> >                 */
> >                conn->asyncStatus = PGASYNC_IDLE;
> 
> And actually that code let the connection state enter to IDLE before
> CloseComplete.  In the test case I posted, the following happens.
> 
>   PQsendQuery(conn, "SELECT 1;");
>   PQsendFlushRequest(conn);
>   PQgetResult(conn);      // state enters IDLE, reads down to <CommandComplete>
>   PQgetResult(conn);      // reads <CloseComplete comes>
>   PQpipelineSync(conn);   // sync too late
> 
> Pipeline feature seems intending to allow PQgetResult called before
> PQpipelineSync. And also seems allowing to call QPpipelineSync() after
> PQgetResult().
> 
> I haven't come up with a valid *fix* of this flow..

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center



Re: Using PQexecQuery in pipeline mode produces unexpected Close messages

From
Kyotaro Horiguchi
Date:
At Thu, 16 Jun 2022 10:34:22 +0900 (JST), Kyotaro Horiguchi <horikyota.ntt@gmail.com> wrote in 
> PQgetResult() resets the state to IDLE while in pipeline mode.
> 
> fe-exec.c:2171
> 
> >            if (conn->pipelineStatus != PQ_PIPELINE_OFF)
> >            {
> >                /*
> >                 * We're about to send the results of the current query.  Set
> >                 * us idle now, and ...
> >                 */
> >                conn->asyncStatus = PGASYNC_IDLE;
> 
> And actually that code let the connection state enter to IDLE before
> CloseComplete.  In the test case I posted, the following happens.
> 
>   PQsendQuery(conn, "SELECT 1;");
>   PQsendFlushRequest(conn);
>   PQgetResult(conn);      // state enters IDLE, reads down to <CommandComplete>
>   PQgetResult(conn);      // reads <CloseComplete comes>
>   PQpipelineSync(conn);   // sync too late
> 
> Pipeline feature seems intending to allow PQgetResult called before
> PQpipelineSync. And also seems allowing to call QPpipelineSync() after
> PQgetResult().
> 
> I haven't come up with a valid *fix* of this flow..

The attached is a crude patch to separate the state for PIPELINE-IDLE
from PGASYNC_IDLE.  I haven't found a better way..

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center



Attachment

Re: Using PQexecQuery in pipeline mode produces unexpected Close messages

From
Alvaro Herrera
Date:
On 2022-Jun-16, Kyotaro Horiguchi wrote:

> The attached is a crude patch to separate the state for PIPELINE-IDLE
> from PGASYNC_IDLE.  I haven't found a better way..

Ah, yeah, this might be a way to fix this.

Something very similar to a PIPELINE_IDLE mode was present in Craig's
initial patch for pipeline mode.  However, I fought very hard to remove
it, because it seemed to me that failing to handle it correctly
everywhere would lead to more bugs than not having it.  (Indeed, there
were some.)

However, I see now that your patch would not only fix this bug, but also
let us remove the ugly "notionally not-idle" bit in fe-protocol3.c,
which makes me ecstatic.  So let's push forward with this.  However,
this means we'll have to go over all places that use asyncStatus to
ensure that they all handle the new value correctly.

I did found one bug in your patch: in the switch for asyncStatus in
PQsendQueryStart, you introduce a new error message.  With the current
tests, that never fires, which is telling us that our coverage is not
complete.  But with the right sequence of libpq calls, which the
attached adds (note that it's for REL_14_STABLE), that can be hit, and
it's easy to see that throwing an error there is a mistake.  The right
action to take there is to let the action through.

Others to think about:

PQisBusy (I think no changes are needed),
PQfn (I think it should accept a call in PGASYNC_PIPELINE_IDLE mode;
fully untested in pipeline mode),
PQexitPipelineMode (I think it needs to return error; needs test case),
PQsendFlushRequest (I think it should let through; ditto).

I also attach a patch to make the test suite use Test::Differences, if
available.  It makes the diffs of the traces much easier to read, when
they fail.  (I wish for a simple way to set the context size, but that
would need a shim routine that I'm currently too lazy to write.)

-- 
Álvaro Herrera               48°01'N 7°57'E  —  https://www.EnterpriseDB.com/

Attachment