Thread: BUG #16035: STATEMENT_TIMEOUT not working when we have single quote usage inside CTE which is used in inner sql

The following bug has been logged on the website:

Bug reference:      16035
Logged by:          Raj Mohite
Email address:      rmohite@xento.com
PostgreSQL version: 10.8
Operating system:   Windows 10
Description:

I have created a simple sql where I have added STATEMENT_TIMEOUT = 1 seconds
and added explicit delay(pg_sleep(5) ) of 5 seconds inside CTE. 

Below sql should get killed after 1 second but looks like it is running for
5 seconds.

SET STATEMENT_TIMEOUT = '1s';SELECT * FROM ( WITH test AS ( SELECT
pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;

Note: If we remove the quoted string 'Billy' AS emp_name  from above sql
then proper timeout is getting applied. If we keep quoted string -- 'Billy'
AS emp_name in the comment then also it doesn't work.

Solution: We are still finding the root cause for the above behavior but I
found that if we will put the SET STATEMENT_TIMEOUT before and after the sql
then it working fine.

Example:
SET STATEMENT_TIMEOUT = '3s';SELECT * FROM ( WITH test AS ( SELECT
pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;SET
STATEMENT_TIMEOUT = '1s';  

Above example will timeout after 3 seconds i.e. it will consider the 1st
timeout value.

Can you please help us to know why STATEMENT_TIMEOUT is not working in first
example?

[ cc'ing Tatsuo and Andres, as authors of the relevant commit ]

PG Bug reporting form <noreply@postgresql.org> writes:
> PostgreSQL version: 10.8

> Below sql should get killed after 1 second but looks like it is running for
> 5 seconds.

> SET STATEMENT_TIMEOUT = '1s';SELECT * FROM ( WITH test AS ( SELECT
> pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;

I can reproduce this in v10, but only if I submit the two statements as
a single query string:

psql (10.10)
Type "help" for help.

regression=# \timing
Timing is on.
regression=# SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT
pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;
 ?column?
----------
        1
(1 row)

Time: 5007.648 ms (00:05.008)

If they're sent as separate statements then it works as expected:

psql (10.10)
Type "help" for help.

regression=# \timing
Timing is on.
regression=# SET STATEMENT_TIMEOUT = '1s';SELECT * FROM ( WITH test AS ( SELECT
pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;
SET
Time: 0.635 ms
ERROR:  canceling statement due to statement timeout
Time: 1000.707 ms (00:01.001)

In v11 and up it works the same either way:

psql (11.5)
Type "help" for help.

regression=# \timing
Timing is on.
regression=# SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT
pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;
ERROR:  canceling statement due to statement timeout
Time: 1001.187 ms (00:01.001)

... or does it?

regression=# SET STATEMENT_TIMEOUT = '10s';
SET
Time: 0.462 ms
regression=# SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT
pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;
 ?column?
----------
        1
(1 row)

Time: 5005.946 ms (00:05.006)

The v10-and-below behavior is consistent with the idea that the initial
value of statement_timeout is applied across the whole multi-statement
query string.  Since you didn't set statement_timeout till after the query
string started, the new value doesn't apply until the next submitted
command.

The newer behavior is simply not very consistent.  If you had a prevailing
statement_timeout then it continues to apply; but if you didn't, and you
set one, then it's armed immediately and applies to the rest of the query
string (as a whole, not per-statement).

The change in behavior seems to be a consequence of f8e5f156b,
which made start_xact_command do this unconditionally:

+   /*
+    * Start statement timeout if necessary.  Note that this'll intentionally
+    * not reset the clock on an already started timeout, to avoid the timing
+    * overhead when start_xact_command() is invoked repeatedly, without an
+    * interceding finish_xact_command() (e.g. parse/bind/execute).  If that's
+    * not desired, the timeout has to be disabled explicitly.
+    */
+   enable_statement_timeout();

The commit message claims that this only affected extended query
protocol, but that's obviously false, because start_xact_command
is also called by exec_simple_query.

Not sure what if anything we should do about this.  The semantics
of SET within a multi-statement string have always been pretty
squishy: most variables will affect the remaining statements, but
a few won't.  But I don't like the fact that simple query's timeout
behavior can no longer be categorized as either of those alternatives.
"It affects the later statements, except when it doesn't" seems
unsatisfactory.

tl;dr: I do not think this is buggy in v10.  But arguably there's
a bug in later branches, and they need to go back to behaving
like v10.

            regards, tom lane

> [ cc'ing Tatsuo and Andres, as authors of the relevant commit ]
> 
> PG Bug reporting form <noreply@postgresql.org> writes:
>> PostgreSQL version: 10.8
> 
>> Below sql should get killed after 1 second but looks like it is running for
>> 5 seconds.
> 
>> SET STATEMENT_TIMEOUT = '1s';SELECT * FROM ( WITH test AS ( SELECT
>> pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;
> 
> I can reproduce this in v10, but only if I submit the two statements as
> a single query string:
> 
> psql (10.10)
> Type "help" for help.
> 
> regression=# \timing
> Timing is on.
> regression=# SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT 
> pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;
>  ?column? 
> ----------
>         1
> (1 row)
> 
> Time: 5007.648 ms (00:05.008)
> 
> If they're sent as separate statements then it works as expected:
> 
> psql (10.10)
> Type "help" for help.
> 
> regression=# \timing
> Timing is on.
> regression=# SET STATEMENT_TIMEOUT = '1s';SELECT * FROM ( WITH test AS ( SELECT
> pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;
> SET
> Time: 0.635 ms
> ERROR:  canceling statement due to statement timeout
> Time: 1000.707 ms (00:01.001)
> 
> In v11 and up it works the same either way:
> 
> psql (11.5)
> Type "help" for help.
> 
> regression=# \timing
> Timing is on.
> regression=# SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT 
> pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;
> ERROR:  canceling statement due to statement timeout
> Time: 1001.187 ms (00:01.001)
> 
> ... or does it?
> 
> regression=# SET STATEMENT_TIMEOUT = '10s';
> SET
> Time: 0.462 ms
> regression=# SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT 
> pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;
>  ?column? 
> ----------
>         1
> (1 row)
> 
> Time: 5005.946 ms (00:05.006)
> 
> The v10-and-below behavior is consistent with the idea that the initial
> value of statement_timeout is applied across the whole multi-statement
> query string.  Since you didn't set statement_timeout till after the query
> string started, the new value doesn't apply until the next submitted
> command.
> 
> The newer behavior is simply not very consistent.  If you had a prevailing
> statement_timeout then it continues to apply; but if you didn't, and you
> set one, then it's armed immediately and applies to the rest of the query
> string (as a whole, not per-statement).
> 
> The change in behavior seems to be a consequence of f8e5f156b,
> which made start_xact_command do this unconditionally:
> 
> +   /*
> +    * Start statement timeout if necessary.  Note that this'll intentionally
> +    * not reset the clock on an already started timeout, to avoid the timing
> +    * overhead when start_xact_command() is invoked repeatedly, without an
> +    * interceding finish_xact_command() (e.g. parse/bind/execute).  If that's
> +    * not desired, the timeout has to be disabled explicitly.
> +    */
> +   enable_statement_timeout();
> 
> The commit message claims that this only affected extended query
> protocol, but that's obviously false, because start_xact_command
> is also called by exec_simple_query.
> 
> Not sure what if anything we should do about this.  The semantics
> of SET within a multi-statement string have always been pretty
> squishy: most variables will affect the remaining statements, but
> a few won't.  But I don't like the fact that simple query's timeout
> behavior can no longer be categorized as either of those alternatives.
> "It affects the later statements, except when it doesn't" seems
> unsatisfactory.
> 
> tl;dr: I do not think this is buggy in v10.  But arguably there's
> a bug in later branches, and they need to go back to behaving
> like v10.

I understand the original reporter's complain. Also I understand Tom's
complain to v11's behavior. I will look into the v11 (and above) code.

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

>> tl;dr: I do not think this is buggy in v10.  But arguably there's
>> a bug in later branches, and they need to go back to behaving
>> like v10.
> 
> I understand the original reporter's complain. Also I understand Tom's
> complain to v11's behavior. I will look into the v11 (and above) code.

I admit v11's current behavior is inconstant, but I am not sue going
to back V10's behavior is a good idea.

With attached patch (against master), SET STATEMENT_TIMEOUT
immediately affects to subsequent commands in the multi statement. I
think this is not only more intuitive than v10's behavior but it meets
the original reporter's expectation.

SET STATEMENT_TIMEOUT = '10s';
SET
Time: 0.418 ms
-- SELECT timeout in 1 second.
SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM
test) AS sub;
 
ERROR:  canceling statement due to statement timeout
Time: 1001.107 ms (00:01.001)

Here are results of test cases attached (statement_timeout.sql).

\timing
Timing is on.
-- SELECT timeout in 1 second.
SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM
test) AS sub;
 
psql:/home/t-ishii/tmp/statement_timeout.sql:3: ERROR:  canceling statement due to statement timeout
Time: 1001.138 ms (00:01.001)
SET STATEMENT_TIMEOUT = '10s';
SET
Time: 0.434 ms
-- SELECT timeout in 1 second.
SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM
test) AS sub;
 
psql:/home/t-ishii/tmp/statement_timeout.sql:7: ERROR:  canceling statement due to statement timeout
Time: 1000.978 ms (00:01.001)
-- This time SELECT succeeds and STATEMENT_TIMEOUT is set to 8 secinds.
SET STATEMENT_TIMEOUT = '8s'\;SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM
test) AS sub;
 
 ?column? 
----------
        1
(1 row)

Time: 5004.886 ms (00:05.005)
SHOW STATEMENT_TIMEOUT;
 statement_timeout 
-------------------
 8s
(1 row)

Time: 0.433 ms
-- Following SELECT succeeds because now statement_timeout value is 8 seconds..
SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;
 ?column? 
----------
        1
(1 row)

Time: 5006.196 ms (00:05.006)
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index e8d8e6f828..0ba6fa9d5e 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -4701,7 +4701,8 @@ enable_statement_timeout(void)
 
     if (StatementTimeout > 0)
     {
-        if (!stmt_timeout_active)
+        if (!doing_extended_query_message ||
+            (!stmt_timeout_active && doing_extended_query_message))
         {
             enable_timeout_after(STATEMENT_TIMEOUT, StatementTimeout);
             stmt_timeout_active = true;
\timing
-- SELECT timeout in 1 second.
SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM
test) AS sub;
 

SET STATEMENT_TIMEOUT = '10s';
-- SELECT timeout in 1 second.
SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM
test) AS sub;
 

-- This time SELECT succeeds and STATEMENT_TIMEOUT is set to 8 secinds.
SET STATEMENT_TIMEOUT = '8s'\;SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM
test) AS sub;
 
SHOW STATEMENT_TIMEOUT;

-- Following SELECT succeeds because now statement_timeout value is 8 seconds..
SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;

If there's no objection, I would like to commit/push the diff.

> I admit v11's current behavior is inconstant, but I am not sue going
> to back V10's behavior is a good idea.
> 
> With attached patch (against master), SET STATEMENT_TIMEOUT
> immediately affects to subsequent commands in the multi statement. I
> think this is not only more intuitive than v10's behavior but it meets
> the original reporter's expectation.
> 
> SET STATEMENT_TIMEOUT = '10s';
> SET
> Time: 0.418 ms
> -- SELECT timeout in 1 second.
> SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM
test) AS sub;
 
> ERROR:  canceling statement due to statement timeout
> Time: 1001.107 ms (00:01.001)
> 
> Here are results of test cases attached (statement_timeout.sql).
> 
> \timing
> Timing is on.
> -- SELECT timeout in 1 second.
> SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM
test) AS sub;
 
> psql:/home/t-ishii/tmp/statement_timeout.sql:3: ERROR:  canceling statement due to statement timeout
> Time: 1001.138 ms (00:01.001)
> SET STATEMENT_TIMEOUT = '10s';
> SET
> Time: 0.434 ms
> -- SELECT timeout in 1 second.
> SET STATEMENT_TIMEOUT = '1s'\;SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM
test) AS sub;
 
> psql:/home/t-ishii/tmp/statement_timeout.sql:7: ERROR:  canceling statement due to statement timeout
> Time: 1000.978 ms (00:01.001)
> -- This time SELECT succeeds and STATEMENT_TIMEOUT is set to 8 secinds.
> SET STATEMENT_TIMEOUT = '8s'\;SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM
test) AS sub;
 
>  ?column? 
> ----------
>         1
> (1 row)
> 
> Time: 5004.886 ms (00:05.005)
> SHOW STATEMENT_TIMEOUT;
>  statement_timeout 
> -------------------
>  8s
> (1 row)
> 
> Time: 0.433 ms
> -- Following SELECT succeeds because now statement_timeout value is 8 seconds..
> SELECT * FROM ( WITH test AS ( SELECT pg_sleep(5), 'Billy' as emp_name ) SELECT 1 FROM test ) AS sub;
>  ?column? 
> ----------
>         1
> (1 row)
> 
> Time: 5006.196 ms (00:05.006)

Tatsuo Ishii <ishii@sraoss.co.jp> writes:
> If there's no objection, I would like to commit/push the diff.

I'd like to look at the patch, but I just got back from pgconf.eu
and haven't had time yet.

            regards, tom lane

Tatsuo Ishii <ishii@sraoss.co.jp> writes:
>>> tl;dr: I do not think this is buggy in v10.  But arguably there's
>>> a bug in later branches, and they need to go back to behaving
>>> like v10.

>> I understand the original reporter's complain. Also I understand Tom's
>> complain to v11's behavior. I will look into the v11 (and above) code.

> I admit v11's current behavior is inconstant, but I am not sue going
> to back V10's behavior is a good idea.
> With attached patch (against master), SET STATEMENT_TIMEOUT
> immediately affects to subsequent commands in the multi statement. I
> think this is not only more intuitive than v10's behavior but it meets
> the original reporter's expectation.

Hm.  So, okay, that is a nicer API probably, but note that it also
has the effect that the timeout starts over again for each statement
in the string, while before it applied to the string as a whole.
Are we okay with that change?  (I've not yet looked to see if it's
documented anywhere that it works that way...)  It's kind of tossing
some of the optimization intended by f8e5f156b overboard, since when
a timeout is active we'll be doing timeout calculations for each
statement in the string.

Anyway, granting that we want the definitional change, I still
don't like anything about this patch.  The proposed test

+        if (!doing_extended_query_message ||
+            (!stmt_timeout_active && doing_extended_query_message))

is unreadably complicated and repetitive, and it's undocumented,
and it makes timeout handling work quite differently in the simple
and extended query paths, and it will cause excess timeout calculations
(over and above the newly-necessary ones) because it will force a new
timeout calculation for each start_xact_command call in the simple query
path (yes, we do more than one of those per statement in common cases).
Plus it makes the semantics of stmt_timeout_active rather unclear.

I think if we want to do this, the way to do it is to add another
disable_statement_timeout call while finishing up a non-last query
in exec_simple_query, as per 0001 below.  That adds no extra overhead
unless we have a multi-statement string, and it is much more parallel
to the way things are done for extended protocol.

However ... as I was looking at this, I realized that I didn't like
anything about commit f8e5f156b either.  It introduces private state
in postgres.c that has to be kept in sync with state in timeout.c.
We already found one bug in that (cf be42015fc), and I have little
faith that there aren't others, and no faith at all that we won't
introduce more later.  The right way to manage that, I think, is to
extend timeout.c to allow inquiring whether the timeout is active,
as per 0002 below, so that timeout.c's state is the single source of
truth about this.  Maintaining the extra state needed to make this
cheap allows some other small simplifications/speedups, too, mainly
that we can skip useless searches of the active_timeouts[] array.

Not sure what I think about back-patching this.  We probably can't
back-patch 0001; that's enough of a behavioral change that the cure
seems worse than the disease.  I'm tempted though to argue that we
should back-patch 0002, on the grounds that it prevents possible
bugs and should save a few cycles too.

            regards, tom lane

diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index e8d8e6f..1ecaba0 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -1270,6 +1270,13 @@ exec_simple_query(const char *query_string)
              * those that start or end a transaction block.
              */
             CommandCounterIncrement();
+
+            /*
+             * Disable statement timeout between queries of a multi-query
+             * string, so that the timeout applies separately to each query.
+             * (Our next loop iteration will start a fresh timeout.)
+             */
+            disable_statement_timeout();
         }

         /*
@@ -2135,7 +2142,10 @@ exec_execute_message(const char *portal_name, long max_rows)
              */
             CommandCounterIncrement();

