Thread: Re: 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
withPgJDBC, with gdb's breakpoints set on enable_timeout() and disable_timeout().  I confirmed that enable_timeout() is
calledjust 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

From: pgsql-hackers-owner@postgresql.org
> [mailto:pgsql-hackers-owner@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

> From: pgsql-hackers-owner@postgresql.org
>> [mailto:pgsql-hackers-owner@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
effectof "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

From: pgsql-hackers-owner@postgresql.org
> [mailto:pgsql-hackers-owner@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

> 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