public inbox for [email protected]
help / color / mirror / Atom feedFrom: Fujii Masao <[email protected]>
To: Hüseyin Demir <[email protected]>
Cc: Chao Li <[email protected]>
Cc: [email protected]
Subject: Re: client_connection_check_interval default value
Date: Mon, 6 Apr 2026 20:09:30 +0900
Message-ID: <CAHGQGwHPcgESm_cqQ52xeJtLFjfFY4hr+s6byYiojNKOwxO3Mg@mail.gmail.com> (raw)
In-Reply-To: <CAB5wL7amNFF3zA=h5R3Wx1aQZR-EKzv485LyYMLbB9X7dhx2Ew@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>
On Wed, Mar 18, 2026 at 4:59 AM Hüseyin Demir <[email protected]> wrote:
> I created a regression test for the behaviour we mentioned before
> introducing further possible changes.
>
> You can review it. Basically I tried to simulate the desired behaviour
> which the current patch introduced.
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,
Attachments:
[application/octet-stream] v2-0001-Add-TAP-tests-for-log_lock_waits.patch (5.7K, 2-v2-0001-Add-TAP-tests-for-log_lock_waits.patch)
download | inline diff:
From 3741cbdfa3a9dbcc883daaeae06891621e844c3c Mon Sep 17 00:00:00 2001
From: Fujii Masao <[email protected]>
Date: Mon, 6 Apr 2026 15:14:34 +0900
Subject: [PATCH v2] Add TAP tests for log_lock_waits
This commit updates 011_lock_stats.pl to verify log_lock_waits behavior.
The tests check that 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 up during the wait.
The latter covers the behavior introduced by commit fd6ecbfa75f.
---
.../modules/test_misc/t/011_lock_stats.pl | 64 ++++++++++++++++++-
1 file changed, 63 insertions(+), 1 deletion(-)
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..9910db6bf4e 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 pg_reload_conf() wakeups");
+
# 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 log_lock_waits message is emitted when the lock is acquired after waiting'
+);
+
# close sessions
$s1->quit;
$s2->quit;
--
2.51.2
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: <CAHGQGwHPcgESm_cqQ52xeJtLFjfFY4hr+s6byYiojNKOwxO3Mg@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