agora inbox for pgsql-hackers@postgresql.org
help / color / mirror / Atom feedFrom: Bertrand Drouvot <bertranddrouvot.pg@gmail.com>
Subject: [PATCH v9 3/3] Introduce a new track_lock_timing GUC
Date: Fri, 20 Feb 2026 06:13:28 +0000
A new GUC (track_lock_timing) is added and defaults to on. If on, waits and
wait_time counters are incremented if the session waited longer than deadlock_timeout
to acquire the lock. It's on by default, as this is the same idea as 2aac62be8cb.
---
doc/src/sgml/config.sgml | 19 ++
doc/src/sgml/monitoring.sgml | 4 +-
src/backend/storage/lmgr/proc.c | 185 +++++++++---------
src/backend/utils/misc/guc_parameters.dat | 6 +
src/backend/utils/misc/postgresql.conf.sample | 1 +
src/include/pgstat.h | 1 +
src/test/isolation/expected/stats.out | 24 +--
src/test/isolation/expected/stats_1.out | 24 +--
src/test/isolation/specs/stats.spec | 24 +--
9 files changed, 161 insertions(+), 127 deletions(-)
7.3% doc/src/sgml/
50.0% src/backend/storage/lmgr/
34.7% src/test/isolation/expected/
5.8% src/test/isolation/specs/
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 8cdd826fbd3..69938ba3cdc 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -8857,6 +8857,25 @@ COPY postgres_log FROM '/full/path/to/logfile.csv' WITH csv;
</listitem>
</varlistentry>
+ <varlistentry id="guc-track-lock-timing" xreflabel="track_lock_timing">
+ <term><varname>track_lock_timing</varname> (<type>boolean</type>)
+ <indexterm>
+ <primary><varname>track_lock_timing</varname> configuration parameter</primary>
+ </indexterm>
+ </term>
+ <listitem>
+ <para>
+ Enables timing of lock waits. This parameter is on by default, as it tracks
+ only the timings for successful acquisitions that waited longer than
+ <xref linkend="guc-deadlock-timeout"/>. Lock timing information is
+ displayed in the <link linkend="monitoring-pg-stat-lock-view">
+ <structname>pg_stat_lock</structname></link> view.
+ Only superusers and users with the appropriate <literal>SET</literal>
+ privilege can change this setting.
+ </para>
+ </listitem>
+ </varlistentry>
+
<varlistentry id="guc-track-wal-io-timing" xreflabel="track_wal_io_timing">
<term><varname>track_wal_io_timing</varname> (<type>boolean</type>)
<indexterm>
diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml
index 221ee28cc7b..6ae9cc7635d 100644
--- a/doc/src/sgml/monitoring.sgml
+++ b/doc/src/sgml/monitoring.sgml
@@ -3340,7 +3340,7 @@ description | Waiting for a newly initialized WAL file to reach durable storage
</para>
<para>
Number of times a lock of this type had to wait because of a
- conflicting lock. Only incremented when <xref linkend="guc-log-lock-waits"/>
+ conflicting lock. Only incremented when <xref linkend="guc-track-lock-timing"/>
is enabled and the lock was successfully acquired after waiting longer
than <xref linkend="guc-deadlock-timeout"/>.
</para>
@@ -3354,7 +3354,7 @@ description | Waiting for a newly initialized WAL file to reach durable storage
</para>
<para>
Total time spent waiting for locks of this type, in milliseconds.
- Only incremented when <xref linkend="guc-log-lock-waits"/> is enabled and
+ Only incremented when <xref linkend="guc-track-lock-timing"/> is enabled and
the lock was successfully acquired after waiting longer than
<xref linkend="guc-deadlock-timeout"/>.
</para>
diff --git a/src/backend/storage/lmgr/proc.c b/src/backend/storage/lmgr/proc.c
index 263dc88b735..e9b7b5fd4c9 100644
--- a/src/backend/storage/lmgr/proc.c
+++ b/src/backend/storage/lmgr/proc.c
@@ -63,6 +63,7 @@ int IdleInTransactionSessionTimeout = 0;
int TransactionTimeout = 0;
int IdleSessionTimeout = 0;
bool log_lock_waits = true;
+bool track_lock_timing = true;
/* Pointer to this process's PGPROC struct, if any */
PGPROC *MyProc = NULL;
@@ -1550,115 +1551,125 @@ ProcSleep(LOCALLOCK *locallock)
/*
* If awoken after the deadlock check interrupt has run, and
- * log_lock_waits is on, then report about the wait.
+ * log_lock_waits or track_lock_timing is on, then report or track
+ * about the wait.
*/
- if (log_lock_waits && deadlock_state != DS_NOT_YET_CHECKED)
+ if ((log_lock_waits || track_lock_timing) &&
+ deadlock_state != DS_NOT_YET_CHECKED)
{
- StringInfoData buf,
- lock_waiters_sbuf,
- lock_holders_sbuf;
- const char *modename;
long secs;
int usecs;
long msecs;
- int lockHoldersNum = 0;
- initStringInfo(&buf);
- initStringInfo(&lock_waiters_sbuf);
- initStringInfo(&lock_holders_sbuf);
-
- DescribeLockTag(&buf, &locallock->tag.lock);
- modename = GetLockmodeName(locallock->tag.lock.locktag_lockmethodid,
- lockmode);
TimestampDifference(get_timeout_start_time(DEADLOCK_TIMEOUT),
GetCurrentTimestamp(),
&secs, &usecs);
msecs = secs * 1000 + usecs / 1000;
usecs = usecs % 1000;
- /* Gather a list of all lock holders and waiters */
- LWLockAcquire(partitionLock, LW_SHARED);
- GetLockHoldersAndWaiters(locallock, &lock_holders_sbuf,
- &lock_waiters_sbuf, &lockHoldersNum);
- LWLockRelease(partitionLock);
-
- if (deadlock_state == DS_SOFT_DEADLOCK)
- ereport(LOG,
- (errmsg("process %d avoided deadlock for %s on %s by rearranging queue order after %ld.%03d ms",
- MyProcPid, modename, buf.data, msecs, usecs),
- (errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.",
- "Processes holding the lock: %s. Wait queue: %s.",
- lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data))));
- else if (deadlock_state == DS_HARD_DEADLOCK)
- {
- /*
- * This message is a bit redundant with the error that will be
- * reported subsequently, but in some cases the error report
- * might not make it to the log (eg, if it's caught by an
- * exception handler), and we want to ensure all long-wait
- * events get logged.
- */
- ereport(LOG,
- (errmsg("process %d detected deadlock while waiting for %s on %s after %ld.%03d ms",
- MyProcPid, modename, buf.data, msecs, usecs),
- (errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.",
- "Processes holding the lock: %s. Wait queue: %s.",
- lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data))));
- }
+ /* Increment the lock statistics counters */
+ if (track_lock_timing && myWaitStatus == PROC_WAIT_STATUS_OK)
+ pgstat_count_lock_waits(locallock->tag.lock.locktag_type, msecs);
- if (myWaitStatus == PROC_WAIT_STATUS_WAITING)
+ if (log_lock_waits)
{
- /*
- * Guard the "still waiting on lock" log message so it is
- * reported at most once while waiting for the lock.
- *
- * Without this guard, the message can be emitted whenever the
- * lock-wait sleep is interrupted (for example by SIGHUP for
- * config reload or by client_connection_check_interval). For
- * example, if client_connection_check_interval is set very
- * low (e.g., 100 ms), the message could be logged repeatedly,
- * flooding the log and making it difficult to use.
- */
- if (!logged_lock_wait)
- {
+ StringInfoData buf,
+ lock_waiters_sbuf,
+ lock_holders_sbuf;
+ const char *modename;
+ int lockHoldersNum = 0;
+
+ initStringInfo(&buf);
+ initStringInfo(&lock_waiters_sbuf);
+ initStringInfo(&lock_holders_sbuf);
+
+ DescribeLockTag(&buf, &locallock->tag.lock);
+ modename = GetLockmodeName(locallock->tag.lock.locktag_lockmethodid,
+ lockmode);
+
+ /* Gather a list of all lock holders and waiters */
+ LWLockAcquire(partitionLock, LW_SHARED);
+ GetLockHoldersAndWaiters(locallock, &lock_holders_sbuf,
+ &lock_waiters_sbuf, &lockHoldersNum);
+ LWLockRelease(partitionLock);
+
+ if (deadlock_state == DS_SOFT_DEADLOCK)
ereport(LOG,
- (errmsg("process %d still waiting for %s on %s after %ld.%03d ms",
+ (errmsg("process %d avoided deadlock for %s on %s by rearranging queue order after %ld.%03d ms",
MyProcPid, modename, buf.data, msecs, usecs),
(errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.",
"Processes holding the lock: %s. Wait queue: %s.",
lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data))));
- logged_lock_wait = true;
- }
- }
- else if (myWaitStatus == PROC_WAIT_STATUS_OK)
- {
- /* Increment the lock statistics counters */
- pgstat_count_lock_waits(locallock->tag.lock.locktag_type, msecs);
-
- ereport(LOG,
- (errmsg("process %d acquired %s on %s after %ld.%03d ms",
- MyProcPid, modename, buf.data, msecs, usecs)));
- }
- else
- {
- Assert(myWaitStatus == PROC_WAIT_STATUS_ERROR);
-
- /*
- * Currently, the deadlock checker always kicks its own
- * process, which means that we'll only see
- * PROC_WAIT_STATUS_ERROR when deadlock_state ==
- * DS_HARD_DEADLOCK, and there's no need to print redundant
- * messages. But for completeness and future-proofing, print
- * a message if it looks like someone else kicked us off the
- * lock.
- */
- if (deadlock_state != DS_HARD_DEADLOCK)
+ else if (deadlock_state == DS_HARD_DEADLOCK)
+ {
+ /*
+ * This message is a bit redundant with the error that
+ * will be reported subsequently, but in some cases the
+ * error report might not make it to the log (eg, if it's
+ * caught by an exception handler), and we want to ensure
+ * all long-wait events get logged.
+ */
ereport(LOG,
- (errmsg("process %d failed to acquire %s on %s after %ld.%03d ms",
+ (errmsg("process %d detected deadlock while waiting for %s on %s after %ld.%03d ms",
MyProcPid, modename, buf.data, msecs, usecs),
(errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.",
"Processes holding the lock: %s. Wait queue: %s.",
lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data))));
+ }
+ if (myWaitStatus == PROC_WAIT_STATUS_WAITING)
+ {
+ /*
+ * Guard the "still waiting on lock" log message so it is
+ * reported at most once while waiting for the lock.
+ *
+ * Without this guard, the message can be emitted whenever
+ * the lock-wait sleep is interrupted (for example by
+ * SIGHUP for config reload or by
+ * client_connection_check_interval). For example, if
+ * client_connection_check_interval is set very low (e.g.,
+ * 100 ms), the message could be logged repeatedly,
+ * flooding the log and making it difficult to use.
+ */
+ if (!logged_lock_wait)
+ {
+ ereport(LOG,
+ (errmsg("process %d still waiting for %s on %s after %ld.%03d ms",
+ MyProcPid, modename, buf.data, msecs, usecs),
+ (errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.",
+ "Processes holding the lock: %s. Wait queue: %s.",
+ lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data))));
+ logged_lock_wait = true;
+ }
+ }
+ else if (myWaitStatus == PROC_WAIT_STATUS_OK)
+ ereport(LOG,
+ (errmsg("process %d acquired %s on %s after %ld.%03d ms",
+ MyProcPid, modename, buf.data, msecs, usecs)));
+ else
+ {
+ Assert(myWaitStatus == PROC_WAIT_STATUS_ERROR);
+
+ /*
+ * Currently, the deadlock checker always kicks its own
+ * process, which means that we'll only see
+ * PROC_WAIT_STATUS_ERROR when deadlock_state ==
+ * DS_HARD_DEADLOCK, and there's no need to print
+ * redundant messages. But for completeness and
+ * future-proofing, print a message if it looks like
+ * someone else kicked us off the lock.
+ */
+ if (deadlock_state != DS_HARD_DEADLOCK)
+ ereport(LOG,
+ (errmsg("process %d failed to acquire %s on %s after %ld.%03d ms",
+ MyProcPid, modename, buf.data, msecs, usecs),
+ (errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.",
+ "Processes holding the lock: %s. Wait queue: %s.",
+ lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data))));
+ }
+
+ pfree(buf.data);
+ pfree(lock_holders_sbuf.data);
+ pfree(lock_waiters_sbuf.data);
}
/*
@@ -1666,10 +1677,6 @@ ProcSleep(LOCALLOCK *locallock)
* state so we don't print the above messages again.
*/
deadlock_state = DS_NO_DEADLOCK;
-
- pfree(buf.data);
- pfree(lock_holders_sbuf.data);
- pfree(lock_waiters_sbuf.data);
}
} while (myWaitStatus == PROC_WAIT_STATUS_WAITING);
diff --git a/src/backend/utils/misc/guc_parameters.dat b/src/backend/utils/misc/guc_parameters.dat
index a5a0edf2534..7055dc88e0d 100644
--- a/src/backend/utils/misc/guc_parameters.dat
+++ b/src/backend/utils/misc/guc_parameters.dat
@@ -3110,6 +3110,12 @@
boot_val => 'false',
},
+{ name => 'track_lock_timing', type => 'bool', context => 'PGC_SUSET', group => 'STATS_CUMULATIVE',
+ short_desc => 'Collects timing statistics for lock acquisition.',
+ variable => 'track_lock_timing',
+ boot_val => 'true',
+},
+
{ name => 'track_wal_io_timing', type => 'bool', context => 'PGC_SUSET', group => 'STATS_CUMULATIVE',
short_desc => 'Collects timing statistics for WAL I/O activity.',
variable => 'track_wal_io_timing',
diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample
index e686d88afc4..5d057608fe1 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -685,6 +685,7 @@
#track_counts = on
#track_cost_delay_timing = off
#track_io_timing = off
+#track_lock_timing = on
#track_wal_io_timing = off
#track_functions = none # none, pl, all
#stats_fetch_consistency = cache # cache, none, snapshot
diff --git a/src/include/pgstat.h b/src/include/pgstat.h
index 06e2638e788..95006dc139c 100644
--- a/src/include/pgstat.h
+++ b/src/include/pgstat.h
@@ -842,6 +842,7 @@ extern PgStat_WalStats *pgstat_fetch_stat_wal(void);
extern PGDLLIMPORT bool pgstat_track_counts;
extern PGDLLIMPORT int pgstat_track_functions;
extern PGDLLIMPORT int pgstat_fetch_consistency;
+extern PGDLLIMPORT bool track_lock_timing;
/*
diff --git a/src/test/isolation/expected/stats.out b/src/test/isolation/expected/stats.out
index 3cae3052e40..4f7ad061549 100644
--- a/src/test/isolation/expected/stats.out
+++ b/src/test/isolation/expected/stats.out
@@ -3752,7 +3752,7 @@ test_stat_func| 1|t |t
step s1_commit: COMMIT;
-starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_log_lock_waits s2_set_deadlock_timeout s2_set_log_lock_waits s1_begin s1_lock_relation s2_begin s2_ff s2_lock_relation s1_sleep s1_commit s2_commit s2_report_stat_lock_relation
+starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_track_lock_timing s2_set_deadlock_timeout s2_set_track_lock_timing s1_begin s1_lock_relation s2_begin s2_ff s2_lock_relation s1_sleep s1_commit s2_commit s2_report_stat_lock_relation
pg_stat_force_next_flush
------------------------
@@ -3765,9 +3765,9 @@ pg_stat_reset_shared
(1 row)
-step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s1_set_track_lock_timing: SET track_lock_timing = on;
step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
-step s2_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_track_lock_timing: SET track_lock_timing = on;
step s1_begin: BEGIN;
step s1_lock_relation: LOCK TABLE test_stat_tab;
step s2_begin: BEGIN;
@@ -3794,7 +3794,7 @@ t |t
(1 row)
-starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_log_lock_waits s2_set_deadlock_timeout s2_set_log_lock_waits s1_table_insert s1_begin s1_table_update_k1 s2_begin s2_ff s2_table_update_k1 s1_sleep s1_commit s2_commit s2_report_stat_lock_transactionid
+starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_track_lock_timing s2_set_deadlock_timeout s2_set_track_lock_timing s1_table_insert s1_begin s1_table_update_k1 s2_begin s2_ff s2_table_update_k1 s1_sleep s1_commit s2_commit s2_report_stat_lock_transactionid
pg_stat_force_next_flush
------------------------
@@ -3807,9 +3807,9 @@ pg_stat_reset_shared
(1 row)
-step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s1_set_track_lock_timing: SET track_lock_timing = on;
step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
-step s2_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_track_lock_timing: SET track_lock_timing = on;
step s1_table_insert: INSERT INTO test_stat_tab(key, value) VALUES('k1', 1), ('k2', 1), ('k3', 1);
step s1_begin: BEGIN;
step s1_table_update_k1: UPDATE test_stat_tab SET value = value + 1 WHERE key = 'k1';
@@ -3837,7 +3837,7 @@ t |t
(1 row)
-starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_log_lock_waits s2_set_deadlock_timeout s2_set_log_lock_waits s1_lock_advisory_lock s2_begin s2_ff s2_lock_advisory_lock s1_sleep s1_lock_advisory_unlock s2_lock_advisory_unlock s2_commit s2_report_stat_lock_advisory
+starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_track_lock_timing s2_set_deadlock_timeout s2_set_track_lock_timing s1_lock_advisory_lock s2_begin s2_ff s2_lock_advisory_lock s1_sleep s1_lock_advisory_unlock s2_lock_advisory_unlock s2_commit s2_report_stat_lock_advisory
pg_stat_force_next_flush
------------------------
@@ -3850,9 +3850,9 @@ pg_stat_reset_shared
(1 row)
-step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s1_set_track_lock_timing: SET track_lock_timing = on;
step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
-step s2_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_track_lock_timing: SET track_lock_timing = on;
step s1_lock_advisory_lock: SELECT pg_advisory_lock(1);
pg_advisory_lock
----------------
@@ -3899,7 +3899,7 @@ t |t
(1 row)
-starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_log_lock_waits s2_set_deadlock_timeout s2_unset_log_lock_waits s1_begin s1_lock_relation s2_begin s2_ff s2_lock_relation s1_sleep s1_commit s2_commit s2_report_stat_lock_relation
+starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_track_lock_timing s2_set_deadlock_timeout s2_unset_track_lock_timing s1_begin s1_lock_relation s2_begin s2_ff s2_lock_relation s1_sleep s1_commit s2_commit s2_report_stat_lock_relation
pg_stat_force_next_flush
------------------------
@@ -3912,9 +3912,9 @@ pg_stat_reset_shared
(1 row)
-step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s1_set_track_lock_timing: SET track_lock_timing = on;
step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
-step s2_unset_log_lock_waits: SET log_lock_waits = off;
+step s2_unset_track_lock_timing: SET track_lock_timing = off;
step s1_begin: BEGIN;
step s1_lock_relation: LOCK TABLE test_stat_tab;
step s2_begin: BEGIN;
diff --git a/src/test/isolation/expected/stats_1.out b/src/test/isolation/expected/stats_1.out
index ea4fd97a9a5..e1a60d41bad 100644
--- a/src/test/isolation/expected/stats_1.out
+++ b/src/test/isolation/expected/stats_1.out
@@ -3776,7 +3776,7 @@ test_stat_func| 1|t |t
step s1_commit: COMMIT;
-starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_log_lock_waits s2_set_deadlock_timeout s2_set_log_lock_waits s1_begin s1_lock_relation s2_begin s2_ff s2_lock_relation s1_sleep s1_commit s2_commit s2_report_stat_lock_relation
+starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_track_lock_timing s2_set_deadlock_timeout s2_set_track_lock_timing s1_begin s1_lock_relation s2_begin s2_ff s2_lock_relation s1_sleep s1_commit s2_commit s2_report_stat_lock_relation
pg_stat_force_next_flush
------------------------
@@ -3789,9 +3789,9 @@ pg_stat_reset_shared
(1 row)
-step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s1_set_track_lock_timing: SET track_lock_timing = on;
step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
-step s2_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_track_lock_timing: SET track_lock_timing = on;
step s1_begin: BEGIN;
step s1_lock_relation: LOCK TABLE test_stat_tab;
step s2_begin: BEGIN;
@@ -3818,7 +3818,7 @@ t |t
(1 row)
-starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_log_lock_waits s2_set_deadlock_timeout s2_set_log_lock_waits s1_table_insert s1_begin s1_table_update_k1 s2_begin s2_ff s2_table_update_k1 s1_sleep s1_commit s2_commit s2_report_stat_lock_transactionid
+starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_track_lock_timing s2_set_deadlock_timeout s2_set_track_lock_timing s1_table_insert s1_begin s1_table_update_k1 s2_begin s2_ff s2_table_update_k1 s1_sleep s1_commit s2_commit s2_report_stat_lock_transactionid
pg_stat_force_next_flush
------------------------
@@ -3831,9 +3831,9 @@ pg_stat_reset_shared
(1 row)
-step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s1_set_track_lock_timing: SET track_lock_timing = on;
step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
-step s2_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_track_lock_timing: SET track_lock_timing = on;
step s1_table_insert: INSERT INTO test_stat_tab(key, value) VALUES('k1', 1), ('k2', 1), ('k3', 1);
step s1_begin: BEGIN;
step s1_table_update_k1: UPDATE test_stat_tab SET value = value + 1 WHERE key = 'k1';
@@ -3861,7 +3861,7 @@ t |t
(1 row)
-starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_log_lock_waits s2_set_deadlock_timeout s2_set_log_lock_waits s1_lock_advisory_lock s2_begin s2_ff s2_lock_advisory_lock s1_sleep s1_lock_advisory_unlock s2_lock_advisory_unlock s2_commit s2_report_stat_lock_advisory
+starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_track_lock_timing s2_set_deadlock_timeout s2_set_track_lock_timing s1_lock_advisory_lock s2_begin s2_ff s2_lock_advisory_lock s1_sleep s1_lock_advisory_unlock s2_lock_advisory_unlock s2_commit s2_report_stat_lock_advisory
pg_stat_force_next_flush
------------------------
@@ -3874,9 +3874,9 @@ pg_stat_reset_shared
(1 row)
-step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s1_set_track_lock_timing: SET track_lock_timing = on;
step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
-step s2_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_track_lock_timing: SET track_lock_timing = on;
step s1_lock_advisory_lock: SELECT pg_advisory_lock(1);
pg_advisory_lock
----------------
@@ -3923,7 +3923,7 @@ t |t
(1 row)
-starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_log_lock_waits s2_set_deadlock_timeout s2_unset_log_lock_waits s1_begin s1_lock_relation s2_begin s2_ff s2_lock_relation s1_sleep s1_commit s2_commit s2_report_stat_lock_relation
+starting permutation: s1_set_deadlock_timeout s1_reset_stat_lock s1_set_track_lock_timing s2_set_deadlock_timeout s2_unset_track_lock_timing s1_begin s1_lock_relation s2_begin s2_ff s2_lock_relation s1_sleep s1_commit s2_commit s2_report_stat_lock_relation
pg_stat_force_next_flush
------------------------
@@ -3936,9 +3936,9 @@ pg_stat_reset_shared
(1 row)
-step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s1_set_track_lock_timing: SET track_lock_timing = on;
step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
-step s2_unset_log_lock_waits: SET log_lock_waits = off;
+step s2_unset_track_lock_timing: SET track_lock_timing = off;
step s1_begin: BEGIN;
step s1_lock_relation: LOCK TABLE test_stat_tab;
step s2_begin: BEGIN;
diff --git a/src/test/isolation/specs/stats.spec b/src/test/isolation/specs/stats.spec
index 42be68c545f..81b45a801d9 100644
--- a/src/test/isolation/specs/stats.spec
+++ b/src/test/isolation/specs/stats.spec
@@ -132,7 +132,7 @@ step s1_slru_check_stats {
# Lock stats steps
step s1_set_deadlock_timeout { SET deadlock_timeout = '10ms'; }
-step s1_set_log_lock_waits { SET log_lock_waits = on; }
+step s1_set_track_lock_timing { SET track_lock_timing = on; }
step s1_reset_stat_lock { SELECT pg_stat_reset_shared('lock'); }
step s1_sleep { SELECT pg_sleep(0.5); }
step s1_lock_relation { LOCK TABLE test_stat_tab; }
@@ -174,8 +174,8 @@ step s2_big_notify { SELECT pg_notify('stats_test_use',
# Lock stats steps
step s2_set_deadlock_timeout { SET deadlock_timeout = '10ms'; }
-step s2_set_log_lock_waits { SET log_lock_waits = on; }
-step s2_unset_log_lock_waits { SET log_lock_waits = off; }
+step s2_set_track_lock_timing { SET track_lock_timing = on; }
+step s2_unset_track_lock_timing { SET track_lock_timing = off; }
step s2_report_stat_lock_relation { SELECT waits > 0, wait_time > 500 FROM pg_stat_lock WHERE locktype = 'relation'; }
step s2_report_stat_lock_transactionid { SELECT waits > 0, wait_time > 500 FROM pg_stat_lock WHERE locktype = 'transactionid'; }
step s2_report_stat_lock_advisory { SELECT waits > 0, wait_time > 500 FROM pg_stat_lock WHERE locktype = 'advisory'; }
@@ -793,9 +793,9 @@ permutation
permutation
s1_set_deadlock_timeout
s1_reset_stat_lock
- s1_set_log_lock_waits
+ s1_set_track_lock_timing
s2_set_deadlock_timeout
- s2_set_log_lock_waits
+ s2_set_track_lock_timing
s1_begin
s1_lock_relation
s2_begin
@@ -811,9 +811,9 @@ permutation
permutation
s1_set_deadlock_timeout
s1_reset_stat_lock
- s1_set_log_lock_waits
+ s1_set_track_lock_timing
s2_set_deadlock_timeout
- s2_set_log_lock_waits
+ s2_set_track_lock_timing
s1_table_insert
s1_begin
s1_table_update_k1
@@ -830,9 +830,9 @@ permutation
permutation
s1_set_deadlock_timeout
s1_reset_stat_lock
- s1_set_log_lock_waits
+ s1_set_track_lock_timing
s2_set_deadlock_timeout
- s2_set_log_lock_waits
+ s2_set_track_lock_timing
s1_lock_advisory_lock
s2_begin
s2_ff
@@ -843,14 +843,14 @@ permutation
s2_commit
s2_report_stat_lock_advisory
-# Ensure log_lock_waits behaves correctly
+# Ensure track_lock_timing behaves correctly
permutation
s1_set_deadlock_timeout
s1_reset_stat_lock
- s1_set_log_lock_waits
+ s1_set_track_lock_timing
s2_set_deadlock_timeout
- s2_unset_log_lock_waits
+ s2_unset_track_lock_timing
s1_begin
s1_lock_relation
s2_begin
--
2.34.1
--nK2xgkLTeiiswcxd--
view thread (5+ 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: pgsql-hackers@postgresql.org
Cc: bertranddrouvot.pg@gmail.com
Subject: Re: [PATCH v9 3/3] Introduce a new track_lock_timing GUC
In-Reply-To: <no-message-id-1836471@localhost>
* 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