public inbox for [email protected]
help / color / mirror / Atom feedFrom: Alfonso Escribano <[email protected]>
To: [email protected]
Subject: Interaction between "client_connection_check_interval" and "log_lock_waits" parameters
Date: Wed, 3 Dec 2025 09:24:50 +0100
Message-ID: <[email protected]> (raw)
<html>
<head>
<meta http-equiv="content-type" content="text/html; charset=UTF-8">
</head>
<body bgcolor="#FFFFFF" text="#000000">
Hello,<br>
I have seen an interaction between
"client_connection_check_interval" and "log_lock_waits" parameters
that it isn't documented (or I can't find it anywhere).<br>
<br>
I don't know if it is a bug or if it is desired behaviour.<br>
When client_connection_check_interval has any value, and
log_lock_waits is enabled, the postgresql log displays a message
about lock waits with the frequency of
client_connection_check_interval.<br>
In these tests, I have "log_min_messages = log"<br>
<br>
Example test with log_lock_waits = on and
client_connection_check_interval = 10 (ms):<br>
<blockquote>2025-12-02 14:01:42.294 UTC psql postgres postgres
[local] 7138 SELECT waiting 00000 > LOG: process 7138 still
waiting for ShareLock on transaction 1292309444 after 1000.719 ms<br>
2025-12-02 14:01:42.294 UTC psql postgres postgres [local] 7138
SELECT waiting 00000 > STATEMENT: SELECT pdata FROM parent
WHERE pid = 1 FOR UPDATE;<br>
2025-12-02 14:01:42.304 UTC psql postgres postgres [local] 7138
SELECT waiting 00000 > LOG: process 7138 still waiting for
ShareLock on transaction 1292309444 after 1010.756 ms<br>
2025-12-02 14:01:42.304 UTC psql postgres postgres [local] 7138
SELECT waiting 00000 > STATEMENT: SELECT pdata FROM parent
WHERE pid = 1 FOR UPDATE;<br>
2025-12-02 14:01:42.314 UTC psql postgres postgres [local] 7138
SELECT waiting 00000 > LOG: process 7138 still waiting for
ShareLock on transaction 1292309444 after 1020.794 ms<br>
2025-12-02 14:01:42.314 UTC psql postgres postgres [local] 7138
SELECT waiting 00000 > STATEMENT: SELECT pdata FROM parent
WHERE pid = 1 FOR UPDATE;<br>
2025-12-02 14:01:42.324 UTC psql postgres postgres [local] 7138
SELECT waiting 00000 > LOG: process 7138 still waiting for
ShareLock on transaction 1292309444 after 1030.829 ms<br>
2025-12-02 14:01:42.324 UTC psql postgres postgres [local] 7138
SELECT waiting 00000 > STATEMENT: SELECT pdata FROM parent
WHERE pid = 1 FOR UPDATE;<br>
</blockquote>
If I set client_connection_check_interval to 1000 (1 second):<br>
<blockquote>2025-12-02 14:19:17.430 UTC psql postgres postgres
[local] 7320 SELECT waiting 00000 > LOG: process 7320 still
waiting for ShareLock on transaction 1292309446 after 108012.829
ms<br>
2025-12-02 14:19:17.430 UTC psql postgres postgres [local] 7320
SELECT waiting 00000 > STATEMENT: SELECT pdata FROM parent
WHERE pid = 1 FOR UPDATE;<br>
2025-12-02 14:19:18.430 UTC psql postgres postgres [local] 7320
SELECT waiting 00000 > LOG: process 7320 still waiting for
ShareLock on transaction 1292309446 after 109012.946 ms<br>
2025-12-02 14:19:18.430 UTC psql postgres postgres [local] 7320
SELECT waiting 00000 > STATEMENT: SELECT pdata FROM parent
WHERE pid = 1 FOR UPDATE;<br>
2025-12-02 14:19:19.430 UTC psql postgres postgres [local] 7320
SELECT waiting 00000 > LOG: process 7320 still waiting for
ShareLock on transaction 1292309446 after 110013.104 ms<br>
2025-12-02 14:19:19.430 UTC psql postgres postgres [local] 7320
SELECT waiting 00000 > STATEMENT: SELECT pdata FROM parent
WHERE pid = 1 FOR UPDATE;<br>
2025-12-02 14:19:20.430 UTC psql postgres postgres [local] 7320
SELECT waiting 00000 > LOG: process 7320 still waiting for
ShareLock on transaction 1292309446 after 111013.235 ms<br>
2025-12-02 14:19:20.430 UTC psql postgres postgres [local] 7320
SELECT waiting 00000 > STATEMENT: SELECT pdata FROM parent
WHERE pid = 1 FOR UPDATE;<br>
</blockquote>
And If I unset client_connection_check_interval config option, I
don't get these messages, only initial message of lock and I don't
have more messages about locks until it is resolved:<br>
<blockquote>2025-12-02 15:04:07.214 UTC psql postgres postgres
[local] 7680 SELECT waiting 00000 > STATEMENT: SELECT pdata
FROM parent WHERE pid = 1 FOR UPDATE;<br>
2025-12-02 15:04:43.522 UTC psql postgres postgres [local] 7688
SELECT waiting 00000 > LOG: process 7688 detected deadlock
while waiting for ShareLock on transaction 1292309452 after
1000.192 ms<br>
2025-12-02 15:04:43.522 UTC psql postgres postgres [local] 7688
SELECT waiting 00000 > STATEMENT: SELECT pdata FROM parent
WHERE pid = 1 FOR UPDATE;<br>
2025-12-02 15:04:43.523 UTC psql postgres postgres [local] 7688
SELECT 40P01 > ERROR: deadlock detected<br>
2025-12-02 15:04:43.523 UTC psql postgres postgres [local] 7688
SELECT 40P01 > STATEMENT: SELECT pdata FROM parent WHERE pid =
1 FOR UPDATE;<br>
2025-12-02 15:04:43.523 UTC psql postgres postgres [local] 7680
SELECT waiting 00000 > LOG: process 7680 acquired ShareLock on
transaction 1292309451 after 37309.305 ms<br>
2025-12-02 15:04:43.523 UTC psql postgres postgres [local] 7680
SELECT waiting 00000 > STATEMENT: SELECT pdata FROM parent
WHERE pid = 1 FOR UPDATE;<br>
<br>
</blockquote>
For me it seems that there is a bug about these config parameters
interaction, but I don't know if it is the desired behaviour.<br>
If it where the desired behaviour, it should be documented in <a
moz-do-not-send="true"
href="https://www.postgresql.org/docs/current/runtime-config-locks.html#GUC-DEADLOCK-TIMEOUT">deadl...;,
<a moz-do-not-send="true"
href="https://www.postgresql.org/docs/current/runtime-config-logging.html#GUC-LOG-LOCK-WAITS">log_l...;
and <a moz-do-not-send="true"
href="https://www.postgresql.org/docs/18/runtime-config-connection.html#GUC-CLIENT-CONNECTION-CHECK-INTERV...;
<br>
Would it be possible for someone to clarify this behaviour or see if
it's actually a bug so we can open the corresponding bug report?<br>
<br>
Regards,<br>
Alfonso Escribano<br>
<br>
<div class="moz-signature">-- <br>
<div dir="ltr">
<div><br clear="all">
</div>
<div dir"ltr"="" class="gmail_signature"
data-smartmail="gmail_signature">
<div dir="ltr"> <br>
<b style="color:rgb(105,105,105)">Alfonso Escribano</b> <br>
<font color="#3333ff"> <a
href="mailto:[email protected]"
target="_blank">[email protected]</a> <br>
<br>
</font> <a href="https://www.meteologica.com";
target="_blank"><img
src="http://www.meteologica.com/assets/images/logo.png";
width="200" height="16"></a> <br>
<a>c/ Costa Brava 10 - 28034 Madrid</a> <br>
<b style="color:rgb(105,105,105)">Office: </b> <a>+34 91
456 10 01</a> <br>
<br>
<div> <font size="1"> <font color="#000000" face="arial,
sans-serif"> This email and any files transmitted with
it are confidential and may be privileged and are
intended solely for the use of the individual or
entity to whom they are addressed. If you are not an
addressee, any unauthorized direct or indirect
dissemination, distribution, publication, reading, or
copying of this message and any attachments is
strictly prohibited. If you have received this email
in error please notify the sender immediately, and
delete this email from your system. Email
communication does not guarantee the confidentiality,
integrity, or proper receipt of the messages sent.
Meteológica, S.A. accepts no liability for such
circumstances. </font> <br>
</font> </div>
</div>
</div>
</div>
</div>
</body>
</html>
reply
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: [email protected]
Cc: [email protected], [email protected]
Subject: Re: Interaction between "client_connection_check_interval" and "log_lock_waits" parameters
In-Reply-To: <[email protected]>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox