Re: [HACKERS] Statement timeout behavior in extended queries
> On 2017-09-10 17:12:19 -0700, Andres Freund wrote: >> On 2017-09-11 09:10:49 +0900, Tatsuo Ishii wrote: >> > If you don't mind, can you please commit/push the patch? >> >> Ok, will do so. > > And, done. Thanks for patch and reminder! Thanks! -- Tatsuo Ishii SRA OSS, Inc. Japan English: http://www.sraoss.co.jp/index_en.php Japanese:http://www.sraoss.co.jp -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
On 2017-09-10 17:12:19 -0700, Andres Freund wrote: > On 2017-09-11 09:10:49 +0900, Tatsuo Ishii wrote: > > If you don't mind, can you please commit/push the patch? > > Ok, will do so. And, done. Thanks for patch and reminder! - Andres -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
Hi, On 2017-09-11 09:10:49 +0900, Tatsuo Ishii wrote: > If you don't mind, can you please commit/push the patch? Ok, will do so. Greetings, Andres Freund -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
Andres, If you don't mind, can you please commit/push the patch? Best regards, -- Tatsuo Ishii SRA OSS, Inc. Japan English: http://www.sraoss.co.jp/index_en.php Japanese:http://www.sraoss.co.jp >> What do you think? I've not really tested this with the extended >> protocol, so I'd appreciate if you could rerun your test from the >> older thread. > > Attached is your patch just rebased against master branch. > > Also I attached the test cases and results using pgproto on patched > master branch. All looks good to me. > > Best regards, > -- > Tatsuo Ishii > SRA OSS, Inc. Japan > English: http://www.sraoss.co.jp/index_en.php > Japanese:http://www.sraoss.co.jp -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
> What do you think? I've not really tested this with the extended
> protocol, so I'd appreciate if you could rerun your test from the
> older thread.
Attached is your patch just rebased against master branch.
Also I attached the test cases and results using pgproto on patched
master branch. All looks good to me.
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 8d3fecf..6c53b9c 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -144,6 +144,11 @@ 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.
@@ -182,6 +187,8 @@ static bool IsTransactionExitStmtList(List *pstmts);
static bool IsTransactionStmtList(List *pstmts);
static void drop_unnamed_stmt(void);
static void log_disconnections(int code, Datum arg);
+static void enable_statement_timeout(void);
+static void disable_statement_timeout(void);
/*
@@ -1228,7 +1235,8 @@ exec_parse_message(const char *query_string, /* string to execute */
/*
* Start up a transaction command so we can run parse analysis etc. (Note
* that this will normally change current memory context.) Nothing happens
- * if we are already in one.
+ * if we are already in one. This also arms the statement timeout if
+ * necessary.
*/
start_xact_command();
@@ -1516,7 +1524,8 @@ exec_bind_message(StringInfo input_message)
/*
* Start up a transaction command so we can call functions etc. (Note that
* this will normally change current memory context.) Nothing happens if
- * we are already in one.
+ * we are already in one. This also arms the statement timeout if
+ * necessary.
*/
start_xact_command();
@@ -2008,6 +2017,9 @@ exec_execute_message(const char *portal_name, long max_rows)
* those that start or end a transaction block.
*/
CommandCounterIncrement();
+
+ /* full command has been executed, reset timeout */
+ disable_statement_timeout();
}
/* Send appropriate CommandComplete to client */
@@ -2437,25 +2449,27 @@ 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;
}
+
+ /*
+ * 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();
}
static void
finish_xact_command(void)
{
+ /* cancel active statement timeout after each command */
+ disable_statement_timeout();
+
if (xact_started)
{
- /* Cancel any active statement timeout before committing */
- disable_timeout(STATEMENT_TIMEOUT, false);
-
CommitTransactionCommand();
#ifdef MEMORY_CONTEXT_CHECKING
@@ -4521,3 +4535,42 @@ log_disconnections(int code, Datum arg)
port->user_name, port->database_name, port->remote_host,
port->remote_port[0] ? " port=" : "", port->remote_port)));
}
+
+/*
+ * Start statement timeout timer, if enabled.
+ *
+ * If there's already a timeout running, don't restart the timer. That
+ * enables compromises between accuracy of timeouts and cost of starting a
+ * timeout.
+ */
+static void
+enable_statement_timeout(void)
+{
+ /* must be within an xact */
+ Assert(xact_started);
+
+ if (StatementTimeout > 0)
+ {
+ if (!stmt_timeout_active)
+ {
+ enable_timeout_after(STATEMENT_TIMEOUT, StatementTimeout);
+ stmt_timeout_active = true;
+ }
+ }
+ else
+ disable_timeout(STATEMENT_TIMEOUT, false);
+}
+
+/*
+ * Disable statement timeout, if active.
+ */
+static void
+disable_statement_timeout(void)
+{
+ if (stmt_timeout_active)
+ {
+ disable_timeout(STATEMENT_TIMEOUT, false);
+
+ stmt_timeout_active = false;
+ }
+}
== 001-without-trans ===
FE=> Query(query="SET statement_timeout = '4s'")
<= BE CommandComplete(SET)
<= BE ReadyForQuery(I)
FE=> Parse(stmt="", query="SELECT pg_sleep(3)")
FE=> Bind(stmt="", portal="")
FE=> Execute(portal="")
FE=> Parse(stmt="", query="SELECT pg_sleep(2)")
FE=> Bind(stmt="", portal="")
FE=> Execute(portal="")
FE=> Sync
<= BE ParseComplete
<= BE BindComplete
<= BE D
Re: [HACKERS] Statement timeout behavior in extended queries
On 2017-04-05 09:46:31 -0400, Tom Lane wrote: > Andres Freund writes: > > On 2017-04-05 00:39:51 -0400, Tom Lane wrote: > >> but > >> if that's what we're doing, let's make sure we do it consistently. > >> I haven't read the patch, but the comments in this thread make me fear > >> that it's introducing some ad-hoc, inconsistent behavior. > > > I'm a bit worried too due to the time constraints here, but I think > > resetting the clock at Execute too actually makes a fair amount sense. > > Meh. Two days before feature freeze is not the time to be introducing > a rushed redefinition of the wire protocol --- and let's not fool > ourselves, that is what this amounts to. Let's push this out to v11 > and think about it more carefully. What I was trying to say is that I think the change makes sense and isn't particularly ad-hoc, but that I don't think we need to force this for v10. Greetings, Andres Freund -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
Andres Freund writes: > On 2017-04-05 00:39:51 -0400, Tom Lane wrote: >> but >> if that's what we're doing, let's make sure we do it consistently. >> I haven't read the patch, but the comments in this thread make me fear >> that it's introducing some ad-hoc, inconsistent behavior. > I'm a bit worried too due to the time constraints here, but I think > resetting the clock at Execute too actually makes a fair amount sense. Meh. Two days before feature freeze is not the time to be introducing a rushed redefinition of the wire protocol --- and let's not fool ourselves, that is what this amounts to. Let's push this out to v11 and think about it more carefully. regards, tom lane -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
> Then, the following sequence should have occurred. The test result is valid. Yes, I remembered that and was about to make a posting :-) > # Execute statement which takes 2 seconds. > 'P' "S1""SELECT pg_sleep(2)"0 > -> start transaction T1 > 'B' "S2""S1"0 0 0 Yes, an extended query automatically starts a transaction if there's no ongoing transaction. > 'P' "" "SET statement_timeout = '1s'" 0 > 'B' "" "" 0 0 0 > 'E' "" 0 > > # Execute statement which takes 2 seconds (statement timeout expected). > 'E' "S2"0 > -> timeout error occurred, T1 aborted Right. The automatically started transaction is aborted and the effect of the set statement is canceled. In summary, as far as I know Andres's patch is working as expected. Best regards, -- Tatsuo Ishii SRA OSS, Inc. Japan English: http://www.sraoss.co.jp/index_en.php Japanese:http://www.sraoss.co.jp -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
On 2017-04-05 00:39:51 -0400, Tom Lane wrote: > Andres Freund writes: > > On 2017-04-05 10:05:19 +0900, Tatsuo Ishii wrote: > >> What's your point of the question? What kind of problem do you expect > >> if the timeout starts only once at the first parse meesage out of > >> bunch of parse messages? > > > It's perfectly valid to send a lot of Parse messages without > > interspersed Sync or Bind/Execute message. There'll be one timeout > > covering all of those Parse messages, which can thus lead to a timeout, > > even though nothing actually takes long individually. > > It might well be reasonable to redefine statement_timeout as limiting the > total time from the first client input to the response to Sync ... That's actually the current behaviour. start_xact_command arms the timer in the !xact_started case, and only finish_xact_command() disarms it. finish_xact_command() is issued for Sync messsages and simple statements. I brought the case up because what we're discussing is changing things so Execute resets the clock (more precisely disables it, and have it reenabled later). So it'd be "fixed" for pipelined Execute statements, but not for pipelined Parses. Changing things so that Parse/Bind also reset the timing would increase overhead - and it'd not be useful in practice, because Sync's are sent by the drivers that support pipelining when statements are prepared. > but > if that's what we're doing, let's make sure we do it consistently. > I haven't read the patch, but the comments in this thread make me fear > that it's introducing some ad-hoc, inconsistent behavior. I'm a bit worried too due to the time constraints here, but I think resetting the clock at Execute too actually makes a fair amount sense. Greetings, Andres Freund -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
From: pgsql-hackers-ow...@postgresql.org > [mailto:pgsql-hackers-ow...@postgresql.org] On Behalf Of Tatsuo Ishii > Since pgproto is a dumb protocol machine, it does not start a transaction > automatically (user needs to explicitly send a start transaction command > via either simple or extended query). In this particular case no explicit > transaction has started. > Then, the following sequence should have occurred. The test result is valid. # Execute statement which takes 2 seconds. 'P' "S1""SELECT pg_sleep(2)"0 -> start transaction T1 'B' "S2""S1"0 0 0 'P' "" "SET statement_timeout = '1s'" 0 'B' "" "" 0 0 0 'E' "" 0 # Execute statement which takes 2 seconds (statement timeout expected). 'E' "S2"0 -> timeout error occurred, T1 aborted # Issue Sync message 'S' -> rolled back T1, so statement_timeout reverted to 3s # Receive response from backend 'Y' # Execute statement which takes 2 seconds (statement timeout expected). 'P' "S3""SELECT pg_sleep(2)"0 -> start transaction T2 'B' "S2""S3"0 0 0 'E' "S2"0 # Issue Sync message 'S' -> committed T2 Regards Takayuki Tsunakawa -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
> From: pgsql-hackers-ow...@postgresql.org >> [mailto:pgsql-hackers-ow...@postgresql.org] On Behalf Of Tatsuo Ishii >> I have done tests using pgproto. One thing I noticed a strange behavior. >> Below is an output of pgproto. The test first set the timeout to 3 seconds, >> and parse/bind for "SELECT pg_sleep(2)" then set timeout to 1 second using >> extended query. Subsequent Execute emits a statement timeout error as >> expected, but next "SELECT pg_sleep(2)" >> call using extended query does not emit a statement error. The test for >> this is "007-timeout-twice". Attached is the test cases including this. > > What's the handling of transactions like in pgproto? I guess the first > statement timeout error rolled back the effect of "SET statement_timeout = > '1s'", and the timeout reverted to 3s or some other value. Since pgproto is a dumb protocol machine, it does not start a transaction automatically (user needs to explicitly send a start transaction command via either simple or extended query). In this particular case no explicit transaction has started. Best regards, -- Tatsuo Ishii SRA OSS, Inc. Japan English: http://www.sraoss.co.jp/index_en.php Japanese:http://www.sraoss.co.jp -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
From: pgsql-hackers-ow...@postgresql.org > [mailto:pgsql-hackers-ow...@postgresql.org] On Behalf Of Tatsuo Ishii > I have done tests using pgproto. One thing I noticed a strange behavior. > Below is an output of pgproto. The test first set the timeout to 3 seconds, > and parse/bind for "SELECT pg_sleep(2)" then set timeout to 1 second using > extended query. Subsequent Execute emits a statement timeout error as > expected, but next "SELECT pg_sleep(2)" > call using extended query does not emit a statement error. The test for > this is "007-timeout-twice". Attached is the test cases including this. What's the handling of transactions like in pgproto? I guess the first statement timeout error rolled back the effect of "SET statement_timeout = '1s'", and the timeout reverted to 3s or some other value. Regards Takayuki Tsunakawa -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
>> What do you think? I've not really tested this with the extended protocol, >> so I'd appreciate if you could rerun your test from the older thread. > > The patch looks good and cleaner. It looks like the code works as expected. > As before, I ran one INSERT statement with PgJDBC, with gdb's breakpoints set > on enable_timeout() and disable_timeout(). I confirmed that enable_timeout() > is called just once at Parse message, and disable_timeout() is called just > once at Execute message. > > I'd like to wait for Tatsuo-san's thorough testing with pgproto. I have done tests using pgproto. One thing I noticed a strange behavior. Below is an output of pgproto. The test first set the timeout to 3 seconds, and parse/bind for "SELECT pg_sleep(2)" then set timeout to 1 second using extended query. Subsequent Execute emits a statement timeout error as expected, but next "SELECT pg_sleep(2)" call using extended query does not emit a statement error. The test for this is "007-timeout-twice". Attached is the test cases including this. FE=> Query(query="SET statement_timeout = '3s'") <= BE CommandComplete(SET) <= BE ReadyForQuery(I) FE=> Parse(stmt="S1", query="SELECT pg_sleep(2)") FE=> Bind(stmt="S1", portal="S2") FE=> Parse(stmt="", query="SET statement_timeout = '1s'") FE=> Bind(stmt="", portal="") FE=> Execute(portal="") FE=> Execute(portal="S2") FE=> Sync <= BE ParseComplete <= BE BindComplete <= BE ParseComplete <= BE BindComplete <= BE CommandComplete(SET) <= BE ErrorResponse(S ERROR V ERROR C 57014 M canceling statement due to statement timeout F postgres.c L 2968 R ProcessInterrupts ) <= BE ReadyForQuery(I) FE=> Parse(stmt="S3", query="SELECT pg_sleep(2)") FE=> Bind(stmt="S3", portal="S2") FE=> Execute(portal="S2") FE=> Sync <= BE ParseComplete <= BE BindComplete <= BE DataRow <= BE CommandComplete(SELECT 1) <= BE ReadyForQuery(I) FE=> Terminate tests.tar.gz Description: Binary data -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
From: pgsql-hackers-ow...@postgresql.org > [mailto:pgsql-hackers-ow...@postgresql.org] On Behalf Of 'Andres Freund' > Attached. I did not like that the previous patch had the timeout handling > duplicated in the individual functions, I instead centralized it into > start_xact_command(). Given that it already activated the timeout in the > most common cases, that seems to make more sense to me. In your version > we'd have called enable_statement_timeout() twice consecutively (which > behaviourally is harmless). > > What do you think? I've not really tested this with the extended protocol, > so I'd appreciate if you could rerun your test from the older thread. The patch looks good and cleaner. It looks like the code works as expected. As before, I ran one INSERT statement with PgJDBC, with gdb's breakpoints set on enable_timeout() and disable_timeout(). I confirmed that enable_timeout() is called just once at Parse message, and disable_timeout() is called just once at Execute message. I'd like to wait for Tatsuo-san's thorough testing with pgproto. Regards Takayuki Tsunakawa -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
Andres Freund writes: > On 2017-04-05 10:05:19 +0900, Tatsuo Ishii wrote: >> What's your point of the question? What kind of problem do you expect >> if the timeout starts only once at the first parse meesage out of >> bunch of parse messages? > It's perfectly valid to send a lot of Parse messages without > interspersed Sync or Bind/Execute message. There'll be one timeout > covering all of those Parse messages, which can thus lead to a timeout, > even though nothing actually takes long individually. It might well be reasonable to redefine statement_timeout as limiting the total time from the first client input to the response to Sync ... but if that's what we're doing, let's make sure we do it consistently. I haven't read the patch, but the comments in this thread make me fear that it's introducing some ad-hoc, inconsistent behavior. regards, tom lane -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
From: pgsql-hackers-ow...@postgresql.org > [mailto:pgsql-hackers-ow...@postgresql.org] On Behalf Of Tatsuo Ishii > Hmm. IMO, that could happen even with the current statement timeout > implementation as well. > > Or we could start/stop the timeout in exec_execute_message() only. This > could avoid the problem above. Also this is more consistent with > log_duration/log_min_duration_statement behavior than now. I think it's better to include Parse and Bind as now. Parse or Bind could take long time when the table has many partitions, the query is complex and/or very long, some DDL statement is running against a target table, or the system load is high. Firing statement timeout during or after many Parses is not a problem, because the first Parse started running some statement and it's not finished. Plus, Andres confirmed that major client drivers don't use such a pattern. There may be an odd behavior purely from the perspective of E.Q.P, that's a compromise, which Andres meant by "not perfect but." Regards Takayuki Tsunakawa -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
> On 2017-04-04 16:56:26 -0700, 'Andres Freund' wrote: >> On 2017-04-04 23:52:28 +, Tsunakawa, Takayuki wrote: >> > From: Andres Freund [mailto:and...@anarazel.de] >> > > Looks to me like npgsql doesn't do that either. None of libpq, pgjdbs >> > > and >> > > npgsql doing it seems like some evidence that it's ok. >> > >> > And psqlODBC now uses always libpq. >> > >> > Now time for final decision? >> >> I'll send an updated patch in a bit, and then will wait till tomorrow to >> push. Giving others a chance to chime in seems fair. > > Attached. I did not like that the previous patch had the timeout > handling duplicated in the individual functions, I instead centralized > it into start_xact_command(). Given that it already activated the > timeout in the most common cases, that seems to make more sense to > me. In your version we'd have called enable_statement_timeout() twice > consecutively (which behaviourally is harmless). > > What do you think? I've not really tested this with the extended > protocol, so I'd appreciate if you could rerun your test from the > older thread. Ok, I will look into your patch and test it out using pgproto. Best regards, -- Tatsuo Ishii SRA OSS, Inc. Japan English: http://www.sraoss.co.jp/index_en.php Japanese:http://www.sraoss.co.jp -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
On 2017-04-04 16:56:26 -0700, 'Andres Freund' wrote:
> On 2017-04-04 23:52:28 +, Tsunakawa, Takayuki wrote:
> > From: Andres Freund [mailto:and...@anarazel.de]
> > > Looks to me like npgsql doesn't do that either. None of libpq, pgjdbs and
> > > npgsql doing it seems like some evidence that it's ok.
> >
> > And psqlODBC now uses always libpq.
> >
> > Now time for final decision?
>
> I'll send an updated patch in a bit, and then will wait till tomorrow to
> push. Giving others a chance to chime in seems fair.
Attached. I did not like that the previous patch had the timeout
handling duplicated in the individual functions, I instead centralized
it into start_xact_command(). Given that it already activated the
timeout in the most common cases, that seems to make more sense to
me. In your version we'd have called enable_statement_timeout() twice
consecutively (which behaviourally is harmless).
What do you think? I've not really tested this with the extended
protocol, so I'd appreciate if you could rerun your test from the
older thread.
- Andres
>From c47d904725f3ef0272a4540b6b5bcf0be5c1dea6 Mon Sep 17 00:00:00 2001
From: Andres Freund
Date: Tue, 4 Apr 2017 18:44:42 -0700
Subject: [PATCH] Rearm statement_timeout after each executed query.
Previously statement_timeout, in the extended protocol, affected all
messages till a Sync message. For clients that pipeline/batch
query execution that's problematic.
Instead disable timeout after each Execute message, and enable, if
necessary, the timer in start_xact_command().
Author: Tatsuo Ishii, editorialized by Andres Freund
Reviewed-By: Takayuki Tsunakawa, Andres Freund
Discussion: https://postgr.es/m/20170222.115044.1665674502985097185.t-is...@sraoss.co.jp
---
src/backend/tcop/postgres.c | 77 ++---
1 file changed, 65 insertions(+), 12 deletions(-)
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index a2282058c0..4ab3bd7f07 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 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.
@@ -188,6 +193,8 @@ static bool IsTransactionStmtList(List *pstmts);
static void drop_unnamed_stmt(void);
static void SigHupHandler(SIGNAL_ARGS);
static void log_disconnections(int code, Datum arg);
+static void enable_statement_timeout(void);
+static void disable_statement_timeout(void);
/*
@@ -1234,7 +1241,8 @@ exec_parse_message(const char *query_string, /* string to execute */
/*
* Start up a transaction command so we can run parse analysis etc. (Note
* that this will normally change current memory context.) Nothing happens
- * if we are already in one.
+ * if we are already in one. This also arms the statement timeout if
+ * necessary.
*/
start_xact_command();
@@ -1522,7 +1530,8 @@ exec_bind_message(StringInfo input_message)
/*
* Start up a transaction command so we can call functions etc. (Note that
* this will normally change current memory context.) Nothing happens if
- * we are already in one.
+ * we are already in one. This also arms the statement timeout if
+ * necessary.
*/
start_xact_command();
@@ -2014,6 +2023,9 @@ exec_execute_message(const char *portal_name, long max_rows)
* those that start or end a transaction block.
*/
CommandCounterIncrement();
+
+ /* full command has been executed, reset timeout */
+ disable_statement_timeout();
}
/* Send appropriate CommandComplete to client */
@@ -2443,25 +2455,27 @@ 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;
}
+
+ /*
+ * 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();
}
static void
finish_xact_command(void)
{
+ /* cancel active statement timeout after each command */
+ disable_statement_timeout();
+
if (xact_started)
{
- /* Cancel any active statement timeout before committing */
- disable_timeout(STATEMENT_TIMEOUT, false);
-
Co
Re: [HACKERS] Statement timeout behavior in extended queries
>> What's your point of the question? What kind of problem do you expect >> if the timeout starts only once at the first parse meesage out of >> bunch of parse messages? > > It's perfectly valid to send a lot of Parse messages without > interspersed Sync or Bind/Execute message. There'll be one timeout > covering all of those Parse messages, which can thus lead to a timeout, > even though nothing actually takes long individually. Hmm. IMO, that could happen even with the current statement timeout implementation as well. Or we could start/stop the timeout in exec_execute_message() only. This could avoid the problem above. Also this is more consistent with log_duration/log_min_duration_statement behavior than now. Best regards, -- Tatsuo Ishii SRA OSS, Inc. Japan English: http://www.sraoss.co.jp/index_en.php Japanese:http://www.sraoss.co.jp -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
On 2017-04-05 10:05:19 +0900, Tatsuo Ishii wrote: > > Hm. I started to edit it, but I'm halfway coming back to my previous > > view that this isn't necessarily ready. > > > > If a client were to to prepare a large number of prepared statements > > (i.e. a lot of parse messages), this'll only start the timeout once, at > > the first statement sent. It's not an issue for libpq which sends a > > sync message after each PQprepare, nor does it look to be an issue for > > pgjdbc based on a quick look. > > > > Does anybody think there might be a driver out there that sends a bunch > > of 'parse' messages, without syncs? > > What's your point of the question? What kind of problem do you expect > if the timeout starts only once at the first parse meesage out of > bunch of parse messages? It's perfectly valid to send a lot of Parse messages without interspersed Sync or Bind/Execute message. There'll be one timeout covering all of those Parse messages, which can thus lead to a timeout, even though nothing actually takes long individually. Greetings, Andres Freund -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
> Hm. I started to edit it, but I'm halfway coming back to my previous > view that this isn't necessarily ready. > > If a client were to to prepare a large number of prepared statements > (i.e. a lot of parse messages), this'll only start the timeout once, at > the first statement sent. It's not an issue for libpq which sends a > sync message after each PQprepare, nor does it look to be an issue for > pgjdbc based on a quick look. > > Does anybody think there might be a driver out there that sends a bunch > of 'parse' messages, without syncs? What's your point of the question? What kind of problem do you expect if the timeout starts only once at the first parse meesage out of bunch of parse messages? Best regards, -- Tatsuo Ishii SRA OSS, Inc. Japan English: http://www.sraoss.co.jp/index_en.php Japanese:http://www.sraoss.co.jp -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
On 2017-04-04 23:52:28 +, Tsunakawa, Takayuki wrote: > From: Andres Freund [mailto:and...@anarazel.de] > > Looks to me like npgsql doesn't do that either. None of libpq, pgjdbs and > > npgsql doing it seems like some evidence that it's ok. > > And psqlODBC now uses always libpq. > > Now time for final decision? I'll send an updated patch in a bit, and then will wait till tomorrow to push. Giving others a chance to chime in seems fair. - Andres -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
From: Andres Freund [mailto:and...@anarazel.de] > Looks to me like npgsql doesn't do that either. None of libpq, pgjdbs and > npgsql doing it seems like some evidence that it's ok. And psqlODBC now uses always libpq. Now time for final decision? Regards Takayuki Tsunakawa -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
On 2017-04-04 16:38:53 -0700, Andres Freund wrote: > On 2017-04-04 16:10:32 +0900, Tatsuo Ishii wrote: > > >> If what Tatsuo-san said to Tom is correct (i.e. each Parse/Bind/Execute > > >> starts and stops the timer), then it's a concern and the patch should > > >> not be ready for committer. However, the current patch is not like that > > >> -- it seems to do what others in this thread are expecting. > > > > > > Oh, interesting - I kind of took the author's statement as, uh, > > > authoritative ;). A quick look over the patch confirms your > > > understanding. > > > > Yes, Tsunakawa-san is correct. Sorry for confusion. > > > > > I think the code needs a few clarifying comments around this, but > > > otherwise seems good. Not restarting the timeout in those cases > > > obviously isn't entirely "perfect"/"correct", but a tradeoff - the > > > comments should note that. > > > > > > Tatsuo-san, do you want to change those, and push? I can otherwise. > > > > Andres, > > > > If you don't mind, could you please fix the comments and push it. > > Hm. I started to edit it, but I'm halfway coming back to my previous > view that this isn't necessarily ready. > > If a client were to to prepare a large number of prepared statements > (i.e. a lot of parse messages), this'll only start the timeout once, at > the first statement sent. It's not an issue for libpq which sends a > sync message after each PQprepare, nor does it look to be an issue for > pgjdbc based on a quick look. > > Does anybody think there might be a driver out there that sends a bunch > of 'parse' messages, without syncs? Looks to me like npgsql doesn't do that either. None of libpq, pgjdbs and npgsql doing it seems like some evidence that it's ok. - Andres -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
On 2017-04-05 08:34:43 +0900, Tatsuo Ishii wrote: > Andres, > > >> I think the code needs a few clarifying comments around this, but > >> otherwise seems good. Not restarting the timeout in those cases > >> obviously isn't entirely "perfect"/"correct", but a tradeoff - the > >> comments should note that. > >> > >> Tatsuo-san, do you want to change those, and push? I can otherwise. > > > > Andres, > > > > If you don't mind, could you please fix the comments and push it. > > I have changed the comments as you suggested. If it's ok, I can push > the patch myself (today I have time to work on this). I'm working on the patch, and I've edited it more heavily, so please hold off. Changes: I don't think the debugging statements are a good idea, the !xact_started should be an assert, and disable_timeout should be called from within enable_statement_timeout independent of stmt_timer_started. But more importantly I had just sent a question that I think merits discussion. - Andres -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
On 2017-04-04 16:10:32 +0900, Tatsuo Ishii wrote: > >> If what Tatsuo-san said to Tom is correct (i.e. each Parse/Bind/Execute > >> starts and stops the timer), then it's a concern and the patch should not > >> be ready for committer. However, the current patch is not like that -- it > >> seems to do what others in this thread are expecting. > > > > Oh, interesting - I kind of took the author's statement as, uh, > > authoritative ;). A quick look over the patch confirms your > > understanding. > > Yes, Tsunakawa-san is correct. Sorry for confusion. > > > I think the code needs a few clarifying comments around this, but > > otherwise seems good. Not restarting the timeout in those cases > > obviously isn't entirely "perfect"/"correct", but a tradeoff - the > > comments should note that. > > > > Tatsuo-san, do you want to change those, and push? I can otherwise. > > Andres, > > If you don't mind, could you please fix the comments and push it. Hm. I started to edit it, but I'm halfway coming back to my previous view that this isn't necessarily ready. If a client were to to prepare a large number of prepared statements (i.e. a lot of parse messages), this'll only start the timeout once, at the first statement sent. It's not an issue for libpq which sends a sync message after each PQprepare, nor does it look to be an issue for pgjdbc based on a quick look. Does anybody think there might be a driver out there that sends a bunch of 'parse' messages, without syncs? - Andres -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
Andres,
>> I think the code needs a few clarifying comments around this, but
>> otherwise seems good. Not restarting the timeout in those cases
>> obviously isn't entirely "perfect"/"correct", but a tradeoff - the
>> comments should note that.
>>
>> Tatsuo-san, do you want to change those, and push? I can otherwise.
>
> Andres,
>
> If you don't mind, could you please fix the comments and push it.
I have changed the comments as you suggested. If it's ok, I can push
the patch myself (today I have time to work on this).
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 a2282058..1fd93359 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);
static void log_disconnections(int code, Datum arg);
+static void enable_statement_timeout(void);
+static void disable_statement_timeout(void);
/*
@@ -1239,6 +1246,15 @@ exec_parse_message(const char *query_string, /* string to execute */
start_xact_command();
/*
+ * Set statement timeout running if it's not already set. The timer will
+ * be reset in a subsequent execute message. Ideally the timer should be
+ * reset in this function so that each parse/bind/execute message catches
+ * the timeout, but it needs gettimeofday() call for each, which is too
+ * expensive.
+ */
+ enable_statement_timeout();
+
+ /*
* Switch to appropriate context for constructing parsetrees.
*
* We have two strategies depending on whether the prepared statement is
@@ -1526,6 +1542,15 @@ exec_bind_message(StringInfo input_message)
*/
start_xact_command();
+ /*
+ * Set statement timeout running if it's not already set. The timer will
+ * be reset in a subsequent execute message. Ideally the timer should be
+ * reset in this function so that each parse/bind/execute message catches
+ * the timeout, but it needs gettimeofday() call for each, which is too
+ * expensive.
+ */
+ enable_statement_timeout();
+
/* Switch back to message context */
MemoryContextSwitchTo(MessageContext);
@@ -1942,6 +1967,11 @@ exec_execute_message(const char *portal_name, long max_rows)
start_xact_command();
/*
+ * Set statement timeout running if it's not already set.
+ */
+ enable_statement_timeout();
+
+ /*
* If we re-issue an Execute protocol request against an existing portal,
* then we are only fetching more rows rather than completely re-executing
* the query from the start. atStart is never reset for a v3 portal, so we
@@ -2014,6 +2044,11 @@ exec_execute_message(const char *portal_name, long max_rows)
* those that start or end a transaction block.
*/
CommandCounterIncrement();
+
+ /*
+ * We need to reset statement timeout if already set.
+ */
+ disable_statement_timeout();
}
/* Send appropriate CommandComplete to client */
@@ -2443,14 +2478,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 +2491,7 @@ finish_xact_command(void)
if (xact_started)
{
/* Cancel any active statement timeout before committing */
- disable_timeout(STATEMENT_TIMEOUT, false);
+ disable_statement_timeout();
CommitTransactionCommand();
@@ -4511,3 +4542,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, St
Re: [HACKERS] Statement timeout behavior in extended queries
>> If what Tatsuo-san said to Tom is correct (i.e. each Parse/Bind/Execute >> starts and stops the timer), then it's a concern and the patch should not be >> ready for committer. However, the current patch is not like that -- it >> seems to do what others in this thread are expecting. > > Oh, interesting - I kind of took the author's statement as, uh, > authoritative ;). A quick look over the patch confirms your > understanding. Yes, Tsunakawa-san is correct. Sorry for confusion. > I think the code needs a few clarifying comments around this, but > otherwise seems good. Not restarting the timeout in those cases > obviously isn't entirely "perfect"/"correct", but a tradeoff - the > comments should note that. > > Tatsuo-san, do you want to change those, and push? I can otherwise. Andres, If you don't mind, could you please fix the comments and push it. > Unfortunately I can't move the patch back to the current CF, but I guess > we can just mark it as committed in the next. That will be great. Best regards, -- Tatsuo Ishii SRA OSS, Inc. Japan English: http://www.sraoss.co.jp/index_en.php Japanese:http://www.sraoss.co.jp -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
On 2017-04-04 06:35:00 +, Tsunakawa, Takayuki wrote: > From: Andres Freund [mailto:and...@anarazel.de] > Given the concern raised in > > http://archives.postgresql.org/message-id/12207.1491228316%40sss.pgh.p > > a.us > > I don't see this being ready for committer. > > If what Tatsuo-san said to Tom is correct (i.e. each Parse/Bind/Execute > starts and stops the timer), then it's a concern and the patch should not be > ready for committer. However, the current patch is not like that -- it seems > to do what others in this thread are expecting. Oh, interesting - I kind of took the author's statement as, uh, authoritative ;). A quick look over the patch confirms your understanding. I think the code needs a few clarifying comments around this, but otherwise seems good. Not restarting the timeout in those cases obviously isn't entirely "perfect"/"correct", but a tradeoff - the comments should note that. Tatsuo-san, do you want to change those, and push? I can otherwise. Unfortunately I can't move the patch back to the current CF, but I guess we can just mark it as committed in the next. - Andres -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
From: Andres Freund [mailto:and...@anarazel.de] Given the concern raised in > http://archives.postgresql.org/message-id/12207.1491228316%40sss.pgh.p > a.us > I don't see this being ready for committer. If what Tatsuo-san said to Tom is correct (i.e. each Parse/Bind/Execute starts and stops the timer), then it's a concern and the patch should not be ready for committer. However, the current patch is not like that -- it seems to do what others in this thread are expecting. Regards Takayuki Tsunakawa -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
On 2017-04-04 06:18:04 +, Tsunakawa, Takayuki wrote: > From: Tatsuo Ishii [mailto:is...@sraoss.co.jp] > > It's too late. Someone has already moved the patch to the next CF (for > > PostgreSQL 11). > > Yes, but this patch will be necessary by the final release of PG 10 if the > libpq batch/pipelining is committed in PG 10. > > I marked this as ready for committer in the next CF, so that some committer > can pick up this patch and consider putting it in PG 10. If you decide to > modify the patch, please change the status. Given the concern raised in http://archives.postgresql.org/message-id/12207.1491228316%40sss.pgh.pa.us I don't see this being ready for committer. - Andres -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
From: Tatsuo Ishii [mailto:is...@sraoss.co.jp] > It's too late. Someone has already moved the patch to the next CF (for > PostgreSQL 11). Yes, but this patch will be necessary by the final release of PG 10 if the libpq batch/pipelining is committed in PG 10. I marked this as ready for committer in the next CF, so that some committer can pick up this patch and consider putting it in PG 10. If you decide to modify the patch, please change the status. Regards Takayuki Tsunakawa -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
> The patch doesn't seem to behave like that. The Parse message calls > start_xact_command() -> enable_statement_timeout() -> enable_timeout(), and > set stmt_timer_started to true. Subsequent Bind and Execute messages call > enable_statement_timeout(), but enable_statement_timeout() doesn't call > enable_timeout() because stmt_timer_started is already true. > > >> > It looks like the patch does the following. I think this is desirable, >> because starting and stopping the timer for each message may be costly as >> Tom said. >> > Parse(statement1) >> > start timer >> > Bind(statement1, portal1) >> > Execute(portal1) >> > stop timer >> > Sync > > I ran one INSERT statement using JDBC with log_min_messages = DEBUG3, and the > server log shows what I said. > > DEBUG: parse : insert into a values(2) > DEBUG: Set statement timeout > LOG: duration: 0.431 ms parse : insert into a values(2) > DEBUG: bind to > LOG: duration: 0.127 ms bind : insert into a values(2) > DEBUG: Disable statement timeout > LOG: duration: 0.184 ms execute : insert into a values(2) > DEBUG: snapshot of 1+0 running transaction ids (lsn 0/163BF28 oldest xid 561 > latest complete 560 next xid 562) Check. >> This doesn't work in general use cases. Following pattern appears frequently >> in applications. >> >> Parse(statement1) >> Bind(statement1, portal1) >> Execute(portal1) >> Bind(statement1, portal1) >> Execute(portal1) >> : >> : >> Sync > > It works. The first Parse-Bind-Execute is measured as one unit, then > subsequent Bind-Execute pairs are measured as other units. That's because > each Execute ends the statement_timeout timer and the Bind message starts it > again. I think this is desirable, so the current patch looks good. May I > mark this as ready for committer? FYI, make check-world passed successfully. It's too late. Someone has already moved the patch to the next CF (for PostgreSQL 11). >> Also what would happen if client just send a parse message and does nothing >> after that? > > It's correct to trigger the statement timeout in this case, because the first > SQL statement started (with the Parse message) and its execution is not > finished (with Execute message.) > > > Regards > Takayuki Tsunakawa > > > -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
From: pgsql-hackers-ow...@postgresql.org > [mailto:pgsql-hackers-ow...@postgresql.org] On Behalf Of Tatsuo Ishii > Actually the statement timer is replaced with new statement timer value > in enable_statement_timeout(). The patch doesn't seem to behave like that. The Parse message calls start_xact_command() -> enable_statement_timeout() -> enable_timeout(), and set stmt_timer_started to true. Subsequent Bind and Execute messages call enable_statement_timeout(), but enable_statement_timeout() doesn't call enable_timeout() because stmt_timer_started is already true. > > It looks like the patch does the following. I think this is desirable, > because starting and stopping the timer for each message may be costly as > Tom said. > > Parse(statement1) > > start timer > > Bind(statement1, portal1) > > Execute(portal1) > > stop timer > > Sync I ran one INSERT statement using JDBC with log_min_messages = DEBUG3, and the server log shows what I said. DEBUG: parse : insert into a values(2) DEBUG: Set statement timeout LOG: duration: 0.431 ms parse : insert into a values(2) DEBUG: bind to LOG: duration: 0.127 ms bind : insert into a values(2) DEBUG: Disable statement timeout LOG: duration: 0.184 ms execute : insert into a values(2) DEBUG: snapshot of 1+0 running transaction ids (lsn 0/163BF28 oldest xid 561 latest complete 560 next xid 562) > This doesn't work in general use cases. Following pattern appears frequently > in applications. > > Parse(statement1) > Bind(statement1, portal1) > Execute(portal1) > Bind(statement1, portal1) > Execute(portal1) > : > : > Sync It works. The first Parse-Bind-Execute is measured as one unit, then subsequent Bind-Execute pairs are measured as other units. That's because each Execute ends the statement_timeout timer and the Bind message starts it again. I think this is desirable, so the current patch looks good. May I mark this as ready for committer? FYI, make check-world passed successfully. > Also what would happen if client just send a parse message and does nothing > after that? It's correct to trigger the statement timeout in this case, because the first SQL statement started (with the Parse message) and its execution is not finished (with Execute message.) Regards Takayuki Tsunakawa -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
> Where is the statement_timeout timer stopped when processing Parse and Bind > messages? Actually the statement timer is replaced with new statement timer value in enable_statement_timeout(). > Do you mean the following sequence of operations are performed in this patch? > > Parse(statement1) > start timer > stop timer > Bind(statement1, portal1) > start timer > stop timer > Execute(portal1) > start timer > stop timer > Sync Yes. > It looks like the patch does the following. I think this is desirable, > because starting and stopping the timer for each message may be costly as Tom > said. > Parse(statement1) > start timer > Bind(statement1, portal1) > Execute(portal1) > stop timer > Sync This doesn't work in general use cases. Following pattern appears frequently in applications. Parse(statement1) Bind(statement1, portal1) Execute(portal1) Bind(statement1, portal1) Execute(portal1) : : Sync Also what would happen if client just send a parse message and does nothing after that? So I think following is better: Parse(statement1) Bind(statement1, portal1) Execute(portal1) start timer stop timer Bind(statement1, portal1) Execute(portal1) start timer stop timer : : Sync Best regards, -- Tatsuo Ishii SRA OSS, Inc. Japan English: http://www.sraoss.co.jp/index_en.php Japanese:http://www.sraoss.co.jp -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
From: pgsql-hackers-ow...@postgresql.org
> [mailto:pgsql-hackers-ow...@postgresql.org] On Behalf Of Tatsuo Ishii
> 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.
Where is the statement_timeout timer stopped when processing Parse and Bind
messages? Do you mean the following sequence of operations are performed in
this patch?
Parse(statement1)
start timer
stop timer
Bind(statement1, portal1)
start timer
stop timer
Execute(portal1)
start timer
stop timer
Sync
It looks like the patch does the following. I think this is desirable, because
starting and stopping the timer for each message may be costly as Tom said.
Parse(statement1)
start timer
Bind(statement1, portal1)
Execute(portal1)
stop timer
Sync
> > (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, so I 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.
OK, I favor documenting to reduce code, but I don't have a strong opinion. I'd
like to leave this to the committer. One thing to note is that you can remove
{ and } in the following code like other places.
+ if (!xact_started)
+ {
+ ereport(ERROR,
+
(errcode(ERRCODE_INVALID_PARAMETER_VALUE),
+errmsg("Transaction must have
been already started to set statement timeout")));
+ }
Regards
Takayuki Tsunakawa
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
On 2017-04-03 23:31:59 +0900, Tatsuo Ishii wrote: > > That seems like it could represent quite a lot of added overhead, > > on machines where gettimeofday() is slow ... which is still a lot > > of them, unfortunately. > > Maybe. I think we could eliminate restarting the timer for parse and > bind. I've moved this patch to the next CF - it's been submitted fairly late in the v10 cycle and there's obviously design work ongoing. - Andres -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
> That seems like it could represent quite a lot of added overhead, > on machines where gettimeofday() is slow ... which is still a lot > of them, unfortunately. Maybe. I think we could eliminate restarting the timer for parse and bind. Best regards, -- Tatsuo Ishii SRA OSS, Inc. Japan English: http://www.sraoss.co.jp/index_en.php Japanese:http://www.sraoss.co.jp -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
Tatsuo Ishii writes: >> * 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. That seems like it could represent quite a lot of added overhead, on machines where gettimeofday() is slow ... which is still a lot of them, unfortunately. regards, tom lane -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
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 being developed for PG
> 10. This patch enables correct timeout handling for each statement execution
> in a batch. Without this patch, the entire batch of statements is subject to
> statement_timeout. That's different from what the manual describes 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 use stmt 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, so I 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);
static void 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 on whether 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();
+
+ /*
*
Re: [HACKERS] Statement timeout behavior in extended queries
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,
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 patch is also necessary (or desirable) for the feature "Pipelining/batch
mode support for libpq," which is being developed for PG 10. This patch
enables correct timeout handling for each statement execution in a batch.
Without this patch, the entire batch of statements is subject to
statement_timeout. That's different from what the manual describes about
statement_timeout. statement_timeout should measure execution of each
statement.
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 use stmt to abbreviate
statement, and thhis variable represents a state (see xact_started for example.)
(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.
(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, so I don't see the chance of misuse.
Regards
Takayuki Tsunakawa
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
> On Wed, Feb 22, 2017 at 11:50:44AM +0900, Tatsuo Ishii wrote: >> Last year I have proposed an enhancement regarding behavior of the >> statement timeout in extended queries. >> >> https://www.postgresql.org/message-id/20160528.220442.1489791680347556026.t-ishii%40sraoss.co.jp >> >> IMO the current behavior is counter intuitive and I would like to >> change it toward PostgreSQL 10.0. >> >> For example, suppose that the timeout is set to 4 seconds and the >> first query takes 2 seconds and the second query takes 3 seconds. Then >> the statement timeout is triggered if a sync message is sent to >> backend after the second query. >> >> Moreover, log_duration or log_min_duration_statement shows that each >> query took 2 or 3 seconds of course, which is not very consistent with >> the statement timeout IMO. >> >> Attached patch tries to change the behavior, by checking statement >> timeout against each phase of an extended query. >> >> To test the patch, I have created a small tool called "pgproto", which >> can issue arbitrary sequence of frontend/backend message, reading from a >> text file. >> >> https://github.com/tatsuo-ishii/pgproto >> (to build the program, you need C compiler and libpq) > > Does it seem reasonable to start making this into a regression test > and/or fuzz test for the protocol itself? I personally think the regression tests ought to include tests for extended query protocols and pgproto could be an useful tool to implement that. Of course if we are going for that direction, pgproto needs to be a contrib module first. Best regards, -- Tatsuo Ishii SRA OSS, Inc. Japan English: http://www.sraoss.co.jp/index_en.php Japanese:http://www.sraoss.co.jp -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Statement timeout behavior in extended queries
On Wed, Feb 22, 2017 at 11:50:44AM +0900, Tatsuo Ishii wrote: > Last year I have proposed an enhancement regarding behavior of the > statement timeout in extended queries. > > https://www.postgresql.org/message-id/20160528.220442.1489791680347556026.t-ishii%40sraoss.co.jp > > IMO the current behavior is counter intuitive and I would like to > change it toward PostgreSQL 10.0. > > For example, suppose that the timeout is set to 4 seconds and the > first query takes 2 seconds and the second query takes 3 seconds. Then > the statement timeout is triggered if a sync message is sent to > backend after the second query. > > Moreover, log_duration or log_min_duration_statement shows that each > query took 2 or 3 seconds of course, which is not very consistent with > the statement timeout IMO. > > Attached patch tries to change the behavior, by checking statement > timeout against each phase of an extended query. > > To test the patch, I have created a small tool called "pgproto", which > can issue arbitrary sequence of frontend/backend message, reading from a > text file. > > https://github.com/tatsuo-ishii/pgproto > (to build the program, you need C compiler and libpq) Does it seem reasonable to start making this into a regression test and/or fuzz test for the protocol itself? Best, David. -- David Fetter http://fetter.org/ Phone: +1 415 235 3778 AIM: dfetter666 Yahoo!: dfetter Skype: davidfetter XMPP: david(dot)fetter(at)gmail(dot)com Remember to vote! Consider donating to Postgres: http://www.postgresql.org/about/donate -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
[HACKERS] Statement timeout behavior in extended queries
Last year I have proposed an enhancement regarding behavior of the
statement timeout in extended queries.
https://www.postgresql.org/message-id/20160528.220442.1489791680347556026.t-ishii%40sraoss.co.jp
IMO the current behavior is counter intuitive and I would like to
change it toward PostgreSQL 10.0.
For example, suppose that the timeout is set to 4 seconds and the
first query takes 2 seconds and the second query takes 3 seconds. Then
the statement timeout is triggered if a sync message is sent to
backend after the second query.
Moreover, log_duration or log_min_duration_statement shows that each
query took 2 or 3 seconds of course, which is not very consistent with
the statement timeout IMO.
Attached patch tries to change the behavior, by checking statement
timeout against each phase of an extended query.
To test the patch, I have created a small tool called "pgproto", which
can issue arbitrary sequence of frontend/backend message, reading from a
text file.
https://github.com/tatsuo-ishii/pgproto
(to build the program, you need C compiler and libpq)
A test data is here:
--
#
# Test case for statement timeout patch.
#
'Q' "SET statement_timeout = '4s'"
# Receive response from backend
'Y'
# Execute statement which takes 3 seconds.
'P' "S1""SELECT pg_sleep(3)"0
'B' "" "S1"0 0 0
'E' "" 0
'C' 'S' "S1"
# Execute statement which takes 2 seconds.
'P' "S2""SELECT pg_sleep(2)"0
'B' "" "S2"0 0 0
'E' "" 0
'C' 'S' "S2"
# Issue Sync message
'S'
# Receive response from backend
'Y'
# Send terminate message
'X'
--
In each row, the first column corresponds to the message type defined
in frontend/backend protocol (except 'Y', which asks pgproto to
collect responses from backend). Each column is separated with a tab
character.
To run the test:
pgproto -f data_file -p port_number -d database_name
With the attached patch, "SELECT pg_sleep(3)" and "SELECT pg_sleep(2)"
does not trigger the statement timeout as expected, while existing
code triggers the statement timeout after the sync message is sent.
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 b07d6c6..e35a1dd 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 *pstmts);
static void drop_unnamed_stmt(void);
static void SigHupHandler(SIGNAL_ARGS);
static void log_disconnections(int code, Datum arg);
+static void enable_statement_timeout(void);
+static void disable_statement_timeout(void);
/*
@@ -1234,6 +1241,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 on whether the prepared statement is
@@ -1521,6 +1533,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);
@@ -1937,6 +1954,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 more rows rather than completely re-executing
* the query from the start. atStart is never reset for a v3 portal, so we
@@ -2008,6 +2030,11 @@ exec_execute_message(const char *portal_name, long max_rows)
* those that start or end a transaction block.
*/
CommandCounterIncrement();
+
+ /*
+ * We need to reset statement timeout if already set.
+ */
+ disable_statement_timeout();
}
/* Send appropriate CommandComplete to client */
@@ -2437,14 +2464,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(STATEMEN
