extended query protcol violation?

Tatsuo Ishii <ishii@sraoss.co.jp> writes:

While looking into an issue of Pgpool-II, I found an interesting
behavior of a PostgreSQL client.
Below is a trace from pgproto to reproduce the client's behavior.

It starts a transacton.

FE=> Parse(stmt="S1", query="BEGIN")
FE=> Bind(stmt="S1", portal="")
FE=> Execute(portal="")
:
Commit the transaction

FE=> Parse(stmt="S1", query="COMMIT")
FE=> Bind(stmt="S1", portal="")
FE=> Execute(portal="")

Hm, I'd expect the second Parse to generate a "prepared statement already
exists" error due to reuse of the "S1" statement name. Is there more
in this trace than you're showing us?

Send sync message.

FE=> Sync

Now the interesting part. After sync it a close message is sent.

FE=> Close(stmt="S1")

That part seems fine to me.

I thought all extended query protocol messages are finished by a sync
message. But in the example above, a close message is issued, followed
by a simple query without a sync message. Should PostgreSQL regard
this as a protocol violation?

No, although it looks like buggy behavior on the client's part, because
it's unlikely to work well if there's any error in the Close operation.
The protocol definition is that an error causes the backend to discard
messages until Sync, so that if that Close fails, the following simple
Query will just be ignored. Most likely, that's not the behavior the
client wanted ... but it's not a protocol violation, IMO.

regards, tom lane

Tatsuo Ishii <ishii@sraoss.co.jp> writes:

While looking into an issue of Pgpool-II, I found an interesting
behavior of a PostgreSQL client.
Below is a trace from pgproto to reproduce the client's behavior.

It starts a transacton.

FE=> Parse(stmt="S1", query="BEGIN")
FE=> Bind(stmt="S1", portal="")
FE=> Execute(portal="")
:
Commit the transaction

FE=> Parse(stmt="S1", query="COMMIT")
FE=> Bind(stmt="S1", portal="")
FE=> Execute(portal="")

Hm, I'd expect the second Parse to generate a "prepared statement already
exists" error due to reuse of the "S1" statement name. Is there more
in this trace than you're showing us?

Oh, yes. Actually the S1 statement was closed before the parse
message. I should have mentioned it in the previous email.

Send sync message.

FE=> Sync

Now the interesting part. After sync it a close message is sent.

FE=> Close(stmt="S1")

That part seems fine to me.

I thought all extended query protocol messages are finished by a sync
message. But in the example above, a close message is issued, followed
by a simple query without a sync message. Should PostgreSQL regard
this as a protocol violation?

No, although it looks like buggy behavior on the client's part, because
it's unlikely to work well if there's any error in the Close operation.
The protocol definition is that an error causes the backend to discard
messages until Sync, so that if that Close fails, the following simple
Query will just be ignored. Most likely, that's not the behavior the
client wanted ... but it's not a protocol violation, IMO.

Yes, you are right. I actually tried with errornouse close message
(instead of giving 'S' to indicate that I want to close a statement, I
gave 'T'). Ssubsequent simple query "BEGIN" was ignored.

BTW, I also noticed that after the last "BEGIN" simple query, backend
responded with CloseComplete message before a CommandComplete message.
Accoring to our docs:

https://www.postgresql.org/docs/11/protocol-flow.html#id-1.10.5.7.4

responses of a simple query do not include CloseComplete (or any other
extended protocol message responses). So it seems current behavior of
the backend does not follow the protocol defined in the doc. Probably
we should either fix the doc (stats that resoponses from a simple
query are not limited to those messages) or fix the behavior of the
backend.

Here is the whole message exchanging log:

FE=> Parse(stmt="S1", query="BEGIN")
FE=> Bind(stmt="S1", portal="")
FE=> Execute(portal="")
FE=> Close(stmt="S1")
FE=> Parse(stmt="S2", query="SELECT 1")
FE=> Bind(stmt="S2", portal="")
FE=> Execute(portal="")
FE=> Parse(stmt="S1", query="COMMIT")
FE=> Bind(stmt="S1", portal="")
FE=> Execute(portal="")
FE=> Sync
<= BE ParseComplete
<= BE BindComplete
<= BE CommandComplete(BEGIN)
<= BE CloseComplete
<= BE ParseComplete
<= BE BindComplete
<= BE DataRow
<= BE CommandComplete(SELECT 1)
<= BE ParseComplete
<= BE BindComplete
<= BE CommandComplete(COMMIT)
<= BE ReadyForQuery(I)
FE=> Close(stmt="S2")
FE=> Close(stmt="S1")
FE=> Query (query="BEGIN")
<= BE CloseComplete
<= BE CloseComplete
<= BE CommandComplete(BEGIN)
<= BE ReadyForQuery(T)
FE=> Terminate

