Thread: Bug in pgbench prepared statements

Bug in pgbench prepared statements

From
Lev Kokotov
Date:
Hi,

I noticed something that looks like a bug in pgbench when using the prepared protocol. pgbench assumes that all prepared statements are prepared correctly, even if they contain errors (e.g. syntax, column/table doesn't exist, etc.).

My test script is just:

SELECT one;

The output looks something like this:

$ pgbench -f test.sql --protocol prepared -d postgres

[...]
pgbench: client 0 executing script "test.sql"
pgbench: client 0 preparing P_0
pgbench: error: ERROR:  column "one" does not exist

LINE 1: SELECT one;
               ^
pgbench: client 0 sending P_0
pgbench: client 0 receiving
pgbench: client 0 receiving
pgbench: error: client 0 script 0 aborted in command 0 query 0: ERROR:  prepared statement "P_0" does not exist
transaction type: test.sql
[...]

Normally this wouldn't be a big deal, although by itself the output is confusing, since the second error, while technically true, is not what caused the test run to fail. In my case, I was using pgbench to validate the correctness of prepared statements implementation in our pooler. Having the second error sent me on quite a debugging session until I realized that my fix was actually working.

Patch attached, if there is any interest in fixing this small bug.

Cheers!

Lev


Attachment

Re: Bug in pgbench prepared statements

From
"Tristan Partin"
Date:
On Wed Nov 29, 2023 at 7:38 PM CST, Lev Kokotov wrote:
> Patch attached, if there is any interest in fixing this small bug.

I see prepareCommand() is called one more time in
prepareCommandsInPipeline(). Should you also check the return value
there?

It may also be useful to throw this patch on the January commitfest if
no one else comes along to review/commit it. This first set of changes
looks good to me.

--
Tristan Partin
Neon (https://neon.tech)



Re: Bug in pgbench prepared statements

From
Lev Kokotov
Date:
> I see prepareCommand() is called one more time in
> prepareCommandsInPipeline(). Should you also check the return value
> there?

Yes, good catch. New patch attached.

> It may also be useful to throw this patch on the January commitfest if
> no one else comes along to review/commit it.

First time contributing, not familiar with the process here, but happy to learn.

Best,

Lev


On Thu, Nov 30, 2023 at 2:10 PM Tristan Partin <tristan@neon.tech> wrote:
On Wed Nov 29, 2023 at 7:38 PM CST, Lev Kokotov wrote:
> Patch attached, if there is any interest in fixing this small bug.

I see prepareCommand() is called one more time in
prepareCommandsInPipeline(). Should you also check the return value
there?

It may also be useful to throw this patch on the January commitfest if
no one else comes along to review/commit it. This first set of changes
looks good to me.

--
Tristan Partin
Neon (https://neon.tech)
Attachment

Re: Bug in pgbench prepared statements

From
Michael Paquier
Date:
On Thu, Nov 30, 2023 at 07:15:54PM -0800, Lev Kokotov wrote:
>> I see prepareCommand() is called one more time in
>> prepareCommandsInPipeline(). Should you also check the return value
>> there?
>
> Yes, good catch. New patch attached.

Agreed that this is not really helpful as it stands

>> It may also be useful to throw this patch on the January commitfest if
>> no one else comes along to review/commit it.
>
> First time contributing, not familiar with the process here, but happy to
> learn.

The patch you have sent does not apply cleanly on the master branch,
could you rebase please?

FWIW, I am a bit confused by the state of sendCommand().  Wouldn't it
better to consume the errors from PQsendQueryPrepared() and
PQsendQueryParams() when these fail?
--
Michael

Attachment

Re: Bug in pgbench prepared statements

From
Lev Kokotov
Date:
> The patch you have sent does not apply cleanly on the master branch,
> could you rebase please?

Attached. PR against master also here, just to make sure it's mergeable.

> Wouldn't it
> better to consume the errors from PQsendQueryPrepared() and
> PQsendQueryParams() when these fail?

The error is returned in PQPrepare(), which happens only in QUERY_PREPARED mode, so PQsendQueryParams() does not apply, and before PQsendQueryPrepared() is called, so catching the error from PQsendQueryPrepared() is exactly what's causing the bug: ERROR:  prepared statement "P_0" does not exist.

Best,

Lev

On Thu, Nov 30, 2023 at 11:19 PM Michael Paquier <michael@paquier.xyz> wrote:
On Thu, Nov 30, 2023 at 07:15:54PM -0800, Lev Kokotov wrote:
>> I see prepareCommand() is called one more time in
>> prepareCommandsInPipeline(). Should you also check the return value
>> there?
>
> Yes, good catch. New patch attached.

Agreed that this is not really helpful as it stands

>> It may also be useful to throw this patch on the January commitfest if
>> no one else comes along to review/commit it.
>
> First time contributing, not familiar with the process here, but happy to
> learn.

The patch you have sent does not apply cleanly on the master branch,
could you rebase please?

FWIW, I am a bit confused by the state of sendCommand().  Wouldn't it
better to consume the errors from PQsendQueryPrepared() and
PQsendQueryParams() when these fail?
--
Michael
Attachment

Re: Bug in pgbench prepared statements

From
Michael Paquier
Date:
On Fri, Dec 01, 2023 at 07:06:40PM -0800, Lev Kokotov wrote:
> Attached. PR against master also here
> <https://github.com/postgres/postgres/pull/147>, just to make sure it's
> mergeable <https://github.com/postgres/postgres/pull/147.patch>.

Thanks for the updated patch.  It looks sensible seen from here.

+        if (PQresultStatus(res) != PGRES_COMMAND_OK) {
             pg_log_error("%s", PQerrorMessage(st->con));
+            return false;
+        }

Each bracket should be on its own line, that's the format used
elsewhere in the code.

Did you notice that this fails some of the regression tests?  You can
enable these with --enable-tap-tests.  Here is the failure:
[13:57:19.960](0.000s) not ok 241 - pgbench script error: sql syntax error stderr /(?^:prepared statement .* does not
exist)/
[13:57:19.960](0.000s)
[13:57:19.960](0.000s) #   Failed test 'pgbench script error: sql syntax error stderr /(?^:prepared statement .* does
notexist)/' 
#   at t/001_pgbench_with_server.pl line 1150.
[13:57:19.960](0.000s) #                   'pgbench: error: ERROR:  syntax error at or near ";"
# LINE 1: SELECT 1 + ;
#                    ^
# pgbench: error: client 0 aborted in command 0 (SQL) of script 0; SQL command send failed
# pgbench: error: Run was aborted; the above results are incomplete.
# '
#     doesn't match '(?^:prepared statement .* does not exist)'

The test case expects a syntax error as per its name, but we've just
bothered checking for the last pattern of the error generated since
it has been introduced in ed8a7c6fcf92.  I would be more restrictive
and just update the error output in the test, to reflect the error we
want to show up, aka a "syntax error".
--
Michael

Attachment