-            /* full command has been executed, reset timeout */
+            /*
+             * Disable statement timeout whenever we complete an Execute
+             * message.  The next protocol message will start a fresh timeout.
+             */
             disable_statement_timeout();
         }

diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 1ecaba0..4bec40a 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -146,11 +146,6 @@ static bool doing_extended_query_message = false;
 static bool ignore_till_sync = false;

 /*
- * Flag to keep track of whether statement timeout timer is active.
- */
-static bool stmt_timeout_active = false;
-
-/*
  * If an unnamed prepared statement exists, it's stored here.
  * We keep it separate from the hashtable kept by commands/prepare.c
  * in order to reduce overhead for short-lived queries.
@@ -4029,7 +4024,6 @@ PostgresMain(int argc, char *argv[],
          */
         disable_all_timeouts(false);
         QueryCancelPending = false; /* second to avoid race condition */
-        stmt_timeout_active = false;

         /* Not reading from the client anymore. */
         DoingCommandRead = false;
@@ -4711,14 +4705,14 @@ enable_statement_timeout(void)

     if (StatementTimeout > 0)
     {
-        if (!stmt_timeout_active)
-        {
+        if (!get_timeout_active(STATEMENT_TIMEOUT))
             enable_timeout_after(STATEMENT_TIMEOUT, StatementTimeout);
-            stmt_timeout_active = true;
-        }
     }
     else
