Re: Statement timeout behavior in extended queries - Mailing list pgsql-hackers

Thank you for reviewing my patch!

> Hello,
> 
> 
> I've reviewed the patch.  My understanding is as follows.  Please correct me if I'm wrong.
> 
> * The difference is that the Execute message stops the statement_timeout timer, 

No. Parse, bind and Execute message indivually stops and starts the
statement_timeout timer with the patch. Unless there's a lock
conflict, parse and bind will take very short time. So actually users
could only observe the timeout in execute message though.

> so that the execution of one statement doesn't shorten the timeout
> period of subsequent statements when they are run in batch followed by
> a single Sync message.

This is true. Currently multiple set of parse/bind/execute will not
trigger statement timeout until sync message is sent to
backend. Suppose statement_timeout is set to 3 seconds, combo A
(parse/bind/execute) takes 2 seconds and combo B (parse/bind/execute)
takes 2 seconds then a sync message is followed. Currently statement
timeout is fired in the run of combo B (assuming that parse and bind
take almost 0 seconds). With my patch, no statement timeout will be
fired because both combo A and combo B runs within 3 seconds.

> * This patch is also necessary (or desirable) for the feature "Pipelining/batch mode support for libpq," which is
beingdeveloped for PG 10.  This patch enables correct timeout handling for each statement execution in a batch.
Withoutthis patch, the entire batch of statements is subject to statement_timeout.  That's different from what the
manualdescribes about statement_timeout.  statement_timeout should measure execution of each statement.
 

True.

> Below are what I found in the patch.
> 
> 
> (1)
> +static bool st_timeout = false;
> 
> I think the variable name would better be stmt_timeout_enabled or stmt_timer_started, because other existing names
usestmt to abbreviate statement, and thhis variable represents a state (see xact_started for example.)
 

Agreed. Chaged to stmt_timer_started.

> (2)
> +static void enable_statement_timeout(void)
> +{
> 
> +static void disable_statement_timeout(void)
> +{
> 
> "static void" and the remaining line should be on different lines, as other functions do.

Fixed.

> (3)
> +            /*
> +             * Sanity check
> +             */
> +            if (!xact_started)
> +            {
> +                ereport(ERROR,
> +                        (errcode(ERRCODE_INVALID_PARAMETER_VALUE),
> +                         errmsg("Transaction must have been already started to set statement timeout")));
> +            }
> 
> I think this fragment can be deleted, because enable/disable_timeout() is used only at limited places in postgres.c,
soI don't see the chance of misuse.
 

I'd suggest leave it as it is. Because it might be possible that the
function is used in different place in the future. Or at least we
should document the pre-condition as a comment.

revised patch attached.
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese:http://www.sraoss.co.jp
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index a2282058..68a739e 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -149,6 +149,11 @@ static bool doing_extended_query_message = false;static bool ignore_till_sync = false;/*
+ * Flag to keep track of whether we have started statement timeout timer.
+ */
+static bool stmt_timer_started = 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.
 
@@ -188,6 +193,8 @@ static bool IsTransactionStmtList(List *pstmts);static void drop_unnamed_stmt(void);static void
SigHupHandler(SIGNAL_ARGS);staticvoid log_disconnections(int code, Datum arg);
 
+static void enable_statement_timeout(void);
+static void disable_statement_timeout(void);/* ----------------------------------------------------------------
@@ -1239,6 +1246,11 @@ exec_parse_message(const char *query_string,    /* string to execute */    start_xact_command();
  /*
 
+     * Set statement timeout running, if any
+     */
+    enable_statement_timeout();
+
+    /*     * Switch to appropriate context for constructing parsetrees.     *     * We have two strategies depending
onwhether the prepared statement is
 
@@ -1526,6 +1538,11 @@ exec_bind_message(StringInfo input_message)     */    start_xact_command();
+    /*
+     * Set statement timeout running, if any
+     */
+    enable_statement_timeout();
+    /* Switch back to message context */    MemoryContextSwitchTo(MessageContext);
@@ -1942,6 +1959,11 @@ exec_execute_message(const char *portal_name, long max_rows)    start_xact_command();    /*
+     * Set statement timeout running, if any
+     */
+    enable_statement_timeout();
+
+    /*     * If we re-issue an Execute protocol request against an existing portal,     * then we are only fetching
morerows rather than completely re-executing     * the query from the start. atStart is never reset for a v3 portal, so
we
@@ -2014,6 +2036,11 @@ exec_execute_message(const char *portal_name, long max_rows)             * those that start or
enda transaction block.             */            CommandCounterIncrement();
 
+
+            /*
+             * We need to reset statement timeout if already set.
+             */
+            disable_statement_timeout();        }        /* Send appropriate CommandComplete to client */
@@ -2443,14 +2470,10 @@ start_xact_command(void)    {        StartTransactionCommand();
-        /* Set statement timeout running, if any */
-        /* NB: this mustn't be enabled until we are within an xact */
-        if (StatementTimeout > 0)
-            enable_timeout_after(STATEMENT_TIMEOUT, StatementTimeout);
-        else
-            disable_timeout(STATEMENT_TIMEOUT, false);
-        xact_started = true;
+
+        /* Set statement timeout running, if any */
+        enable_statement_timeout();    }}
@@ -2460,7 +2483,7 @@ finish_xact_command(void)    if (xact_started)    {        /* Cancel any active statement timeout
beforecommitting */
 
-        disable_timeout(STATEMENT_TIMEOUT, false);
+        disable_statement_timeout();        CommitTransactionCommand();
@@ -4511,3 +4534,53 @@ log_disconnections(int code, Datum arg)                    port->user_name, port->database_name,
port->remote_host,                 port->remote_port[0] ? " port=" : "", port->remote_port)));}
 
+
+/*
+ * Set statement timeout if any.
+ */
+static void
+enable_statement_timeout(void)
+{
+    if (!stmt_timer_started)
+    {
+        if (StatementTimeout > 0)
+        {
+
+            /*
+             * Sanity check
+             */
+            if (!xact_started)
+            {
+                ereport(ERROR,
+                        (errcode(ERRCODE_INVALID_PARAMETER_VALUE),
+                         errmsg("Transaction must have been already started to set statement timeout")));
+            }
+
+            ereport(DEBUG3,
+                    (errmsg_internal("Set statement timeout")));
+
+            enable_timeout_after(STATEMENT_TIMEOUT, StatementTimeout);
+            stmt_timer_started = true;
+        }
+        else
+            disable_timeout(STATEMENT_TIMEOUT, false);
+    }
+}
+
+/*
+ * Reset statement timeout if any.
+ */
+static void
+disable_statement_timeout(void)
+{
+    if (stmt_timer_started)
+    {
+        ereport(DEBUG3,
+                    (errmsg_internal("Disable statement timeout")));
+
+        /* Cancel any active statement timeout */
+        disable_timeout(STATEMENT_TIMEOUT, false);
+
+        stmt_timer_started = false;
+    }
+}