Thread: Bug in pgbench prepared statements
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
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
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)
> I see prepareCommand() is called one more time in
> prepareCommandsInPipeline(). Should you also check the return value
> there?
> 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.
> 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
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
> The patch you have sent does not apply cleanly on the master branch,
> could you rebase please?
> could you rebase please?
> Wouldn't it
> better to consume the errors from PQsendQueryPrepared() and
> PQsendQueryParams() when these fail?
> 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
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