Interaction between "client_connection_check_interval" and "log_lock_waits" parameters

[Alfonso Escribano]

Hello, 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). I don't know if it is a bug or if it is desired behaviour. 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. In these tests, I have "log_min_messages = log" Example test with log_lock_waits = on and client_connection_check_interval = 10 (ms): 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 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; 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 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; 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 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; 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 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; If I set client_connection_check_interval to 1000 (1 second): 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 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; 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 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; 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 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; 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 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; 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: 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; 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 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; 2025-12-02 15:04:43.523 UTC psql postgres postgres [local] 7688 SELECT 40P01 > ERROR:  deadlock detected 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; 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 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; 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. If it where the desired behaviour, it should be documented in deadlock_timeout, log_lock_waits and client_connection_check_interval 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? Regards, Alfonso Escribano -- Alfonso Escribano alfonso.escrib...@meteologica.com c/ Costa Brava 10 - 28034 Madrid Office: +34 91 456 10 01 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.