-        disable_timeout(STATEMENT_TIMEOUT, false);
+    {
+        if (get_timeout_active(STATEMENT_TIMEOUT))
+            disable_timeout(STATEMENT_TIMEOUT, false);
+    }
 }

 /*
@@ -4727,10 +4721,6 @@ enable_statement_timeout(void)
 static void
 disable_statement_timeout(void)
 {
-    if (stmt_timeout_active)
-    {
+    if (get_timeout_active(STATEMENT_TIMEOUT))
         disable_timeout(STATEMENT_TIMEOUT, false);
-
-        stmt_timeout_active = false;
-    }
 }
diff --git a/src/backend/utils/misc/timeout.c b/src/backend/utils/misc/timeout.c
index b56259c..a2a4bb6 100644
--- a/src/backend/utils/misc/timeout.c
+++ b/src/backend/utils/misc/timeout.c
@@ -27,7 +27,8 @@ typedef struct timeout_params
 {
     TimeoutId    index;            /* identifier of timeout reason */

-    /* volatile because it may be changed from the signal handler */
+    /* volatile because these may be changed from the signal handler */
+    volatile bool active;        /* true if timeout is in active_timeouts[] */
     volatile bool indicator;    /* true if timeout has occurred */

     /* callback function for timeout, or NULL if timeout not registered */
@@ -105,6 +106,9 @@ insert_timeout(TimeoutId id, int index)
         elog(FATAL, "timeout index %d out of range 0..%d", index,
              num_active_timeouts);

+    Assert(!all_timeouts[id].active);
+    all_timeouts[id].active = true;
+
     for (i = num_active_timeouts - 1; i >= index; i--)
         active_timeouts[i + 1] = active_timeouts[i];

@@ -125,6 +129,9 @@ remove_timeout_index(int index)
         elog(FATAL, "timeout index %d out of range 0..%d", index,
              num_active_timeouts - 1);

+    Assert(active_timeouts[index]->active);
+    active_timeouts[index]->active = false;
+
     for (i = index + 1; i < num_active_timeouts; i++)
         active_timeouts[i - 1] = active_timeouts[i];

@@ -147,9 +154,8 @@ enable_timeout(TimeoutId id, TimestampTz now, TimestampTz fin_time)
      * If this timeout was already active, momentarily disable it.  We
      * interpret the call as a directive to reschedule the timeout.
      */
-    i = find_active_timeout(id);
-    if (i >= 0)
-        remove_timeout_index(i);
+    if (all_timeouts[id].active)
+        remove_timeout_index(find_active_timeout(id));

     /*
      * Find out the index where to insert the new timeout.  We sort by
@@ -349,6 +355,7 @@ InitializeTimeouts(void)
     for (i = 0; i < MAX_TIMEOUTS; i++)
     {
         all_timeouts[i].index = i;
+        all_timeouts[i].active = false;
         all_timeouts[i].indicator = false;
         all_timeouts[i].timeout_handler = NULL;
         all_timeouts[i].start_time = 0;
@@ -524,8 +531,6 @@ enable_timeouts(const EnableTimeoutParams *timeouts, int count)
 void
 disable_timeout(TimeoutId id, bool keep_indicator)
 {
-    int            i;
-
     /* Assert request is sane */
     Assert(all_timeouts_initialized);
     Assert(all_timeouts[id].timeout_handler != NULL);
