Re: Statement timeout

> Oops. Previous example was not appropriate. Here are revised
> examples. (in any case, the time consumed at parse and bind are small,
> and I omit the CHECK_FOR_INTERRUPTS after these commands)
> 
> [example 1]
> 
> statement_timeout = 3s
> 
> parse(statement1) -- time 0. set statement timout timer
> bind(statement1, portal1)
> execute(portal1) -- took 2 seconds
> CHECK_FOR_INTERRUPTS -- 2 seconds passed since time 0. statement timeout does not fire
> parse(statement2)
> bind(statement2, portal2)
> execute(portal2) -- took 2 seconds
> CHECK_FOR_INTERRUPTS -- 4 seconds passed since time 0. the statement timeout fires!
> 
> Another example.
> 
> [example 2]
> 
> statement_timeout = 3s
> 
> parse(statement1) -- time 0. set statement timout timer
> bind(statement1, portal1)
> execute(portal1) -- took 1 second
> CHECK_FOR_INTERRUPTS -- 1 second passed since time 0. statement timeout does not fire
> parse(statement2)
> bind(statement2, portal2)
> execute(portal2) -- took 1 second
> CHECK_FOR_INTERRUPTS -- 2 seconds passed since time 0. the statement timeout fires!
> [client is idle for 2 seconds]
> sync
> CHECK_FOR_INTERRUPTS -- 4 seconds passed since time 0. the statement timeout fires!
> 
> I think current code is good in detecting statement timeout if each
> command execution time actually exceeds the specified timeout. However
> it could report false statement timeout in some cases like above.

Here is the patch against master branch to deal with the problem. I
create new functions in tcop/postgres.c:

static void enable_statement_timeout(void);
static void disable_statement_timeout(void);

Before the code was in start_xact_command() and finish_xact_command()
but I want to manage to disable timeout in exec_execute_command, so I
separated the code into the new functions.

Also start_xact_command() and finish_xact_command() were modified to
use these new functions to avoid code duplication.

I tested the patch using small C program linked with modified libpq
(PQsendQueryParams was modified to issue "flush" message instead of
"sync" message). The statement timeout was set to 3 seconds. With
these test programs, client sends pg_sleep(2) and flush message then
sleep 10 seconds. With current PostgreSQL, this triggers statement
timeout while the client is sleeping. With patched PostgreSQL, this
does not trigger the timeout as expected.

All regression tests passed.

Best regards,
--
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 b185c1b..564855a 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 st_timeout = 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 *parseTrees);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);/* ----------------------------------------------------------------
@@ -2002,6 +2009,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 */
@@ -2433,14 +2445,10 @@ start_xact_command(void)                (errmsg_internal("StartTransactionCommand")));
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();    }}
@@ -2450,7 +2458,7 @@ finish_xact_command(void)    if (xact_started)    {        /* Cancel any active statement timeout
beforecommitting */
 
-        disable_timeout(STATEMENT_TIMEOUT, false);
+        disable_statement_timeout();        /* Now commit the command */        ereport(DEBUG3,
@@ -4510,3 +4518,51 @@ 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 (!st_timeout)
+    {
+        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);
+            st_timeout = true;
+        }
+        else
+            disable_timeout(STATEMENT_TIMEOUT, false);
+    }
+}
+
+/*
+ * Reset statement timeout if any.
+ */
+static void disable_statement_timeout(void)
+{
+    if (st_timeout)
+    {
+        ereport(DEBUG3,
+                    (errmsg_internal("Disable statement timeout")));
+
+        /* Cancel any active statement timeout */
+        disable_timeout(STATEMENT_TIMEOUT, false);
+
+        st_timeout = false;
+    }
+}
#include <stdio.h>
#include <stdlib.h>
#include <stdint.h>
#include <string.h>
#include <sys/types.h>
#include "libpq-fe.h"

static void
exit_nicely(PGconn *conn)
{PQfinish(conn);exit(1);
}

main()
{char *conninfo = "port=11003 dbname=test";PGconn       *conn;PGresult   *res;const char *paramValues[1];
conn = PQconnectdb(conninfo);if (PQstatus(conn) != CONNECTION_OK){    fprintf(stderr, "Connection to database failed:
%s",           PQerrorMessage(conn));    exit_nicely(conn);}
 
paramValues[0] = "2";
fprintf(stderr, "start #1 query\n");PQsendQueryParams(conn,                  "SELECT pg_sleep($1::int)",
 1,        /* one param */                  NULL,    /* let the backend deduce param type */
paramValues,                 NULL,    /* don't need param lengths since text */                  NULL,    /* default to
alltext params */                  0);        /* ask for text results */
 
fprintf(stderr, "end #1 query\n");
sleep(10);
exit(0);
}