public inbox for [email protected]  
help / color / mirror / Atom feed
From: Hüseyin Demir <[email protected]>
To: Fujii Masao <[email protected]>
Cc: Chao Li <[email protected]>
Cc: [email protected]
Subject: Re: client_connection_check_interval default value
Date: Mon, 6 Apr 2026 14:59:49 +0200
Message-ID: <CAB5wL7aSJ5Cw1VdX5V0L4s3t+T2=M=yXo07sC+JLdKggkLCkdA@mail.gmail.com> (raw)
In-Reply-To: <CAHGQGwHPcgESm_cqQ52xeJtLFjfFY4hr+s6byYiojNKOwxO3Mg@mail.gmail.com>
References: <[email protected]>
	<CAHGQGwH7c5X4OkPaQ6VDaLGoFgJgwf_-HNwUi2uXoiAhkFkkyA@mail.gmail.com>
	<177304694613.1094603.10800724073727441272.pgcf@coridan.postgresql.org>
	<CAHGQGwG_Ud-N1zrULv8fE51-CUd2ZF3eDe7jUdNOm-rt_JgcQQ@mail.gmail.com>
	<[email protected]>
	<CAHGQGwEBvWXU4sdu2DMxaUWdPYQvGesr1VPyX-WnSxtW9nN6UA@mail.gmail.com>
	<CAB5wL7YB1my9W5k5i=SY+=sTjeozyJ0YkvGXrVfeDNzuRkoTPg@mail.gmail.com>
	<CAHGQGwGV3ufcdXnW6JLBhejfptCJRGs7Jrp03YPoO7V_b-2MFA@mail.gmail.com>
	<CAB5wL7amNFF3zA=h5R3Wx1aQZR-EKzv485LyYMLbB9X7dhx2Ew@mail.gmail.com>
	<CAHGQGwHPcgESm_cqQ52xeJtLFjfFY4hr+s6byYiojNKOwxO3Mg@mail.gmail.com>

Hi,



> Thanks for the patch!
>
> Commit 557a9f1e3e6 recently added test for lock stats, which also causes
> lock wait situations. So it seems better to extend that test to cover
> log_lock_waits rather than adding a new TAP test file.
>
> I've prepared a patch to do this. Patch attached. Thought?
>
> Regards,
>

Appreciated for the patch. I reviewed it quickly.

In the test description it says that `still waiting logged exactly once
despite pg_reload_conf() wakeups")` but the test sends via
pg_log_backend_memory_contexts(). It would make sense to update it.

```
  -  1, "still waiting logged exactly once despite pg_reload_conf()
wakeups");
  +  1, "still waiting logged exactly once despite wakeups from
pg_log_backend_memory_contexts()");
```

Secondly, before finishing the test it tries to check that no
log_lock_waits messages are emitted. But the comment has the opposite
meaning.

```
  - 'check that log_lock_waits message is emitted when the lock is acquired
after waiting'
  + 'check that no log_lock_waits message is emitted when the lock is
acquired after waiting'
```

I'm not sure they need to change but these are the only topics I wanted to
add. Otherwise, lgtm and thanks.

I attached the v3 to convey my ideas. You can use it or update the existing
if you think the suggestions are reasonable.


Regards.


Attachments:

  [application/octet-stream] v3-0001-Add-TAP-tests-for-log_lock_waits.patch (5.1K, 3-v3-0001-Add-TAP-tests-for-log_lock_waits.patch)
  download | inline diff:
diff --git a/src/test/modules/test_misc/t/011_lock_stats.pl b/src/test/modules/test_misc/t/011_lock_stats.pl
index 58a0046a52c..d95fcd4bb4c 100644
--- a/src/test/modules/test_misc/t/011_lock_stats.pl
+++ b/src/test/modules/test_misc/t/011_lock_stats.pl
@@ -1,13 +1,18 @@
 
 # Copyright (c) 2026, PostgreSQL Global Development Group
 
-# Test for the lock statistics
+# Test for the lock statistics and log_lock_waits
 #
 # This test creates multiple locking situations when a session (s2) has to
 # wait on a lock for longer than deadlock_timeout. The first tests each test a
 # dedicated lock type.
 # The last one checks that log_lock_waits has no impact on the statistics
 # counters.
+#
+# This test also checks that log_lock_waits messages are emitted both when
+# a wait occurs and when the lock is acquired, and that the "still waiting for"
+# message is logged exactly once per wait, even if the backend wakes due
+# to signals.
 
 use strict;
 use warnings FATAL => 'all';
@@ -90,6 +95,8 @@ INSERT INTO test_stat_tab(key, value) VALUES('k0', 1);
 
 setup_sessions();
 
+my $log_offset = -s $node->logfile;
+
 $s1->query_safe(
 	q[
 SELECT pg_stat_reset_shared('lock');
@@ -112,6 +119,18 @@ LOCK TABLE test_stat_tab;
 
 wait_and_detach($node, 'deadlock-timeout-fired');
 
+# Check that log_lock_waits message is emitted during a lock wait.
+$node->wait_for_log(qr/still waiting for AccessExclusiveLock on relation/,
+	$log_offset);
+
+# Wake the backend waiting on the lock. Confirm it woke by calling
+# pg_log_backend_memory_contexts() and checking for the logged memory contexts.
+$node->safe_psql(
+	'postgres', q[SELECT pg_log_backend_memory_contexts(pid)
+	FROM pg_locks WHERE locktype = 'relation' AND
+	relation = 'test_stat_tab'::regclass AND NOT granted;]);
+$node->wait_for_log(qr/logging memory contexts/, $log_offset);
+
 # deadlock_timeout fired, now commit in s1 and s2
 $s1->query_safe(q(COMMIT));
 $s2->query_safe(q(COMMIT));
@@ -120,6 +139,18 @@ $s2->query_safe(q(COMMIT));
 wait_for_pg_stat_lock($node, 'relation');
 ok(1, "Lock stats ok for relation");
 
+# Check that log_lock_waits message is emitted when the lock is acquired
+# after waiting.
+$node->wait_for_log(qr/acquired AccessExclusiveLock on relation/,
+	$log_offset);
+
+# Check that the "still waiting for" message is logged exactly once per wait,
+# even if the backend wakes during the wait.
+my $log_contents = slurp_file($node->logfile, $log_offset);
+my @still_waiting = ($log_contents =~ /still waiting for/g);
+is(scalar @still_waiting,
+	1, "still waiting logged exactly once despite wakeups from pg_log_backend_memory_contexts()");
+
 # close sessions
 $s1->quit;
 $s2->quit;
@@ -128,6 +159,8 @@ $s2->quit;
 
 setup_sessions();
 
+$log_offset = -s $node->logfile;
+
 $s1->query_safe(
 	q[
 SELECT pg_stat_reset_shared('lock');
@@ -152,6 +185,10 @@ UPDATE test_stat_tab SET value = value + 1 WHERE key = 'k1';
 
 wait_and_detach($node, 'deadlock-timeout-fired');
 
+# Check that log_lock_waits message is emitted during a lock wait.
+$node->wait_for_log(qr/still waiting for ShareLock on transaction/,
+	$log_offset);
+
 # deadlock_timeout fired, now commit in s1 and s2
 $s1->query_safe(q(COMMIT));
 $s2->query_safe(q(COMMIT));
@@ -160,6 +197,10 @@ $s2->query_safe(q(COMMIT));
 wait_for_pg_stat_lock($node, 'transactionid');
 ok(1, "Lock stats ok for transactionid");
 
+# Check that log_lock_waits message is emitted when the lock is acquired
+# after waiting.
+$node->wait_for_log(qr/acquired ShareLock on transaction/, $log_offset);
+
 # Close sessions
 $s1->quit;
 $s2->quit;
@@ -168,6 +209,8 @@ $s2->quit;
 
 setup_sessions();
 
+$log_offset = -s $node->logfile;
+
 $s1->query_safe(
 	q[
 SELECT pg_stat_reset_shared('lock');
@@ -190,6 +233,10 @@ SELECT pg_advisory_lock(1);
 
 wait_and_detach($node, 'deadlock-timeout-fired');
 
+# Check that log_lock_waits message is emitted during a lock wait.
+$node->wait_for_log(qr/still waiting for ExclusiveLock on advisory lock/,
+	$log_offset);
+
 # deadlock_timeout fired, now unlock and commit s2
 $s1->query_safe(q(SELECT pg_advisory_unlock(1)));
 $s2->query_safe(
@@ -202,6 +249,10 @@ COMMIT;
 wait_for_pg_stat_lock($node, 'advisory');
 ok(1, "Lock stats ok for advisory");
 
+# Check that log_lock_waits message is emitted when the lock is acquired
+# after waiting.
+$node->wait_for_log(qr/acquired ExclusiveLock on advisory lock/, $log_offset);
+
 # Close sessions
 $s1->quit;
 $s2->quit;
@@ -210,6 +261,8 @@ $s2->quit;
 
 setup_sessions();
 
+$log_offset = -s $node->logfile;
+
 $s1->query_safe(
 	q[
 SELECT pg_stat_reset_shared('lock');
@@ -241,6 +294,15 @@ $s2->query_safe(q(COMMIT));
 wait_for_pg_stat_lock($node, 'relation');
 ok(1, "log_lock_waits has no impact on Lock stats");
 
+# Check that no log_lock_waits messages are emitted
+ok( !$node->log_contains(
+		"still waiting for AccessExclusiveLock on relation", $log_offset),
+	'check that no log_lock_waits message is emitted during a lock wait');
+ok( !$node->log_contains(
+		"acquired AccessExclusiveLock on relation", $log_offset),
+	'check that no log_lock_waits message is emitted when the lock is acquired after waiting'
+);
+
 # close sessions
 $s1->quit;
 $s2->quit;


view thread (22+ messages)  latest in thread

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], [email protected], [email protected]
  Subject: Re: client_connection_check_interval default value
  In-Reply-To: <CAB5wL7aSJ5Cw1VdX5V0L4s3t+T2=M=yXo07sC+JLdKggkLCkdA@mail.gmail.com>

* 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