@@ -534,9 +539,8 @@ disable_timeout(TimeoutId id, bool keep_indicator)
     disable_alarm();

     /* Find the timeout and remove it from the active list. */
-    i = find_active_timeout(id);
-    if (i >= 0)
-        remove_timeout_index(i);
+    if (all_timeouts[id].active)
+        remove_timeout_index(find_active_timeout(id));

     /* Mark it inactive, whether it was active or not. */
     if (!keep_indicator)
@@ -571,13 +575,11 @@ disable_timeouts(const DisableTimeoutParams *timeouts, int count)
     for (i = 0; i < count; i++)
     {
         TimeoutId    id = timeouts[i].id;
-        int            idx;

         Assert(all_timeouts[id].timeout_handler != NULL);

-        idx = find_active_timeout(id);
-        if (idx >= 0)
-            remove_timeout_index(idx);
+        if (all_timeouts[id].active)
+            remove_timeout_index(find_active_timeout(id));

         if (!timeouts[i].keep_indicator)
             all_timeouts[id].indicator = false;
@@ -595,6 +597,8 @@ disable_timeouts(const DisableTimeoutParams *timeouts, int count)
 void
 disable_all_timeouts(bool keep_indicators)
 {
+    int            i;
+
     disable_alarm();

     /*
@@ -613,16 +617,27 @@ disable_all_timeouts(bool keep_indicators)

     num_active_timeouts = 0;

-    if (!keep_indicators)
+    for (i = 0; i < MAX_TIMEOUTS; i++)
     {
-        int            i;
-
-        for (i = 0; i < MAX_TIMEOUTS; i++)
+        all_timeouts[i].active = false;
+        if (!keep_indicators)
             all_timeouts[i].indicator = false;
     }
 }

 /*
+ * Return true if the timeout is active (enabled and not yet fired)
+ *
+ * This is, of course, subject to race conditions, as the timeout could fire
+ * immediately after we look.
+ */
+bool
+get_timeout_active(TimeoutId id)
+{
+    return all_timeouts[id].active;
+}
+
+/*
  * Return the timeout's I've-been-fired indicator
  *
  * If reset_indicator is true, reset the indicator when returning true.
diff --git a/src/include/utils/timeout.h b/src/include/utils/timeout.h
index 9244a2a..ae5389e 100644
--- a/src/include/utils/timeout.h
+++ b/src/include/utils/timeout.h
@@ -80,6 +80,7 @@ extern void disable_timeouts(const DisableTimeoutParams *timeouts, int count);
 extern void disable_all_timeouts(bool keep_indicators);

 /* accessors */
+extern bool get_timeout_active(TimeoutId id);
 extern bool get_timeout_indicator(TimeoutId id, bool reset_indicator);
 extern TimestampTz get_timeout_start_time(TimeoutId id);
 extern TimestampTz get_timeout_finish_time(TimeoutId id);

I wrote:
> Tatsuo Ishii <ishii@sraoss.co.jp> writes:
>> With attached patch (against master), SET STATEMENT_TIMEOUT
>> immediately affects to subsequent commands in the multi statement. I
>> think this is not only more intuitive than v10's behavior but it meets
>> the original reporter's expectation.

> Hm.  So, okay, that is a nicer API probably, but note that it also
> has the effect that the timeout starts over again for each statement
> in the string, while before it applied to the string as a whole.
> Are we okay with that change?  (I've not yet looked to see if it's
> documented anywhere that it works that way...)  It's kind of tossing
> some of the optimization intended by f8e5f156b overboard, since when
> a timeout is active we'll be doing timeout calculations for each
> statement in the string.

I looked around, and as far as I can tell, there is no detail at all
about this in our user-facing docs.  I think we should apply a doc
patch more or less like the attached.  This fails to provide a complete
spec of what the behavior used to be, but I don't much care to try to
document that 100% exactly.

Anyone have an objection to pushing ahead with this for HEAD only?

            regards, tom lane

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 886632f..26ef8ff 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7592,11 +7592,25 @@ COPY postgres_log FROM '/full/path/to/logfile.csv' WITH csv;
       </term>
       <listitem>
        <para>
-        Abort any statement that takes more than the specified duration
-        (defaults to milliseconds), starting from the time the command arrives at the server
-        from the client.  If <varname>log_min_error_statement</varname> is set to
-        <literal>ERROR</literal> or lower, the statement that timed out will also be
-        logged.  A value of zero (the default) turns this off.
+        Abort any statement that takes more than the specified duration.
+        If <varname>log_min_error_statement</varname> is set
+        to <literal>ERROR</literal> or lower, the statement that timed out
+        will also be logged.
+        If the value is specified as a plain number, it is measured in
+        milliseconds by default.
+        A value of zero (the default) disables the timeout.
+       </para>
+
+       <para>
+        The timeout is measured from the time a command arrives at the
+        server until it is completed by the server.  If multiple SQL
+        statements appear in a single simple-Query message, the timeout
+        is applied to each statement separately.
+        (<productname>PostgreSQL</productname> versions before 13 usually
+        treated the timeout as applying to the whole query string.)
+        In extended query protocol, the timeout starts running when any
+        query-related message (Parse, Bind, Execute, Describe) arrives, and
+        it is cancelled by completion of an Execute or Sync message.
        </para>

        <para>