pg.ddx.io pgsql-bugs@postgresql.org mailing list archive
help / color / mirror / Atom feedBUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending
6+ messages / 3 participants
[nested] [flat]
* BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending
@ 2017-09-21 01:09 lukas@fittl.com
2017-09-21 01:29 ` Re: BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending Andres Freund <andres@anarazel.de>
0 siblings, 1 reply; 6+ messages in thread
From: lukas@fittl.com @ 2017-09-21 01:09 UTC (permalink / raw)
To: pgsql-bugs; +Cc: lukas@fittl.com
The following bug has been logged on the website:
Bug reference: 14821
Logged by: Lukas Fittl
Email address: lukas@fittl.com
PostgreSQL version: 9.6.4
Operating system: Amazon Linux RHEL 6
Description:
Hi all,
I've been observing a problem on 9.6.4, but in my understanding this still
applies on master too.
Relevant config:
idle_in_transaction_session_timeout = 30s
statement_timeout = 30s
Backend thats idle in transaction and should have been cancelled:
=> SELECT pid, state, now() - backend_start AS backend_age, now() -
xact_start AS xact_age, now() - state_change AS state_age, query FROM
pg_stat_activity WHERE state = 'idle in transaction' ORDER BY
backend_start;
pid | state | backend_age | xact_age |
state_age | query
------+---------------------+-----------------+-----------------+-----------------+------------------
4005 | idle in transaction | 04:29:51.844063 | 01:19:10.984972 |
01:19:10.984947 | BEGIN READ WRITE
(1 row)
Backtrace from that backend:
(gdb) bt
#0 0x00007f9dffb298c3 in __epoll_wait_nocancel () at
../sysdeps/unix/syscall-template.S:81
#1 0x00000000006a06d6 in WaitEventSetWaitBlock (nevents=1,
occurred_events=0x7fff0e0f3cf0, cur_timeout=-1, set=0x29ea1a8) at
latch.c:1053
#2 WaitEventSetWait (set=0x29ea1a8, timeout=timeout@entry=-1,
occurred_events=occurred_events@entry=0x7fff0e0f3cf0,
nevents=nevents@entry=1) at latch.c:1007
#3 0x00000000005e4985 in secure_read (port=0x2a42f30, ptr=0xc09260
<PqRecvBuffer>, len=8192) at be-secure.c:149
#4 0x00000000005ed898 in pq_recvbuf () at pqcomm.c:940
#5 0x00000000005ee3a5 in pq_getbyte () at pqcomm.c:983
#6 0x00000000006bf012 in SocketBackend (inBuf=0x7fff0e0f3e80) at
postgres.c:326
#7 ReadCommand (inBuf=0x7fff0e0f3e80) at postgres.c:499
#8 PostgresMain (argc=<optimized out>, argv=argv@entry=0x2a4c4f8,
dbname=0x2a4c468 "mydb", username=<optimized out>) at postgres.c:4019
#9 0x000000000046ed2b in BackendRun (port=0x2a42f30) at postmaster.c:4294
#10 BackendStartup (port=0x2a42f30) at postmaster.c:3968
#11 ServerLoop () at postmaster.c:1719
#12 0x0000000000666946 in PostmasterMain (argc=argc@entry=3,
argv=argv@entry=0x29e86b0) at postmaster.c:1327
#13 0x000000000046f8a2 in main (argc=3, argv=0x29e86b0) at main.c:228
So as you can see its waiting on line 326 of tcop/postgres.c for data from
pq_getbyte(). And the reason that ProcessInterrupts() can't move forward is
due to the HOLD_CANCEL_INTERRUPTS() just before that in combination with a
pending query cancellation.
Relevant variables:
(gdb) p InterruptHoldoffCount
$13 = 0
(gdb) p CritSectionCount
$14 = 0
(gdb) p QueryCancelHoldoffCount
$16 = 1
(gdb) p QueryCancelPending
$17 = 1 '\001'
(gdb) p IdleInTransactionSessionTimeout
$1 = 30000
(gdb) p IdleInTransactionSessionTimeoutPending
$2 = 1 '\001'
(gdb) p all_timeouts[IDLE_IN_TRANSACTION_SESSION_TIMEOUT]
$3 = {index = IDLE_IN_TRANSACTION_SESSION_TIMEOUT, indicator = 1 '\001',
timeout_handler = 0x7baee0 <IdleInTransactionSessionTimeoutHandler>,
start_time = 559266384031137, fin_time = 559266414031137}
It seems to me that ProcessInterrupts() should check for the idle in
transaction timeout first, since it short-circuits and returns early if
QueryCancelPending && QueryCancelHoldoffCount != 0 before even getting
there.
Best,
Lukas
--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending
2017-09-21 01:09 BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending lukas@fittl.com
@ 2017-09-21 01:29 ` Andres Freund <andres@anarazel.de>
2017-09-21 01:39 ` Re: BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending Lukas Fittl <lukas@fittl.com>
0 siblings, 1 reply; 6+ messages in thread
From: Andres Freund @ 2017-09-21 01:29 UTC (permalink / raw)
To: lukas@fittl.com; +Cc: pgsql-bugs
Hi,
On 2017-09-21 01:09:56 +0000, lukas@fittl.com wrote:
> It seems to me that ProcessInterrupts() should check for the idle in
> transaction timeout first, since it short-circuits and returns early if
> QueryCancelPending && QueryCancelHoldoffCount != 0 before even getting
> there.
Indeed - although I wonder if the correct fix isn't to move things
around, but to instead avoid the order dependency changing the short
circuit logic so that there's no early return. Like e.g.
if (QueryCancelPending && QueryCancelHoldoffCount != 0)
{
/* rearm */
}
else if (QueryCancelPending)
{
/* handle interrupt */
}
there's really no good reason for the return right now, and it's bound
to create more bugs in the future.
Greetings,
Andres Freund
--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending
2017-09-21 01:09 BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending lukas@fittl.com
2017-09-21 01:29 ` Re: BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending Andres Freund <andres@anarazel.de>
@ 2017-09-21 01:39 ` Lukas Fittl <lukas@fittl.com>
0 siblings, 0 replies; 6+ messages in thread
From: Lukas Fittl @ 2017-09-21 01:39 UTC (permalink / raw)
To: Andres Freund <andres@anarazel.de>; pgsql-bugs
Hi,
On Wed, Sep 20, 2017 at 6:29 PM, Andres Freund <andres@anarazel.de> wrote:
> Hi,
>
> On 2017-09-21 01:09:56 +0000, lukas@fittl.com wrote:
> > It seems to me that ProcessInterrupts() should check for the idle in
> > transaction timeout first, since it short-circuits and returns early if
> > QueryCancelPending && QueryCancelHoldoffCount != 0 before even getting
> > there.
>
> Indeed - although I wonder if the correct fix isn't to move things
> around, but to instead avoid the order dependency changing the short
> circuit logic so that there's no early return. Like e.g.
>
> if (QueryCancelPending && QueryCancelHoldoffCount != 0)
> {
> /* rearm */
> }
> else if (QueryCancelPending)
> {
> /* handle interrupt */
> }
>
> there's really no good reason for the return right now, and it's bound
> to create more bugs in the future.
That seems like a reasonable approach and a good idea.
I'll take a stab at making a patch for this tonight and send it over to
hackers then.
Best,
Lukas
--
Lukas Fittl
Skype: lfittl
Phone: +1 415 321 0630
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: [BUGS] BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending
@ 2017-09-21 03:27 Lukas Fittl <lukas@fittl.com>
2017-10-11 21:11 ` Re: [HACKERS] Re: BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending Andres Freund <andres@anarazel.de>
0 siblings, 1 reply; 6+ messages in thread
From: Lukas Fittl @ 2017-09-21 03:27 UTC (permalink / raw)
To: pgsql-hackers@postgresql.org <pgsql-hackers@postgresql.org>; +Cc: Andres Freund <andres@anarazel.de>; pgsql-bugs
Hi,
As per the bug report at
https://www.postgresql.org/message-id/20170921010956.17345.61461%40wrigleys.postgresql.org
it seems that the query cancellation holdoff logic in ProcessInterrupts is
a bit overly aggressive in keeping other interrupts from running.
In particular I've seen an issue in the wild where
idle_in_transaction_session_timeout did not get triggered because
the HOLD_CANCEL_INTERRUPTS() in SocketBackend wraps around a pq_getbyte()
call, and so ProcessInterrupts doesn't do anything when it gets called
because the query cancel holdoff counter is positive.
Andres suggested the following re-ordering of the logic on -bugs:
> On Wed, Sep 20, 2017 at 6:29 PM, Andres Freund <andres@anarazel.de> wrote:
>>
>>
>> if (QueryCancelPending && QueryCancelHoldoffCount != 0)
>> {
>> /* rearm */
>> }
>> else if (QueryCancelPending)
>> {
>> /* handle interrupt */
>> }
>>
>
Which is implemented in the attached patch.
Unless someone wants to pick this up right away, I'll register it in the
next commitfest tomorrow.
Best,
Lukas
--
Lukas Fittl
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Attachments:
[application/octet-stream] 0001-Only-skip-query-cancel-itself-when-query-cancel-hold.patch (2.1K, ../../CAP53PkxQnv3OWJpyNPGJYT62uY=n1=2CF_Lpc6gVOFnc0-gazw@mail.gmail.com/3-0001-Only-skip-query-cancel-itself-when-query-cancel-hold.patch)
download | inline diff:
From 463098e59989b258c68e703b396e5364f48d840c Mon Sep 17 00:00:00 2001
From: Lukas Fittl <lukas@fittl.com>
Date: Wed, 20 Sep 2017 19:56:03 -0700
Subject: [PATCH] Only skip query cancel itself when query cancel holdoff count
is positive
Previously the logic would short-circuit all other interrupts that follow,
which is particularly a problem for idle_in_transaction_session_timeout
since that might want to cancel a connection thats not receiving any data
whilst being inside a block that has query cancellation holdoff active.
---
src/backend/tcop/postgres.c | 32 +++++++++++++++-----------------
1 file changed, 15 insertions(+), 17 deletions(-)
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index c807b00b0b..edea6f177b 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -2941,26 +2941,24 @@ ProcessInterrupts(void)
" database and repeat your command.")));
}
- if (QueryCancelPending)
+ /*
+ * Don't allow query cancel interrupts while reading input from the
+ * client, because we might lose sync in the FE/BE protocol. (Die
+ * interrupts are OK, because we won't read any further messages from
+ * the client in that case.)
+ */
+ if (QueryCancelPending && QueryCancelHoldoffCount != 0)
{
- bool lock_timeout_occurred;
- bool stmt_timeout_occurred;
-
/*
- * Don't allow query cancel interrupts while reading input from the
- * client, because we might lose sync in the FE/BE protocol. (Die
- * interrupts are OK, because we won't read any further messages from
- * the client in that case.)
+ * Re-arm InterruptPending so that we process the cancel request
+ * as soon as we're done reading the message.
*/
- if (QueryCancelHoldoffCount != 0)
- {
- /*
- * Re-arm InterruptPending so that we process the cancel request
- * as soon as we're done reading the message.
- */
- InterruptPending = true;
- return;
- }
+ InterruptPending = true;
+ }
+ else if (QueryCancelPending)
+ {
+ bool lock_timeout_occurred;
+ bool stmt_timeout_occurred;
QueryCancelPending = false;
--
2.11.0
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: [HACKERS] Re: BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending
2017-09-21 03:27 Re: [BUGS] BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending Lukas Fittl <lukas@fittl.com>
@ 2017-10-11 21:11 ` Andres Freund <andres@anarazel.de>
2017-10-11 22:23 ` Re: [HACKERS] Re: BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending Lukas Fittl <lukas@fittl.com>
0 siblings, 1 reply; 6+ messages in thread
From: Andres Freund @ 2017-10-11 21:11 UTC (permalink / raw)
To: Lukas Fittl <lukas@fittl.com>; +Cc: pgsql-hackers@postgresql.org <pgsql-hackers@postgresql.org>; pgsql-bugs
Hi,
On 2017-09-20 20:27:05 -0700, Lukas Fittl wrote:
> As per the bug report at
> https://www.postgresql.org/message-id/20170921010956.17345.61461%40wrigleys.postgresql.org
> it seems that the query cancellation holdoff logic in ProcessInterrupts is
> a bit overly aggressive in keeping other interrupts from running.
>
> In particular I've seen an issue in the wild where
> idle_in_transaction_session_timeout did not get triggered because
> the HOLD_CANCEL_INTERRUPTS() in SocketBackend wraps around a pq_getbyte()
> call, and so ProcessInterrupts doesn't do anything when it gets called
> because the query cancel holdoff counter is positive.
>
> Andres suggested the following re-ordering of the logic on -bugs:
I've pushed this. Thanks for the report & fix!
Greetings,
Andres Freund
--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: [HACKERS] Re: BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending
2017-09-21 03:27 Re: [BUGS] BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending Lukas Fittl <lukas@fittl.com>
2017-10-11 21:11 ` Re: [HACKERS] Re: BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending Andres Freund <andres@anarazel.de>
@ 2017-10-11 22:23 ` Lukas Fittl <lukas@fittl.com>
0 siblings, 0 replies; 6+ messages in thread
From: Lukas Fittl @ 2017-10-11 22:23 UTC (permalink / raw)
To: Andres Freund <andres@anarazel.de>; +Cc: pgsql-bugs@postgresql.org, "pgsql-hackers@postgresql.org" <pgsql-hackers@postgresql.org>
On Wed, Oct 11, 2017 at 2:11 PM Andres Freund <andres@anarazel.de> wrote:
> I've pushed this. Thanks for the report & fix!
>
Excellent, thanks!
Best,
Lukas
--
Lukas Fittl
^ permalink raw reply [nested|flat] 6+ messages in thread
end of thread, other threads:[~2017-10-11 22:23 UTC | newest]
Thread overview: 6+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2017-09-21 01:09 BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending lukas@fittl.com
2017-09-21 01:29 ` Andres Freund <andres@anarazel.de>
2017-09-21 01:39 ` Lukas Fittl <lukas@fittl.com>
2017-09-21 03:27 Re: [BUGS] BUG #14821: idle_in_transaction_session_timeout sometimes gets ignored when statement timeout is pending Lukas Fittl <lukas@fittl.com>
2017-10-11 21:11 ` Andres Freund <andres@anarazel.de>
2017-10-11 22:23 ` Lukas Fittl <lukas@fittl.com>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox