| From: | Ayush Tiwari <ayushtiwari(dot)slg01(at)gmail(dot)com> |
|---|---|
| To: | Tomas Vondra <tomas(at)vondra(dot)me> |
| Cc: | PostgreSQL Hackers <pgsql-hackers(at)postgresql(dot)org> |
| Subject: | Re: two statement_timeout race conditions |
| Date: | 2026-11-09 08:49:22 |
| Message-ID: | CAJTYsWUG8_LJiwYmXo-suuBvQRm-Uc3mkP8ETg8JW2TgZLnz1Q@mail.gmail.com |
| Views: | Whole Thread | Raw Message | Download mbox | Resend email |
| Thread: | |
| Lists: | pgsql-hackers |
Hi,
On Mon, 9 Nov 2026 at 05:42, Tomas Vondra <tomas(at)vondra(dot)me> wrote:
>
> Hi,
>
> While running a stress test on a patch I'm working on, I ran into two
> annoying race conditions with statement_timeout. It's not a huge issue,
> most people either don't have statement_timeout set at all, or there's
> sufficient margin to not hit the timeout very often. I've since
> mitigated that in my test script, but it was annoying and it took me a
> while to figure out what's going to (and that it's not a bug in the new
> code I was testing).
>
>
> 1) statement_timeout can kill the next command instead
>
> Roughly what happens is that the command takes just about the timeout,
> the timeout fires, but the statement does not check interrupts before it
> ends, and we leave the cancel request as pending. Then we run the next
> command (which could be as simple as "SET guc"), and that gets killed by
> the timeout. That's exactly what I saw with statement_timeout = '60s',
> SET statements getting aborted.
>
> This happens because isable_statement_timeout() does nothing if
> get_timeout_active() says the timeout is no longer active, which is the
> case once it has fired. So the indicator stays set, and then is reported
> as a statement timeout against whatever comes next (without being
> executed at all).
>
> I'm attaching a SQL reproducer for that (repro-exec.sql), leveraging the
> fact that lpad() does not check interrupts even for very long values
> (which we should probably fix, "repeat" already does that). And
> CALL/FETCH don't either.
>
> The attached 0001 fixes this race by doing pretty much the same thing as
> ProcessInterrupts() for QueryCancelPending - checking both lock/timeout
> indicators, and resetting the flag. With this the reproducer no longer
> reproduces the unexpected interruptions.
Thanks for the patches, the repros made this easy to check.
>
> 2) statement timeout reported as "user request" cancellation
>
> While looking at the code and trying to come up with reproducers for the
> first issue, I ran into a second race, where we correctly cancel the
> query due to a timeout, but report it happened due to a "user request".
>
> It can happen if the timeout expires while parsing a long query string
> (yes, that's not very common), because that does not check interrupts.
> In exec_simple_query() we start the timer, do parsing etc., and then
> call enable_statement_timeout() again, which does this:
>
> if (!get_timeout_active(STATEMENT_TIMEOUT) &&
> !get_timeout_indicator(STATEMENT_TIMEOUT, false))
> enable_timeout_after(STATEMENT_TIMEOUT, StatementTimeout);
>
> But get_timeout_active(() returns false if the timer already fired, so
> the timer gets restarted, but leaves QueryCancelPending set. And so on
> the next CHECK_FOR_INTERRUPTS() the query gets cancelled with the
> misleading "canceling statement due to user request" reason.
>
> I'm attaching a SQL reproducer for this too (repro-parse.sql), hitting
> this. It's a bit artificial, I don't think I've seen this in practice
> (even though some of the queries the stress test produces are long and
> complex). 0002 fixes that by not restarting the timer that has fired
> (which relies on the previous commit).
I was poking at this a bit, and I think it would be good to also check
QueryCancelPending there, i.e. only skip the restart while the cancel
is actually still pending:
if (!get_timeout_active(STATEMENT_TIMEOUT) &&
!(QueryCancelPending &&
get_timeout_indicator(STATEMENT_TIMEOUT, false)))
enable_timeout_after(STATEMENT_TIMEOUT, StatementTimeout);
Otherwise, if the cancel already got handled somewhere else (e.g. in the
sync rep wait), the indicator stays set and the next query can end up
running without any statement timeout.
It's a pretty narrow case, but seems worth fixing.
Rest looks good to me.
Regards,
Ayush
| From | Date | Subject | |
|---|---|---|---|
| Next Message | Jim Jones | 2026-11-09 09:06:12 | Re: Reject access to unlogged tables in contrib modules |
| Previous Message | Zsolt Parragi | 2026-11-09 08:46:01 | Re: BGWORKER_INTERRUPTIBLE workers are never restarted after DROP/ALTER/CREATE DATABASE |