Best regards,
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese:http://www.sraoss.co.jp

Tatsuo>responses of a simple query do not include CloseComplete

Tatsuo, where do you get the logs from?
I guess you are just confused by the PRINTED order of the messages in the
log.
Note: wire order do not have to be exactly the same as the order in the log
since messages are buffered, then might be read in batches.

In other words, an application might just batch (send all three) close(s2),
close(s1), query(begin) messages, then read the responses.
How does it break protocol?

Vladimir

Tatsuo>responses of a simple query do not include CloseComplete

Tatsuo, where do you get the logs from?

As I said, pgproto.

https://github.com/tatsuo-ishii/pgproto

I guess you are just confused by the PRINTED order of the messages in the
log.
Note: wire order do not have to be exactly the same as the order in the log
since messages are buffered, then might be read in batches.

pgproto directly reads from socket using read system call. There's no
buffer here.

In other words, an application might just batch (send all three) close(s2),
close(s1), query(begin) messages, then read the responses.
How does it break protocol?

Again as I said before, the doc says in extended query protocol a
sequence of extended messages (parse, bind. describe, execute, closes)
should be followed by a sync message. ie.

close
close
sync
query(begin)

Maybe

close
close
query(begin)

is not a violation of protocol, but still I would say this is buggy
because of the reason Tom said, and I agree with him.

Best regards,
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese:http://www.sraoss.co.jp

On Sat, 8 Dec 2018 at 05:16, Tatsuo Ishii <ishii@sraoss.co.jp> wrote:

Tatsuo>responses of a simple query do not include CloseComplete

Tatsuo, where do you get the logs from?

As I said, pgproto.

https://github.com/tatsuo-ishii/pgproto

I guess you are just confused by the PRINTED order of the messages in the
log.
Note: wire order do not have to be exactly the same as the order in the

log

since messages are buffered, then might be read in batches.

pgproto directly reads from socket using read system call. There's no
buffer here.

In other words, an application might just batch (send all three)

close(s2),

close(s1), query(begin) messages, then read the responses.
How does it break protocol?

Again as I said before, the doc says in extended query protocol a
sequence of extended messages (parse, bind. describe, execute, closes)
should be followed by a sync message. ie.

close
close
sync
query(begin)

Maybe

close
close
query(begin)

is not a violation of protocol, but still I would say this is buggy
because of the reason Tom said, and I agree with him.

Curious what client is this that is violating the protocol.

Dave Cramer

davec@postgresintl.com
www.postgresintl.com

Curious what client is this that is violating the protocol.

I stand corrected: that is not a violation, however client might get
unexpected failure of query(begin) in a rare case of close(s1) or close(s2)
fail.

Vladimir

Curious what client is this that is violating the protocol.

I heard it was a Java program.

Best regards,
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese:http://www.sraoss.co.jp

On Sat, 8 Dec 2018 at 07:50, Tatsuo Ishii <ishii@sraoss.co.jp> wrote:

Curious what client is this that is violating the protocol.

I heard it was a Java program.

This is not surprising there are a proliferation of non-blocking
implementations,
probably approaching 10 different implementations now.

Dave Cramer

davec@postgresintl.com
www.postgresintl.com

Curious what client is this that is violating the protocol.

I heard it was a Java program.

This is not surprising there are a proliferation of non-blocking
implementations,
probably approaching 10 different implementations now.

Do you think some of the implementations may not be appropriate if
they behave like that discussed in this thread? If so, maybe it is
worth to add a warning to the backend.

Best regards,
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese:http://www.sraoss.co.jp

On Sat, 8 Dec 2018 at 08:18, Tatsuo Ishii <ishii@sraoss.co.jp> wrote:

Curious what client is this that is violating the protocol.

I heard it was a Java program.

This is not surprising there are a proliferation of non-blocking
implementations,
probably approaching 10 different implementations now.

Do you think some of the implementations may not be appropriate if
they behave like that discussed in this thread? If so, maybe it is
worth to add a warning to the backend.

Given that java code is notorious for not reading warnings, I'd say no
That said I'd probably be in favour of a DEBUG mode that did warn.

Dave Cramer

davec@postgresintl.com
www.postgresintl.com