public inbox for [email protected]
help / color / mirror / Atom feedRe: Adding locks statistics
26+ messages / 4 participants
[nested] [flat]
* Re: Adding locks statistics
@ 2026-02-20 16:02 Andres Freund <[email protected]>
0 siblings, 1 reply; 26+ messages in thread
From: Andres Freund @ 2026-02-20 16:02 UTC (permalink / raw)
To: Bertrand Drouvot <[email protected]>; +Cc: Michael Paquier <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
Hi,
On 2026-02-20 06:38:07 +0000, Bertrand Drouvot wrote:
> > If the delay is very
> > short it's probably also not that interesting to track, but I guess that's
> > debatable.
>
> v6 was introducing timed_waits so that we have:
>
> waits
> timed_waits
> wait_time
> fastpath_exceeded
>
> timed_waits and wait_time were incremented together and waits was incremented
> unconditionally. I like the idea of being able to track the numbers of waits
> whatever the value of log_lock_waits (or the new track_lock_timing) is. Also
> one could compare waits vs timed_waits.
How could a user benefit from that split? To me this is pointless number
gathering that wastes resources and confuses users.
Seriously, youre introducing stats left and right, you really need to stop and
first carefully think about what those stats could possibly be useful
for. Before writing a patch implementing the stats.
Greetings,
Andres Freund
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-02-20 17:26 Bertrand Drouvot <[email protected]>
parent: Andres Freund <[email protected]>
0 siblings, 1 reply; 26+ messages in thread
From: Bertrand Drouvot @ 2026-02-20 17:26 UTC (permalink / raw)
To: Andres Freund <[email protected]>; +Cc: Michael Paquier <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
Hi,
On Fri, Feb 20, 2026 at 11:02:49AM -0500, Andres Freund wrote:
> Hi,
>
> On 2026-02-20 06:38:07 +0000, Bertrand Drouvot wrote:
> > > If the delay is very
> > > short it's probably also not that interesting to track, but I guess that's
> > > debatable.
> >
> > v6 was introducing timed_waits so that we have:
> >
> > waits
> > timed_waits
> > wait_time
> > fastpath_exceeded
> >
> > timed_waits and wait_time were incremented together and waits was incremented
> > unconditionally. I like the idea of being able to track the numbers of waits
> > whatever the value of log_lock_waits (or the new track_lock_timing) is. Also
> > one could compare waits vs timed_waits.
>
> How could a user benefit from that split? To me this is pointless number
> gathering that wastes resources and confuses users.
I was thinking that could be useful to know the distribution between "long" waits
(greater than the deadlock timeout) among all the waits.
If the vast majority are long waits that may indicate that the application is
misbehaving (as opposed to a tiny percentage of long waits).
I was also thinking to bring those stats per-backend (as a next step) and that
could also probably be more useful (distribution per host for example, thanks to
joining with pg_stat_activity).
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-02-27 05:14 Bertrand Drouvot <[email protected]>
parent: Bertrand Drouvot <[email protected]>
0 siblings, 1 reply; 26+ messages in thread
From: Bertrand Drouvot @ 2026-02-27 05:14 UTC (permalink / raw)
To: Andres Freund <[email protected]>; +Cc: Michael Paquier <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
Hi,
On Fri, Feb 20, 2026 at 05:26:37PM +0000, Bertrand Drouvot wrote:
> Hi,
>
> On Fri, Feb 20, 2026 at 11:02:49AM -0500, Andres Freund wrote:
> > Hi,
> >
> > How could a user benefit from that split? To me this is pointless number
> > gathering that wastes resources and confuses users.
>
> I was thinking that could be useful to know the distribution between "long" waits
> (greater than the deadlock timeout) among all the waits.
>
> If the vast majority are long waits that may indicate that the application is
> misbehaving (as opposed to a tiny percentage of long waits).
>
> I was also thinking to bring those stats per-backend (as a next step) and that
> could also probably be more useful (distribution per host for example, thanks to
> joining with pg_stat_activity).
As it seems that I'm the only one thinking that this split could be useful, I'm
removing it in the attached. We can still split later on if we have requests from
the field.
So, we're back to what we were discussing before the split. As in v7, 0003 is
adding the new GUC. So that we can see what having a new GUC implies in ProcSleep()
and we can just get rid of 0003 if we think the GUC is not worth the extra complexity
(I don't have a strong opinion on it but tempted to think that the extra GUC is
not worth it).
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
Attachments:
[text/x-diff] v8-0001-Add-lock-statistics.patch (15.6K, 2-v8-0001-Add-lock-statistics.patch)
download | inline diff:
From bae7e839d430dbea957dea316038b9bc52688170 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <[email protected]>
Date: Tue, 29 Jul 2025 08:36:35 +0000
Subject: [PATCH v8 1/3] Add lock statistics
Adding a new stat kind PGSTAT_KIND_LOCK for the lock statistics.
This new statistic kind is a fixed one because its key is the lock type
so that we know its size is LOCKTAG_LAST_TYPE + 1.
This statistic kind records the following counters:
waits
wait_time
fastpath_exceeded
The waits and wait_time counters are incremented if log_lock_waits is on
and the session waited longer than deadlock_timeout to acquire the lock.
fastpath_exceeded is incremented when the lock can not be acquired via fast path
because the fast path slot limit was exceeded.
No extra details is added (like the ones, i.e relation oid, database oid, we
can find in pg_locks). The idea is to provide an idea on what the locking
behaviour looks like.
XXX: Bump stat file format
---
src/backend/storage/lmgr/lock.c | 58 ++++----
src/backend/storage/lmgr/proc.c | 6 +
src/backend/utils/activity/Makefile | 1 +
src/backend/utils/activity/meson.build | 1 +
src/backend/utils/activity/pgstat.c | 18 +++
src/backend/utils/activity/pgstat_lock.c | 160 +++++++++++++++++++++++
src/include/pgstat.h | 27 ++++
src/include/utils/pgstat_internal.h | 21 +++
src/include/utils/pgstat_kind.h | 5 +-
src/tools/pgindent/typedefs.list | 4 +
10 files changed, 273 insertions(+), 28 deletions(-)
28.7% src/backend/storage/lmgr/
55.2% src/backend/utils/activity/
7.5% src/include/utils/
7.6% src/include/
diff --git a/src/backend/storage/lmgr/lock.c b/src/backend/storage/lmgr/lock.c
index d930c66cdbd..b2d597bfd1e 100644
--- a/src/backend/storage/lmgr/lock.c
+++ b/src/backend/storage/lmgr/lock.c
@@ -39,6 +39,7 @@
#include "access/xlogutils.h"
#include "miscadmin.h"
#include "pg_trace.h"
+#include "pgstat.h"
#include "storage/lmgr.h"
#include "storage/proc.h"
#include "storage/procarray.h"
@@ -984,37 +985,42 @@ LockAcquireExtended(const LOCKTAG *locktag,
* lock type on a relation we have already locked using the fast-path, but
* for now we don't worry about that case either.
*/
- if (EligibleForRelationFastPath(locktag, lockmode) &&
- FastPathLocalUseCounts[FAST_PATH_REL_GROUP(locktag->locktag_field2)] < FP_LOCK_SLOTS_PER_GROUP)
+ if (EligibleForRelationFastPath(locktag, lockmode))
{
- uint32 fasthashcode = FastPathStrongLockHashPartition(hashcode);
- bool acquired;
-
- /*
- * LWLockAcquire acts as a memory sequencing point, so it's safe to
- * assume that any strong locker whose increment to
- * FastPathStrongRelationLocks->counts becomes visible after we test
- * it has yet to begin to transfer fast-path locks.
- */
- LWLockAcquire(&MyProc->fpInfoLock, LW_EXCLUSIVE);
- if (FastPathStrongRelationLocks->count[fasthashcode] != 0)
- acquired = false;
- else
- acquired = FastPathGrantRelationLock(locktag->locktag_field2,
- lockmode);
- LWLockRelease(&MyProc->fpInfoLock);
- if (acquired)
+ if (FastPathLocalUseCounts[FAST_PATH_REL_GROUP(locktag->locktag_field2)] <
+ FP_LOCK_SLOTS_PER_GROUP)
{
+ uint32 fasthashcode = FastPathStrongLockHashPartition(hashcode);
+ bool acquired;
+
/*
- * The locallock might contain stale pointers to some old shared
- * objects; we MUST reset these to null before considering the
- * lock to be acquired via fast-path.
+ * LWLockAcquire acts as a memory sequencing point, so it's safe
+ * to assume that any strong locker whose increment to
+ * FastPathStrongRelationLocks->counts becomes visible after we
+ * test it has yet to begin to transfer fast-path locks.
*/
- locallock->lock = NULL;
- locallock->proclock = NULL;
- GrantLockLocal(locallock, owner);
- return LOCKACQUIRE_OK;
+ LWLockAcquire(&MyProc->fpInfoLock, LW_EXCLUSIVE);
+ if (FastPathStrongRelationLocks->count[fasthashcode] != 0)
+ acquired = false;
+ else
+ acquired = FastPathGrantRelationLock(locktag->locktag_field2,
+ lockmode);
+ LWLockRelease(&MyProc->fpInfoLock);
+ if (acquired)
+ {
+ /*
+ * The locallock might contain stale pointers to some old
+ * shared objects; we MUST reset these to null before
+ * considering the lock to be acquired via fast-path.
+ */
+ locallock->lock = NULL;
+ locallock->proclock = NULL;
+ GrantLockLocal(locallock, owner);
+ return LOCKACQUIRE_OK;
+ }
}
+ else
+ pgstat_count_lock_fastpath_exceeded(locallock->tag.lock.locktag_type);
}
/*
diff --git a/src/backend/storage/lmgr/proc.c b/src/backend/storage/lmgr/proc.c
index 771b006b522..e38c8820103 100644
--- a/src/backend/storage/lmgr/proc.c
+++ b/src/backend/storage/lmgr/proc.c
@@ -1611,9 +1611,15 @@ ProcSleep(LOCALLOCK *locallock)
"Processes holding the lock: %s. Wait queue: %s.",
lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data))));
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);
diff --git a/src/backend/utils/activity/Makefile b/src/backend/utils/activity/Makefile
index c37bfb350bb..ca3ef89bf59 100644
--- a/src/backend/utils/activity/Makefile
+++ b/src/backend/utils/activity/Makefile
@@ -26,6 +26,7 @@ OBJS = \
pgstat_database.o \
pgstat_function.o \
pgstat_io.o \
+ pgstat_lock.o \
pgstat_relation.o \
pgstat_replslot.o \
pgstat_shmem.o \
diff --git a/src/backend/utils/activity/meson.build b/src/backend/utils/activity/meson.build
index 53bd5a246ca..1aa7ece5290 100644
--- a/src/backend/utils/activity/meson.build
+++ b/src/backend/utils/activity/meson.build
@@ -11,6 +11,7 @@ backend_sources += files(
'pgstat_database.c',
'pgstat_function.c',
'pgstat_io.c',
+ 'pgstat_lock.c',
'pgstat_relation.c',
'pgstat_replslot.c',
'pgstat_shmem.c',
diff --git a/src/backend/utils/activity/pgstat.c b/src/backend/utils/activity/pgstat.c
index 11bb71cad5a..eb8ccbaa628 100644
--- a/src/backend/utils/activity/pgstat.c
+++ b/src/backend/utils/activity/pgstat.c
@@ -83,6 +83,7 @@
* - pgstat_database.c
* - pgstat_function.c
* - pgstat_io.c
+ * - pgstat_lock.c
* - pgstat_relation.c
* - pgstat_replslot.c
* - pgstat_slru.c
@@ -448,6 +449,23 @@ static const PgStat_KindInfo pgstat_kind_builtin_infos[PGSTAT_KIND_BUILTIN_SIZE]
.snapshot_cb = pgstat_io_snapshot_cb,
},
+ [PGSTAT_KIND_LOCK] = {
+ .name = "lock",
+
+ .fixed_amount = true,
+ .write_to_file = true,
+
+ .snapshot_ctl_off = offsetof(PgStat_Snapshot, lock),
+ .shared_ctl_off = offsetof(PgStat_ShmemControl, lock),
+ .shared_data_off = offsetof(PgStatShared_Lock, stats),
+ .shared_data_len = sizeof(((PgStatShared_Lock *) 0)->stats),
+
+ .flush_static_cb = pgstat_lock_flush_cb,
+ .init_shmem_cb = pgstat_lock_init_shmem_cb,
+ .reset_all_cb = pgstat_lock_reset_all_cb,
+ .snapshot_cb = pgstat_lock_snapshot_cb,
+ },
+
[PGSTAT_KIND_SLRU] = {
.name = "slru",
diff --git a/src/backend/utils/activity/pgstat_lock.c b/src/backend/utils/activity/pgstat_lock.c
new file mode 100644
index 00000000000..91a53a6013a
--- /dev/null
+++ b/src/backend/utils/activity/pgstat_lock.c
@@ -0,0 +1,160 @@
+/* -------------------------------------------------------------------------
+ *
+ * pgstat_lock.c
+ * Implementation of lock statistics.
+ *
+ * This file contains the implementation of lock statistics. It is kept separate
+ * from pgstat.c to enforce the line between the statistics access / storage
+ * implementation and the details about individual types of statistics.
+ *
+ * Copyright (c) 2021-2025, PostgreSQL Global Development Group
+ *
+ * IDENTIFICATION
+ * src/backend/utils/activity/pgstat_lock.c
+ * -------------------------------------------------------------------------
+ */
+
+#include "postgres.h"
+
+#include "utils/pgstat_internal.h"
+
+static PgStat_PendingLock PendingLockStats;
+static bool have_lockstats = false;
+
+/*
+ * Simpler wrapper of pgstat_lock_flush_cb()
+ */
+void
+pgstat_lock_flush(bool nowait)
+{
+ (void) pgstat_lock_flush_cb(nowait);
+}
+
+/*
+ * Flush out locally pending lock statistics
+ *
+ * If no stats have been recorded, this function returns false.
+ *
+ * If nowait is true, this function returns true if the lock could not be
+ * acquired. Otherwise, return false.
+ */
+bool
+pgstat_lock_flush_cb(bool nowait)
+{
+ LWLock *lcktype_lock;
+ PgStat_LockEntry *lck_shstats;
+ bool lock_not_acquired = false;
+
+ if (!have_lockstats)
+ return false;
+
+ for (int i = 0; i <= LOCKTAG_LAST_TYPE; i++)
+ {
+ lcktype_lock = &pgStatLocal.shmem->lock.locks[i];
+ lck_shstats =
+ &pgStatLocal.shmem->lock.stats.stats[i];
+
+ if (!nowait)
+ LWLockAcquire(lcktype_lock, LW_EXCLUSIVE);
+ else if (!LWLockConditionalAcquire(lcktype_lock, LW_EXCLUSIVE))
+ {
+ lock_not_acquired = true;
+ continue;
+ }
+
+#define LOCKSTAT_ACC(fld) \
+ (lck_shstats->fld += PendingLockStats.stats[i].fld)
+ LOCKSTAT_ACC(waits);
+ LOCKSTAT_ACC(wait_time);
+ LOCKSTAT_ACC(fastpath_exceeded);
+#undef LOCKSTAT_ACC
+
+ LWLockRelease(lcktype_lock);
+ }
+
+ memset(&PendingLockStats, 0, sizeof(PendingLockStats));
+
+ have_lockstats = false;
+
+ return lock_not_acquired;
+}
+
+
+void
+pgstat_lock_init_shmem_cb(void *stats)
+{
+ PgStatShared_Lock *stat_shmem = (PgStatShared_Lock *) stats;
+
+ for (int i = 0; i <= LOCKTAG_LAST_TYPE; i++)
+ LWLockInitialize(&stat_shmem->locks[i], LWTRANCHE_PGSTATS_DATA);
+}
+
+void
+pgstat_lock_reset_all_cb(TimestampTz ts)
+{
+ for (int i = 0; i <= LOCKTAG_LAST_TYPE; i++)
+ {
+ LWLock *lcktype_lock = &pgStatLocal.shmem->lock.locks[i];
+ PgStat_LockEntry *lck_shstats = &pgStatLocal.shmem->lock.stats.stats[i];
+
+ LWLockAcquire(lcktype_lock, LW_EXCLUSIVE);
+
+ /*
+ * Use the lock in the first lock type PgStat_LockEntry to protect the
+ * reset timestamp as well.
+ */
+ if (i == 0)
+ pgStatLocal.shmem->lock.stats.stat_reset_timestamp = ts;
+
+ memset(lck_shstats, 0, sizeof(*lck_shstats));
+ LWLockRelease(lcktype_lock);
+ }
+}
+
+void
+pgstat_lock_snapshot_cb(void)
+{
+ for (int i = 0; i <= LOCKTAG_LAST_TYPE; i++)
+ {
+ LWLock *lcktype_lock = &pgStatLocal.shmem->lock.locks[i];
+ PgStat_LockEntry *lck_shstats = &pgStatLocal.shmem->lock.stats.stats[i];
+ PgStat_LockEntry *lck_snap = &pgStatLocal.snapshot.lock.stats[i];
+
+ LWLockAcquire(lcktype_lock, LW_SHARED);
+
+ /*
+ * Use the lock in the first lock type PgStat_LockEntry to protect the
+ * reset timestamp as well.
+ */
+ if (i == 0)
+ pgStatLocal.snapshot.lock.stat_reset_timestamp =
+ pgStatLocal.shmem->lock.stats.stat_reset_timestamp;
+
+ /* using struct assignment due to better type safety */
+ *lck_snap = *lck_shstats;
+ LWLockRelease(lcktype_lock);
+ }
+}
+
+#define PGSTAT_COUNT_LOCK_FUNC(stat) \
+void \
+CppConcat(pgstat_count_lock_,stat)(uint8 locktag_type) \
+{ \
+ Assert(locktag_type <= LOCKTAG_LAST_TYPE); \
+ PendingLockStats.stats[locktag_type].stat++; \
+ have_lockstats = true; \
+ pgstat_report_fixed = true; \
+}
+
+/* pgstat_count_lock_fastpath_exceeded */
+PGSTAT_COUNT_LOCK_FUNC(fastpath_exceeded)
+
+void
+pgstat_count_lock_waits(uint8 locktag_type, long msecs)
+{
+ Assert(locktag_type <= LOCKTAG_LAST_TYPE);
+ PendingLockStats.stats[locktag_type].waits++;
+ PendingLockStats.stats[locktag_type].wait_time += (PgStat_Counter) msecs;
+ have_lockstats = true;
+ pgstat_report_fixed = true;
+}
diff --git a/src/include/pgstat.h b/src/include/pgstat.h
index 0e9d2b4c623..f563132bf7b 100644
--- a/src/include/pgstat.h
+++ b/src/include/pgstat.h
@@ -15,6 +15,7 @@
#include "portability/instr_time.h"
#include "postmaster/pgarch.h" /* for MAX_XFN_CHARS */
#include "replication/conflict.h"
+#include "storage/lock.h"
#include "utils/backend_progress.h" /* for backward compatibility */ /* IWYU pragma: export */
#include "utils/backend_status.h" /* for backward compatibility */ /* IWYU pragma: export */
#include "utils/pgstat_kind.h"
@@ -346,6 +347,24 @@ typedef struct PgStat_IO
PgStat_BktypeIO stats[BACKEND_NUM_TYPES];
} PgStat_IO;
+typedef struct PgStat_LockEntry
+{
+ PgStat_Counter waits;
+ PgStat_Counter wait_time; /* time in milliseconds */
+ PgStat_Counter fastpath_exceeded;
+} PgStat_LockEntry;
+
+typedef struct PgStat_PendingLock
+{
+ PgStat_LockEntry stats[LOCKTAG_LAST_TYPE + 1];
+} PgStat_PendingLock;
+
+typedef struct PgStat_Lock
+{
+ TimestampTz stat_reset_timestamp;
+ PgStat_LockEntry stats[LOCKTAG_LAST_TYPE + 1];
+} PgStat_Lock;
+
typedef struct PgStat_StatDBEntry
{
PgStat_Counter xact_commit;
@@ -618,6 +637,14 @@ extern bool pgstat_tracks_io_op(BackendType bktype, IOObject io_object,
IOContext io_context, IOOp io_op);
+/*
+ * Functions in pgstat_lock.c
+ */
+
+extern void pgstat_lock_flush(bool nowait);
+extern void pgstat_count_lock_fastpath_exceeded(uint8 locktag_type);
+extern void pgstat_count_lock_waits(uint8 locktag_type, long msecs);
+
/*
* Functions in pgstat_database.c
*/
diff --git a/src/include/utils/pgstat_internal.h b/src/include/utils/pgstat_internal.h
index 9b8fbae00ed..97704421a92 100644
--- a/src/include/utils/pgstat_internal.h
+++ b/src/include/utils/pgstat_internal.h
@@ -464,6 +464,16 @@ typedef struct PgStatShared_IO
PgStat_IO stats;
} PgStatShared_IO;
+typedef struct PgStatShared_Lock
+{
+ /*
+ * locks[i] protects stats.stats[i]. locks[0] also protects
+ * stats.stat_reset_timestamp.
+ */
+ LWLock locks[LOCKTAG_LAST_TYPE + 1];
+ PgStat_Lock stats;
+} PgStatShared_Lock;
+
typedef struct PgStatShared_SLRU
{
/* lock protects ->stats */
@@ -570,6 +580,7 @@ typedef struct PgStat_ShmemControl
PgStatShared_BgWriter bgwriter;
PgStatShared_Checkpointer checkpointer;
PgStatShared_IO io;
+ PgStatShared_Lock lock;
PgStatShared_SLRU slru;
PgStatShared_Wal wal;
@@ -602,6 +613,8 @@ typedef struct PgStat_Snapshot
PgStat_IO io;
+ PgStat_Lock lock;
+
PgStat_SLRUStats slru[SLRU_NUM_ELEMENTS];
PgStat_WalStats wal;
@@ -752,6 +765,14 @@ extern void pgstat_io_init_shmem_cb(void *stats);
extern void pgstat_io_reset_all_cb(TimestampTz ts);
extern void pgstat_io_snapshot_cb(void);
+/*
+ * Functions in pgstat_lock.c
+ */
+
+extern bool pgstat_lock_flush_cb(bool nowait);
+extern void pgstat_lock_init_shmem_cb(void *stats);
+extern void pgstat_lock_reset_all_cb(TimestampTz ts);
+extern void pgstat_lock_snapshot_cb(void);
/*
* Functions in pgstat_relation.c
diff --git a/src/include/utils/pgstat_kind.h b/src/include/utils/pgstat_kind.h
index c30b6235623..2d78a029683 100644
--- a/src/include/utils/pgstat_kind.h
+++ b/src/include/utils/pgstat_kind.h
@@ -36,8 +36,9 @@
#define PGSTAT_KIND_BGWRITER 8
#define PGSTAT_KIND_CHECKPOINTER 9
#define PGSTAT_KIND_IO 10
-#define PGSTAT_KIND_SLRU 11
-#define PGSTAT_KIND_WAL 12
+#define PGSTAT_KIND_LOCK 11
+#define PGSTAT_KIND_SLRU 12
+#define PGSTAT_KIND_WAL 13
#define PGSTAT_KIND_BUILTIN_MIN PGSTAT_KIND_DATABASE
#define PGSTAT_KIND_BUILTIN_MAX PGSTAT_KIND_WAL
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index 1a89ef94bec..b4de923667f 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -2256,6 +2256,7 @@ PgStatShared_Database
PgStatShared_Function
PgStatShared_HashEntry
PgStatShared_IO
+PgStatShared_Lock
PgStatShared_Relation
PgStatShared_ReplSlot
PgStatShared_SLRU
@@ -2278,8 +2279,11 @@ PgStat_HashKey
PgStat_IO
PgStat_KindInfo
PgStat_LocalState
+PgStat_Lock
+PgStat_LockEntry
PgStat_PendingDroppedStatsItem
PgStat_PendingIO
+PgStat_PendingLock
PgStat_SLRUStats
PgStat_ShmemControl
PgStat_Snapshot
--
2.34.1
[text/x-diff] v8-0002-Add-the-pg_stat_lock-view.patch (29.9K, 3-v8-0002-Add-the-pg_stat_lock-view.patch)
download | inline diff:
From e71db2d88480f5a1a300c8c73b4428bfe5d5d877 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <[email protected]>
Date: Thu, 31 Jul 2025 09:35:31 +0000
Subject: [PATCH v8 2/3] Add the pg_stat_lock view
This new view reports lock statistics.
Note that it does not omit combinations which do not make sense (as pg_locks
does).
Also wait_time is reported as bigint as the deadlock_timeout default value is
1s.
This commit also adds documentation and a few tests.
XXX: Bump catversion
---
doc/src/sgml/monitoring.sgml | 113 ++++++++++++++
src/backend/catalog/system_views.sql | 9 ++
src/backend/utils/activity/pgstat_lock.c | 8 +
src/backend/utils/adt/pgstatfuncs.c | 39 +++++
src/include/catalog/pg_proc.dat | 9 ++
src/include/pgstat.h | 1 +
src/test/isolation/expected/stats.out | 189 +++++++++++++++++++++++
src/test/isolation/expected/stats_1.out | 189 +++++++++++++++++++++++
src/test/isolation/specs/stats.spec | 95 ++++++++++++
src/test/regress/expected/rules.out | 6 +
src/test/regress/expected/stats.out | 48 ++++++
src/test/regress/sql/stats.sql | 36 +++++
12 files changed, 742 insertions(+)
15.9% doc/src/sgml/
5.0% src/backend/utils/adt/
54.1% src/test/isolation/expected/
11.3% src/test/isolation/specs/
5.7% src/test/regress/expected/
4.0% src/test/regress/sql/
3.6% src/
diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml
index b77d189a500..3a196bc305c 100644
--- a/doc/src/sgml/monitoring.sgml
+++ b/doc/src/sgml/monitoring.sgml
@@ -493,6 +493,15 @@ postgres 27093 0.0 0.0 30096 2752 ? Ss 11:34 0:00 postgres: ser
</entry>
</row>
+ <row>
+ <entry><structname>pg_stat_lock</structname><indexterm><primary>pg_stat_lock</primary></indexterm></entry>
+ <entry>
+ One row for each lock type, containing cluster-wide locks statistics.
+ See <link linkend="monitoring-pg-stat-lock-view">
+ <structname>pg_stat_lock</structname></link> for details.
+ </entry>
+ </row>
+
<row>
<entry><structname>pg_stat_replication_slots</structname><indexterm><primary>pg_stat_replication_slots</primary></indexterm></entry>
<entry>One row per replication slot, showing statistics about the
@@ -3124,6 +3133,104 @@ description | Waiting for a newly initialized WAL file to reach durable storage
</sect2>
+
+ <sect2 id="monitoring-pg-stat-lock-view">
+ <title><structname>pg_stat_lock</structname></title>
+
+ <indexterm>
+ <primary>pg_stat_lock</primary>
+ </indexterm>
+
+ <para>
+ The <structname>pg_stat_lock</structname> view will contain one row for each
+ lock type, showing cluster-wide locks statistics.
+ </para>
+
+ <table id="pg-stat-lock-view" xreflabel="pg_stat_lock">
+ <title><structname>pg_stat_lock</structname> View</title>
+ <tgroup cols="1">
+ <thead>
+ <row>
+ <entry role="catalog_table_entry">
+ <para role="column_definition">
+ Column Type
+ </para>
+ <para>
+ Description
+ </para>
+ </entry>
+ </row>
+ </thead>
+ <tbody>
+ <row>
+ <entry role="catalog_table_entry">
+ <para role="column_definition">
+ <structfield>locktype</structfield> <type>text</type>
+ </para>
+ <para>
+ Type of the lockable object. See <link linkend="view-pg-locks">
+ <structname>pg_locks</structname></link> for details.
+ </para>
+ </entry>
+ </row>
+
+ <row>
+ <entry role="catalog_table_entry">
+ <para role="column_definition">
+ <structfield>waits</structfield> <type>bigint</type>
+ </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"/>
+ is enabled and the lock was successfully acquired after waiting longer
+ than <xref linkend="guc-deadlock-timeout"/>.
+ </para>
+ </entry>
+ </row>
+
+ <row>
+ <entry role="catalog_table_entry">
+ <para role="column_definition">
+ <structfield>wait_time</structfield> <type>bigint</type>
+ </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
+ the lock was successfully acquired after waiting longer than
+ <xref linkend="guc-deadlock-timeout"/>.
+ </para>
+ </entry>
+ </row>
+
+ <row>
+ <entry role="catalog_table_entry">
+ <para role="column_definition">
+ <structfield>fastpath_exceeded</structfield> <type>bigint</type>
+ </para>
+ <para>
+ Number of times a lock of this type could not be acquired via fast path
+ because the fast path slot limit was exceeded. You may want to increase
+ <xref linkend="guc-max-locks-per-transaction"/> if you feel this counter
+ is too high.
+ </para>
+ </entry>
+ </row>
+
+ <row>
+ <entry role="catalog_table_entry">
+ <para role="column_definition">
+ <structfield>stats_reset</structfield> <type>timestamp with time zone</type>
+ </para>
+ <para>
+ Time at which these statistics were last reset.
+ </para>
+ </entry>
+ </row>
+ </tbody>
+ </tgroup>
+ </table>
+ </sect2>
+
<sect2 id="monitoring-pg-stat-bgwriter-view">
<title><structname>pg_stat_bgwriter</structname></title>
@@ -5195,6 +5302,12 @@ description | Waiting for a newly initialized WAL file to reach durable storage
<structname>pg_stat_io</structname> view.
</para>
</listitem>
+ <listitem>
+ <para>
+ <literal>lock</literal>: Reset all the counters shown in the
+ <structname>pg_stat_lock</structname> view.
+ </para>
+ </listitem>
<listitem>
<para>
<literal>recovery_prefetch</literal>: Reset all the counters shown in
diff --git a/src/backend/catalog/system_views.sql b/src/backend/catalog/system_views.sql
index 1ea8f1faa9e..22efeb713e4 100644
--- a/src/backend/catalog/system_views.sql
+++ b/src/backend/catalog/system_views.sql
@@ -985,6 +985,15 @@ CREATE VIEW pg_stat_slru AS
s.stats_reset
FROM pg_stat_get_slru() s;
+CREATE VIEW pg_stat_lock AS
+ SELECT
+ l.locktype,
+ l.waits,
+ l.wait_time,
+ l.fastpath_exceeded,
+ l.stats_reset
+ FROM pg_stat_get_lock() l;
+
CREATE VIEW pg_stat_wal_receiver AS
SELECT
s.pid,
diff --git a/src/backend/utils/activity/pgstat_lock.c b/src/backend/utils/activity/pgstat_lock.c
index 91a53a6013a..954fa51c3e0 100644
--- a/src/backend/utils/activity/pgstat_lock.c
+++ b/src/backend/utils/activity/pgstat_lock.c
@@ -21,6 +21,14 @@
static PgStat_PendingLock PendingLockStats;
static bool have_lockstats = false;
+PgStat_Lock *
+pgstat_fetch_stat_lock(void)
+{
+ pgstat_snapshot_fixed(PGSTAT_KIND_LOCK);
+
+ return &pgStatLocal.snapshot.lock;
+}
+
/*
* Simpler wrapper of pgstat_lock_flush_cb()
*/
diff --git a/src/backend/utils/adt/pgstatfuncs.c b/src/backend/utils/adt/pgstatfuncs.c
index b1df96e7b0b..27ca2d8f07c 100644
--- a/src/backend/utils/adt/pgstatfuncs.c
+++ b/src/backend/utils/adt/pgstatfuncs.c
@@ -1737,6 +1737,42 @@ pg_stat_get_wal(PG_FUNCTION_ARGS)
wal_stats->stat_reset_timestamp));
}
+Datum
+pg_stat_get_lock(PG_FUNCTION_ARGS)
+{
+#define PG_STAT_LOCK_COLS 5
+ ReturnSetInfo *rsinfo;
+ PgStat_Lock *lock_stats;
+
+ InitMaterializedSRF(fcinfo, 0);
+ rsinfo = (ReturnSetInfo *) fcinfo->resultinfo;
+
+ lock_stats = pgstat_fetch_stat_lock();
+
+ for (int lcktype = 0; lcktype <= LOCKTAG_LAST_TYPE; lcktype++)
+ {
+ const char *locktypename;
+ Datum values[PG_STAT_LOCK_COLS] = {0};
+ bool nulls[PG_STAT_LOCK_COLS] = {0};
+ PgStat_LockEntry *lck_stats = &lock_stats->stats[lcktype];
+ int i = 0;
+
+ locktypename = LockTagTypeNames[lcktype];
+
+ values[i++] = CStringGetTextDatum(locktypename);
+ values[i++] = Int64GetDatum(lck_stats->waits);
+ values[i++] = Int64GetDatum(lck_stats->wait_time);
+ values[i++] = Int64GetDatum(lck_stats->fastpath_exceeded);
+ values[i] = TimestampTzGetDatum(lock_stats->stat_reset_timestamp);
+
+ Assert(i + 1 == PG_STAT_LOCK_COLS);
+
+ tuplestore_putvalues(rsinfo->setResult, rsinfo->setDesc, values, nulls);
+ }
+
+ return (Datum) 0;
+}
+
/*
* Returns statistics of SLRU caches.
*/
@@ -1921,6 +1957,7 @@ pg_stat_reset_shared(PG_FUNCTION_ARGS)
pgstat_reset_of_kind(PGSTAT_KIND_BGWRITER);
pgstat_reset_of_kind(PGSTAT_KIND_CHECKPOINTER);
pgstat_reset_of_kind(PGSTAT_KIND_IO);
+ pgstat_reset_of_kind(PGSTAT_KIND_LOCK);
XLogPrefetchResetStats();
pgstat_reset_of_kind(PGSTAT_KIND_SLRU);
pgstat_reset_of_kind(PGSTAT_KIND_WAL);
@@ -1938,6 +1975,8 @@ pg_stat_reset_shared(PG_FUNCTION_ARGS)
pgstat_reset_of_kind(PGSTAT_KIND_CHECKPOINTER);
else if (strcmp(target, "io") == 0)
pgstat_reset_of_kind(PGSTAT_KIND_IO);
+ else if (strcmp(target, "lock") == 0)
+ pgstat_reset_of_kind(PGSTAT_KIND_LOCK);
else if (strcmp(target, "recovery_prefetch") == 0)
XLogPrefetchResetStats();
else if (strcmp(target, "slru") == 0)
diff --git a/src/include/catalog/pg_proc.dat b/src/include/catalog/pg_proc.dat
index dac40992cbc..daeb45704c6 100644
--- a/src/include/catalog/pg_proc.dat
+++ b/src/include/catalog/pg_proc.dat
@@ -6027,6 +6027,15 @@
proargnames => '{backend_type,object,context,reads,read_bytes,read_time,writes,write_bytes,write_time,writebacks,writeback_time,extends,extend_bytes,extend_time,hits,evictions,reuses,fsyncs,fsync_time,stats_reset}',
prosrc => 'pg_stat_get_io' },
+{ oid => '9375', descr => 'statistics: per lock type statistics',
+ proname => 'pg_stat_get_lock', prorows => '10', proretset => 't',
+ provolatile => 'v', proparallel => 'r', prorettype => 'record',
+ proargtypes => '',
+ proallargtypes => '{text,int8,int8,int8,timestamptz}',
+ proargmodes => '{o,o,o,o,o}',
+ proargnames => '{locktype,waits,wait_time,fastpath_exceeded,stats_reset}',
+ prosrc => 'pg_stat_get_lock' },
+
{ oid => '6386', descr => 'statistics: backend IO statistics',
proname => 'pg_stat_get_backend_io', prorows => '5', proretset => 't',
provolatile => 'v', proparallel => 'r', prorettype => 'record',
diff --git a/src/include/pgstat.h b/src/include/pgstat.h
index f563132bf7b..1c261e2c7a8 100644
--- a/src/include/pgstat.h
+++ b/src/include/pgstat.h
@@ -644,6 +644,7 @@ extern bool pgstat_tracks_io_op(BackendType bktype, IOObject io_object,
extern void pgstat_lock_flush(bool nowait);
extern void pgstat_count_lock_fastpath_exceeded(uint8 locktag_type);
extern void pgstat_count_lock_waits(uint8 locktag_type, long msecs);
+extern PgStat_Lock *pgstat_fetch_stat_lock(void);
/*
* Functions in pgstat_database.c
diff --git a/src/test/isolation/expected/stats.out b/src/test/isolation/expected/stats.out
index cfad309ccf3..3cae3052e40 100644
--- a/src/test/isolation/expected/stats.out
+++ b/src/test/isolation/expected/stats.out
@@ -3751,3 +3751,192 @@ test_stat_func| 1|t |t
(1 row)
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
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s1_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s1_reset_stat_lock: SELECT pg_stat_reset_shared('lock');
+pg_stat_reset_shared
+--------------------
+
+(1 row)
+
+step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s2_set_log_lock_waits: SET log_lock_waits = on;
+step s1_begin: BEGIN;
+step s1_lock_relation: LOCK TABLE test_stat_tab;
+step s2_begin: BEGIN;
+step s2_ff: SELECT pg_stat_force_next_flush();
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s2_lock_relation: LOCK TABLE test_stat_tab; <waiting ...>
+step s1_sleep: SELECT pg_sleep(0.5);
+pg_sleep
+--------
+
+(1 row)
+
+step s1_commit: COMMIT;
+step s2_lock_relation: <... completed>
+step s2_commit: COMMIT;
+step s2_report_stat_lock_relation: SELECT waits > 0, wait_time > 500 FROM pg_stat_lock WHERE locktype = 'relation';
+?column?|?column?
+--------+--------
+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
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s1_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s1_reset_stat_lock: SELECT pg_stat_reset_shared('lock');
+pg_stat_reset_shared
+--------------------
+
+(1 row)
+
+step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s2_set_log_lock_waits: SET log_lock_waits = 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';
+step s2_begin: BEGIN;
+step s2_ff: SELECT pg_stat_force_next_flush();
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s2_table_update_k1: UPDATE test_stat_tab SET value = value + 1 WHERE key = 'k1'; <waiting ...>
+step s1_sleep: SELECT pg_sleep(0.5);
+pg_sleep
+--------
+
+(1 row)
+
+step s1_commit: COMMIT;
+step s2_table_update_k1: <... completed>
+step s2_commit: COMMIT;
+step s2_report_stat_lock_transactionid: SELECT waits > 0, wait_time > 500 FROM pg_stat_lock WHERE locktype = 'transactionid';
+?column?|?column?
+--------+--------
+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
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s1_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s1_reset_stat_lock: SELECT pg_stat_reset_shared('lock');
+pg_stat_reset_shared
+--------------------
+
+(1 row)
+
+step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s2_set_log_lock_waits: SET log_lock_waits = on;
+step s1_lock_advisory_lock: SELECT pg_advisory_lock(1);
+pg_advisory_lock
+----------------
+
+(1 row)
+
+step s2_begin: BEGIN;
+step s2_ff: SELECT pg_stat_force_next_flush();
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s2_lock_advisory_lock: SELECT pg_advisory_lock(1); <waiting ...>
+step s1_sleep: SELECT pg_sleep(0.5);
+pg_sleep
+--------
+
+(1 row)
+
+step s1_lock_advisory_unlock: SELECT pg_advisory_unlock(1);
+pg_advisory_unlock
+------------------
+t
+(1 row)
+
+step s2_lock_advisory_lock: <... completed>
+pg_advisory_lock
+----------------
+
+(1 row)
+
+step s2_lock_advisory_unlock: SELECT pg_advisory_unlock(1);
+pg_advisory_unlock
+------------------
+t
+(1 row)
+
+step s2_commit: COMMIT;
+step s2_report_stat_lock_advisory: SELECT waits > 0, wait_time > 500 FROM pg_stat_lock WHERE locktype = 'advisory';
+?column?|?column?
+--------+--------
+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
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s1_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s1_reset_stat_lock: SELECT pg_stat_reset_shared('lock');
+pg_stat_reset_shared
+--------------------
+
+(1 row)
+
+step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s2_unset_log_lock_waits: SET log_lock_waits = off;
+step s1_begin: BEGIN;
+step s1_lock_relation: LOCK TABLE test_stat_tab;
+step s2_begin: BEGIN;
+step s2_ff: SELECT pg_stat_force_next_flush();
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s2_lock_relation: LOCK TABLE test_stat_tab; <waiting ...>
+step s1_sleep: SELECT pg_sleep(0.5);
+pg_sleep
+--------
+
+(1 row)
+
+step s1_commit: COMMIT;
+step s2_lock_relation: <... completed>
+step s2_commit: COMMIT;
+step s2_report_stat_lock_relation: SELECT waits > 0, wait_time > 500 FROM pg_stat_lock WHERE locktype = 'relation';
+?column?|?column?
+--------+--------
+f |f
+(1 row)
+
diff --git a/src/test/isolation/expected/stats_1.out b/src/test/isolation/expected/stats_1.out
index e1d937784cb..ea4fd97a9a5 100644
--- a/src/test/isolation/expected/stats_1.out
+++ b/src/test/isolation/expected/stats_1.out
@@ -3775,3 +3775,192 @@ test_stat_func| 1|t |t
(1 row)
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
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s1_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s1_reset_stat_lock: SELECT pg_stat_reset_shared('lock');
+pg_stat_reset_shared
+--------------------
+
+(1 row)
+
+step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s2_set_log_lock_waits: SET log_lock_waits = on;
+step s1_begin: BEGIN;
+step s1_lock_relation: LOCK TABLE test_stat_tab;
+step s2_begin: BEGIN;
+step s2_ff: SELECT pg_stat_force_next_flush();
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s2_lock_relation: LOCK TABLE test_stat_tab; <waiting ...>
+step s1_sleep: SELECT pg_sleep(0.5);
+pg_sleep
+--------
+
+(1 row)
+
+step s1_commit: COMMIT;
+step s2_lock_relation: <... completed>
+step s2_commit: COMMIT;
+step s2_report_stat_lock_relation: SELECT waits > 0, wait_time > 500 FROM pg_stat_lock WHERE locktype = 'relation';
+?column?|?column?
+--------+--------
+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
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s1_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s1_reset_stat_lock: SELECT pg_stat_reset_shared('lock');
+pg_stat_reset_shared
+--------------------
+
+(1 row)
+
+step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s2_set_log_lock_waits: SET log_lock_waits = 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';
+step s2_begin: BEGIN;
+step s2_ff: SELECT pg_stat_force_next_flush();
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s2_table_update_k1: UPDATE test_stat_tab SET value = value + 1 WHERE key = 'k1'; <waiting ...>
+step s1_sleep: SELECT pg_sleep(0.5);
+pg_sleep
+--------
+
+(1 row)
+
+step s1_commit: COMMIT;
+step s2_table_update_k1: <... completed>
+step s2_commit: COMMIT;
+step s2_report_stat_lock_transactionid: SELECT waits > 0, wait_time > 500 FROM pg_stat_lock WHERE locktype = 'transactionid';
+?column?|?column?
+--------+--------
+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
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s1_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s1_reset_stat_lock: SELECT pg_stat_reset_shared('lock');
+pg_stat_reset_shared
+--------------------
+
+(1 row)
+
+step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s2_set_log_lock_waits: SET log_lock_waits = on;
+step s1_lock_advisory_lock: SELECT pg_advisory_lock(1);
+pg_advisory_lock
+----------------
+
+(1 row)
+
+step s2_begin: BEGIN;
+step s2_ff: SELECT pg_stat_force_next_flush();
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s2_lock_advisory_lock: SELECT pg_advisory_lock(1); <waiting ...>
+step s1_sleep: SELECT pg_sleep(0.5);
+pg_sleep
+--------
+
+(1 row)
+
+step s1_lock_advisory_unlock: SELECT pg_advisory_unlock(1);
+pg_advisory_unlock
+------------------
+t
+(1 row)
+
+step s2_lock_advisory_lock: <... completed>
+pg_advisory_lock
+----------------
+
+(1 row)
+
+step s2_lock_advisory_unlock: SELECT pg_advisory_unlock(1);
+pg_advisory_unlock
+------------------
+t
+(1 row)
+
+step s2_commit: COMMIT;
+step s2_report_stat_lock_advisory: SELECT waits > 0, wait_time > 500 FROM pg_stat_lock WHERE locktype = 'advisory';
+?column?|?column?
+--------+--------
+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
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s1_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s1_reset_stat_lock: SELECT pg_stat_reset_shared('lock');
+pg_stat_reset_shared
+--------------------
+
+(1 row)
+
+step s1_set_log_lock_waits: SET log_lock_waits = on;
+step s2_set_deadlock_timeout: SET deadlock_timeout = '10ms';
+step s2_unset_log_lock_waits: SET log_lock_waits = off;
+step s1_begin: BEGIN;
+step s1_lock_relation: LOCK TABLE test_stat_tab;
+step s2_begin: BEGIN;
+step s2_ff: SELECT pg_stat_force_next_flush();
+pg_stat_force_next_flush
+------------------------
+
+(1 row)
+
+step s2_lock_relation: LOCK TABLE test_stat_tab; <waiting ...>
+step s1_sleep: SELECT pg_sleep(0.5);
+pg_sleep
+--------
+
+(1 row)
+
+step s1_commit: COMMIT;
+step s2_lock_relation: <... completed>
+step s2_commit: COMMIT;
+step s2_report_stat_lock_relation: SELECT waits > 0, wait_time > 500 FROM pg_stat_lock WHERE locktype = 'relation';
+?column?|?column?
+--------+--------
+f |f
+(1 row)
+
diff --git a/src/test/isolation/specs/stats.spec b/src/test/isolation/specs/stats.spec
index da16710da0f..42be68c545f 100644
--- a/src/test/isolation/specs/stats.spec
+++ b/src/test/isolation/specs/stats.spec
@@ -130,6 +130,14 @@ step s1_slru_check_stats {
WHERE before.stat = 'blks_zeroed';
}
+# 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_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; }
+step s1_lock_advisory_lock { SELECT pg_advisory_lock(1); }
+step s1_lock_advisory_unlock { SELECT pg_advisory_unlock(1); }
session s2
setup { SET stats_fetch_consistency = 'none'; }
@@ -164,6 +172,16 @@ step s2_big_notify { SELECT pg_notify('stats_test_use',
repeat(i::text, current_setting('block_size')::int / 2)) FROM generate_series(1, 3) g(i);
}
+# 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_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'; }
+step s2_lock_relation { LOCK TABLE test_stat_tab; }
+step s2_lock_advisory_lock { SELECT pg_advisory_lock(1); }
+step s2_lock_advisory_unlock { SELECT pg_advisory_unlock(1); }
######################
# Function stats tests
@@ -765,3 +783,80 @@ permutation
s1_clear_snapshot
s1_func_stats
s1_commit
+
+######################
+# Lock stats tests
+######################
+
+# relation lock
+
+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
+
+# transaction lock
+
+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
+
+# advisory lock
+
+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
+
+# Ensure log_lock_waits behaves correctly
+
+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
diff --git a/src/test/regress/expected/rules.out b/src/test/regress/expected/rules.out
index 78a37d9fc8f..c013fbebb88 100644
--- a/src/test/regress/expected/rules.out
+++ b/src/test/regress/expected/rules.out
@@ -1951,6 +1951,12 @@ pg_stat_io| SELECT backend_type,
fsync_time,
stats_reset
FROM pg_stat_get_io() b(backend_type, object, context, reads, read_bytes, read_time, writes, write_bytes, write_time, writebacks, writeback_time, extends, extend_bytes, extend_time, hits, evictions, reuses, fsyncs, fsync_time, stats_reset);
+pg_stat_lock| SELECT locktype,
+ waits,
+ wait_time,
+ fastpath_exceeded,
+ stats_reset
+ FROM pg_stat_get_lock() l(locktype, waits, wait_time, fastpath_exceeded, stats_reset);
pg_stat_progress_analyze| SELECT s.pid,
s.datid,
d.datname,
diff --git a/src/test/regress/expected/stats.out b/src/test/regress/expected/stats.out
index cd00f35bf7a..93de87747d4 100644
--- a/src/test/regress/expected/stats.out
+++ b/src/test/regress/expected/stats.out
@@ -1910,4 +1910,52 @@ SELECT * FROM check_estimated_rows('SELECT * FROM table_fillfactor');
(1 row)
DROP TABLE table_fillfactor;
+-- Test fastpath_exceeded stat
+CREATE TABLE part_test (id int) PARTITION BY RANGE (id);
+SELECT pg_stat_reset_shared('lock');
+ pg_stat_reset_shared
+----------------------
+
+(1 row)
+
+-- Create partitions (exceeds number of slots)
+DO $$
+DECLARE
+ max_locks int;
+BEGIN
+ SELECT setting::int INTO max_locks
+ FROM pg_settings
+ WHERE name = 'max_locks_per_transaction';
+
+ FOR i IN 1..(max_locks + 10) LOOP
+ EXECUTE format(
+ 'CREATE TABLE part_test_%s PARTITION OF part_test
+ FOR VALUES FROM (%s) TO (%s)',
+ i, (i-1)*1000, i*1000
+ );
+ END LOOP;
+END;
+$$;
+SELECT fastpath_exceeded AS fastpath_exceeded_before FROM pg_stat_lock WHERE locktype = 'relation' \gset
+-- Needs a lock on each partition
+SELECT count(*) FROM part_test;
+ count
+-------
+ 0
+(1 row)
+
+-- Ensure pending stats are flushed
+SELECT pg_stat_force_next_flush();
+ pg_stat_force_next_flush
+--------------------------
+
+(1 row)
+
+SELECT fastpath_exceeded > :fastpath_exceeded_before FROM pg_stat_lock WHERE locktype = 'relation';
+ ?column?
+----------
+ t
+(1 row)
+
+DROP TABLE part_test;
-- End of Stats Test
diff --git a/src/test/regress/sql/stats.sql b/src/test/regress/sql/stats.sql
index 8768e0f27fd..db9948eedb8 100644
--- a/src/test/regress/sql/stats.sql
+++ b/src/test/regress/sql/stats.sql
@@ -944,4 +944,40 @@ SELECT * FROM check_estimated_rows('SELECT * FROM table_fillfactor');
DROP TABLE table_fillfactor;
+-- Test fastpath_exceeded stat
+CREATE TABLE part_test (id int) PARTITION BY RANGE (id);
+
+SELECT pg_stat_reset_shared('lock');
+
+-- Create partitions (exceeds number of slots)
+DO $$
+DECLARE
+ max_locks int;
+BEGIN
+ SELECT setting::int INTO max_locks
+ FROM pg_settings
+ WHERE name = 'max_locks_per_transaction';
+
+ FOR i IN 1..(max_locks + 10) LOOP
+ EXECUTE format(
+ 'CREATE TABLE part_test_%s PARTITION OF part_test
+ FOR VALUES FROM (%s) TO (%s)',
+ i, (i-1)*1000, i*1000
+ );
+ END LOOP;
+END;
+$$;
+
+SELECT fastpath_exceeded AS fastpath_exceeded_before FROM pg_stat_lock WHERE locktype = 'relation' \gset
+
+-- Needs a lock on each partition
+SELECT count(*) FROM part_test;
+
+-- Ensure pending stats are flushed
+SELECT pg_stat_force_next_flush();
+
+SELECT fastpath_exceeded > :fastpath_exceeded_before FROM pg_stat_lock WHERE locktype = 'relation';
+
+DROP TABLE part_test;
+
-- End of Stats Test
--
2.34.1
[text/x-diff] v8-0003-Introduce-a-new-track_lock_timing-GUC.patch (25.6K, 4-v8-0003-Introduce-a-new-track_lock_timing-GUC.patch)
download | inline diff:
From 1a7dfa836fa8c3c67b6423c587ebba2edf823cdf Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <[email protected]>
Date: Fri, 20 Feb 2026 06:13:28 +0000
Subject: [PATCH v8 3/3] Introduce a new track_lock_timing GUC
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 | 160 +++++++++---------
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, 149 insertions(+), 114 deletions(-)
7.6% doc/src/sgml/
47.7% src/backend/storage/lmgr/
36.3% src/test/isolation/expected/
6.1% src/test/isolation/specs/
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index f670e2d4c31..1d3acb697da 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -8842,6 +8842,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 3a196bc305c..75c3e036860 100644
--- a/doc/src/sgml/monitoring.sgml
+++ b/doc/src/sgml/monitoring.sgml
@@ -3181,7 +3181,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>
@@ -3195,7 +3195,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 e38c8820103..7681f87f078 100644
--- a/src/backend/storage/lmgr/proc.c
+++ b/src/backend/storage/lmgr/proc.c
@@ -62,6 +62,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;
@@ -1547,99 +1548,110 @@ 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))));
- }
-
- if (myWaitStatus == PROC_WAIT_STATUS_WAITING)
- 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))));
- else if (myWaitStatus == PROC_WAIT_STATUS_OK)
- {
- /* Increment the lock statistics counters */
+ /* Increment the lock statistics counters */
+ if (track_lock_timing && myWaitStatus == PROC_WAIT_STATUS_OK)
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
+ if (log_lock_waits)
{
- 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)
+ 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 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 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)
+ 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))));
+
+ 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);
}
/*
@@ -1647,10 +1659,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 9507778415d..c21e6c6ea4e 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 f938cc65a3a..8a3a704aaa5 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 1c261e2c7a8..1ba7d98d06b 100644
--- a/src/include/pgstat.h
+++ b/src/include/pgstat.h
@@ -843,6 +843,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
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-18 04:36 Bertrand Drouvot <[email protected]>
parent: Bertrand Drouvot <[email protected]>
0 siblings, 1 reply; 26+ messages in thread
From: Bertrand Drouvot @ 2026-03-18 04:36 UTC (permalink / raw)
To: Andres Freund <[email protected]>; +Cc: Michael Paquier <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
Hi,
On Fri, Feb 27, 2026 at 05:14:31AM +0000, Bertrand Drouvot wrote:
> Hi,
>
> On Fri, Feb 20, 2026 at 05:26:37PM +0000, Bertrand Drouvot wrote:
> > Hi,
> >
> > On Fri, Feb 20, 2026 at 11:02:49AM -0500, Andres Freund wrote:
> > > Hi,
> > >
> > > How could a user benefit from that split? To me this is pointless number
> > > gathering that wastes resources and confuses users.
> >
> > I was thinking that could be useful to know the distribution between "long" waits
> > (greater than the deadlock timeout) among all the waits.
> >
> > If the vast majority are long waits that may indicate that the application is
> > misbehaving (as opposed to a tiny percentage of long waits).
> >
> > I was also thinking to bring those stats per-backend (as a next step) and that
> > could also probably be more useful (distribution per host for example, thanks to
> > joining with pg_stat_activity).
>
> As it seems that I'm the only one thinking that this split could be useful, I'm
> removing it in the attached. We can still split later on if we have requests from
> the field.
>
> So, we're back to what we were discussing before the split. As in v7, 0003 is
> adding the new GUC. So that we can see what having a new GUC implies in ProcSleep()
> and we can just get rid of 0003 if we think the GUC is not worth the extra complexity
> (I don't have a strong opinion on it but tempted to think that the extra GUC is
> not worth it).
PFA, a rebase due to fd6ecbfa75ff.
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-18 08:15 Michael Paquier <[email protected]>
parent: Bertrand Drouvot <[email protected]>
0 siblings, 1 reply; 26+ messages in thread
From: Michael Paquier @ 2026-03-18 08:15 UTC (permalink / raw)
To: Bertrand Drouvot <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
On Wed, Mar 18, 2026 at 04:36:04AM +0000, Bertrand Drouvot wrote:
>> So, we're back to what we were discussing before the split. As in v7, 0003 is
>> adding the new GUC. So that we can see what having a new GUC implies in ProcSleep()
>> and we can just get rid of 0003 if we think the GUC is not worth the extra complexity
>> (I don't have a strong opinion on it but tempted to think that the extra GUC is
>> not worth it).
>
> PFA, a rebase due to fd6ecbfa75ff.
Looking again at this patch, all the fields that you are adding are in
non-critical paths, so it looks fine by me to begin with this data
set. We may want to document that for future readers of the code to
not add counter increments in the fast code paths, where performance
could matter.
Let's also drop 0003 with the GUC. log_lock_waits is enabled by
default and we are in a wait path which would not be
performance-critical.
Regarding the isolation test, the new permutations add 4 pg_sleep()
calls at 500ms each, making the stats test longer. It also looks like
the outputs are the same for the two alternate expected files? Do you
think that it could be possible to move these tests to a new file,
perhaps cutting a bit the sleeps to make it faster?
--
Michael
Attachments:
[application/pgp-signature] signature.asc (833B, 2-signature.asc)
download
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-18 14:51 Bertrand Drouvot <[email protected]>
parent: Michael Paquier <[email protected]>
0 siblings, 1 reply; 26+ messages in thread
From: Bertrand Drouvot @ 2026-03-18 14:51 UTC (permalink / raw)
To: Michael Paquier <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
Hi,
On Wed, Mar 18, 2026 at 05:15:27PM +0900, Michael Paquier wrote:
> On Wed, Mar 18, 2026 at 04:36:04AM +0000, Bertrand Drouvot wrote:
> >> So, we're back to what we were discussing before the split. As in v7, 0003 is
> >> adding the new GUC. So that we can see what having a new GUC implies in ProcSleep()
> >> and we can just get rid of 0003 if we think the GUC is not worth the extra complexity
> >> (I don't have a strong opinion on it but tempted to think that the extra GUC is
> >> not worth it).
> >
> > PFA, a rebase due to fd6ecbfa75ff.
>
> Looking again at this patch, all the fields that you are adding are in
> non-critical paths, so it looks fine by me to begin with this data
> set.
Thanks for looking at it!
> We may want to document that for future readers of the code to
> not add counter increments in the fast code paths, where performance
> could matter.
Yeah, added a few words in the callers and on top of the function definitions.
> Let's also drop 0003 with the GUC. log_lock_waits is enabled by
> default and we are in a wait path which would not be
> performance-critical.
Yeah, that was also my vote.
> Regarding the isolation test, the new permutations add 4 pg_sleep()
> calls at 500ms each, making the stats test longer. It also looks like
> the outputs are the same for the two alternate expected files? Do you
> think that it could be possible to move these tests to a new file,
> perhaps cutting a bit the sleeps to make it faster?
This is done that way in the attached, so that we don't need the extra output in
the _1.out file and the test time is reduced (since the deadlock timeout is set
to 10ms in the test, I changed the sleep time to 50ms (I did not want to be very
close to 10ms)).
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-19 07:01 Michael Paquier <[email protected]>
parent: Bertrand Drouvot <[email protected]>
0 siblings, 1 reply; 26+ messages in thread
From: Michael Paquier @ 2026-03-19 07:01 UTC (permalink / raw)
To: Bertrand Drouvot <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
On Wed, Mar 18, 2026 at 02:51:01PM +0000, Bertrand Drouvot wrote:
> This is done that way in the attached, so that we don't need the extra output in
> the _1.out file and the test time is reduced (since the deadlock timeout is set
> to 10ms in the test, I changed the sleep time to 50ms (I did not want to be very
> close to 10ms)).
> + <structfield>waits</structfield> <type>bigint</type>
> + </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"/>
> + is enabled and the lock was successfully acquired after waiting longer
> + than <xref linkend="guc-deadlock-timeout"/>.
> + </para>
> + </entry>
It does not make much sense to me to decide that the counter is
incremented if a GUC related to a control of the logs generated is
enabled. It's a fact that log_lock_waits is enabled by default these
days, hence we will be able to get the time calculation for free for
most deployments, but it seems inconsistent to me to not count this
information if the GUC is disabled. We should increment the counter
and aggregate the time spent on the wait all the time, no?
+ * Copyright (c) 2021-2025, PostgreSQL Global Development Group
Incorrect date at the top of pgstat_lock.c.
storage/lock.h is included in pgstat.h as LOCKTAG_LAST_TYPE is wanted
for the new lock stats structure. That would pull in a lot of header
data into pgstat.h. How about creating a new header that splits a
portion of lock.h into a new file? LockTagType, LOCKTAG_LAST_TYPE,
LockTagTypeNames at least and perhaps a few other things? Or we could
just limit ourselves to a locktag.h with these three, then include the
new locktag.h in pgstat.h.
It would be nice to document at the top of the new spec file what this
test is here for, and perhaps name it stats-lock instead?
--
Michael
Attachments:
[application/pgp-signature] signature.asc (833B, 2-signature.asc)
download
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-19 12:25 Bertrand Drouvot <[email protected]>
parent: Michael Paquier <[email protected]>
0 siblings, 1 reply; 26+ messages in thread
From: Bertrand Drouvot @ 2026-03-19 12:25 UTC (permalink / raw)
To: Michael Paquier <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
Hi,
On Thu, Mar 19, 2026 at 04:01:39PM +0900, Michael Paquier wrote:
> On Wed, Mar 18, 2026 at 02:51:01PM +0000, Bertrand Drouvot wrote:
> > This is done that way in the attached, so that we don't need the extra output in
> > the _1.out file and the test time is reduced (since the deadlock timeout is set
> > to 10ms in the test, I changed the sleep time to 50ms (I did not want to be very
> > close to 10ms)).
>
> > + <structfield>waits</structfield> <type>bigint</type>
> > + </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"/>
> > + is enabled and the lock was successfully acquired after waiting longer
> > + than <xref linkend="guc-deadlock-timeout"/>.
> > + </para>
> > + </entry>
>
> It does not make much sense to me to decide that the counter is
> incremented if a GUC related to a control of the logs generated is
> enabled. It's a fact that log_lock_waits is enabled by default these
> days, hence we will be able to get the time calculation for free for
> most deployments, but it seems inconsistent to me to not count this
> information if the GUC is disabled. We should increment the counter
> and aggregate the time spent on the wait all the time, no?
Yeah that's another way to think about it. In my mind the GUC was a "protection"
to be able to avoid the extra GetCurrentTimestamp() call. But since it's done
only if we waited longer than the deadlock timeout that's also fine to call
GetCurrentTimestamp() even if log_lock_waits is off. Done that way in the
attached.
>
> + * Copyright (c) 2021-2025, PostgreSQL Global Development Group
>
> Incorrect date at the top of pgstat_lock.c.
Yeah, so replaced 2025 with 2026. I did not change 2021 because it's mainly copied
from pgstat_io.c and I also think that's not that important ([1]).
> storage/lock.h is included in pgstat.h as LOCKTAG_LAST_TYPE is wanted
> for the new lock stats structure. That would pull in a lot of header
> data into pgstat.h. How about creating a new header that splits a
> portion of lock.h into a new file? LockTagType, LOCKTAG_LAST_TYPE,
> LockTagTypeNames at least and perhaps a few other things? Or we could
> just limit ourselves to a locktag.h with these three, then include the
> new locktag.h in pgstat.h.
That's a good idea! I only moved LockTagType, LOCKTAG_LAST_TYPE, LockTagTypeNames
and LOCKTAG into a new locktag.h. I chose not to move the SET_LOCKTAG_* macros
because then we'd also need to move DEFAULT_LOCKMETHOD and USER_LOCKMETHOD that
I think are better suited in lock.h.
I did not check if there are any other files that could benefit of using
locktag.h instead of lock.h but that's something I'll do and open a dedicated
if any (once locktag.h is in the tree).
> It would be nice to document at the top of the new spec file what this
> test is here for,
Yeah, I copied stats.spec which has no comments but better to add some. Done in
the new version.
> and perhaps name it stats-lock instead?
Not sure as we already have multixact-stats.
[1]: https://postgr.es/m/202501211750.xf5j6thdkppy%40alvherre.pgsql
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-21 05:55 Michael Paquier <[email protected]>
parent: Bertrand Drouvot <[email protected]>
0 siblings, 2 replies; 26+ messages in thread
From: Michael Paquier @ 2026-03-21 05:55 UTC (permalink / raw)
To: Bertrand Drouvot <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
On Thu, Mar 19, 2026 at 12:25:41PM +0000, Bertrand Drouvot wrote:
> That's a good idea! I only moved LockTagType, LOCKTAG_LAST_TYPE, LockTagTypeNames
> and LOCKTAG into a new locktag.h. I chose not to move the SET_LOCKTAG_* macros
> because then we'd also need to move DEFAULT_LOCKMETHOD and USER_LOCKMETHOD that
> I think are better suited in lock.h.
While looking at the full set of declarations, I've come to disagree
to that: by moving the macros, we also do not need to know about the
internal field names of LOCKTAG across multiple headers.
> I did not check if there are any other files that could benefit of using
> locktag.h instead of lock.h but that's something I'll do and open a dedicated
> if any (once locktag.h is in the tree).
I have checked after that, and did not spot an area (except your patch
of course). And applied this part.
> Not sure as we already have multixact-stats.
Ah, right. I did not notice this one. This existing name sounds OK
by me, then.
--
Michael
Attachments:
[application/pgp-signature] signature.asc (833B, 2-signature.asc)
download
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-21 20:01 Álvaro Herrera <[email protected]>
parent: Michael Paquier <[email protected]>
1 sibling, 1 reply; 26+ messages in thread
From: Álvaro Herrera @ 2026-03-21 20:01 UTC (permalink / raw)
To: Michael Paquier <[email protected]>; Bertrand Drouvot <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; L. pgsql-hackers <[email protected]>
On 2026-03-21, Michael Paquier wrote:
> On Thu, Mar 19, 2026 at 12:25:41PM +0000, Bertrand Drouvot wrote:
>> I did not check if there are any other files that could benefit of using
>> locktag.h instead of lock.h but that's something I'll do and open a dedicated
>> if any (once locktag.h is in the tree).
>
> I have checked after that, and did not spot an area (except your patch
> of course). And applied this part.
I checked this, and found a couple of headers that can benefit from a removal, as shown in the attached patches.
A special case (not modified here) is proc.h. It seems to me that lock.h _could_ be removed from there with some effort, but the amount of .c files that would benefit seems to me not large enough to justify the number of contortions needed. Others could disagree though.
--
Álvaro Herrera
Attachments:
[text/x-patch] 0001-procarray.h-does-not-need-storage-lock.h-for-anythin.patch (741B, 2-0001-procarray.h-does-not-need-storage-lock.h-for-anythin.patch)
download | inline diff:
From aa6155106b7f5dc697df54dc4e4aeb5c6419ec92 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?=C3=81lvaro=20Herrera?= <[email protected]>
Date: Sat, 21 Mar 2026 20:33:10 +0100
Subject: [PATCH 1/4] procarray.h does not need storage/lock.h for anything
No fallout from this change. Weird
---
src/include/storage/procarray.h | 1 -
1 file changed, 1 deletion(-)
diff --git a/src/include/storage/procarray.h b/src/include/storage/procarray.h
index c5ab1574fe3..abdf021e66e 100644
--- a/src/include/storage/procarray.h
+++ b/src/include/storage/procarray.h
@@ -14,7 +14,6 @@
#ifndef PROCARRAY_H
#define PROCARRAY_H
-#include "storage/lock.h"
#include "storage/standby.h"
#include "utils/relcache.h"
#include "utils/snapshot.h"
--
2.47.3
[text/x-patch] 0002-lmgr.h-doesn-t-need-the-full-lock.h.patch (1.7K, 3-0002-lmgr.h-doesn-t-need-the-full-lock.h.patch)
download | inline diff:
From c09489b4164d0d8c7942ca20a9fb645a1d68ea7f Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?=C3=81lvaro=20Herrera?= <[email protected]>
Date: Sat, 21 Mar 2026 20:35:51 +0100
Subject: [PATCH 2/4] lmgr.h doesn't need the full lock.h
---
src/backend/utils/activity/wait_event.c | 6 ++++--
src/backend/utils/cache/syscache.c | 1 +
src/include/storage/lmgr.h | 2 +-
3 files changed, 6 insertions(+), 3 deletions(-)
diff --git a/src/backend/utils/activity/wait_event.c b/src/backend/utils/activity/wait_event.c
index aca2c8fc742..c7e2d825120 100644
--- a/src/backend/utils/activity/wait_event.c
+++ b/src/backend/utils/activity/wait_event.c
@@ -22,9 +22,11 @@
*/
#include "postgres.h"
-#include "storage/lmgr.h" /* for GetLockNameFromTagType */
-#include "storage/lwlock.h" /* for GetLWLockIdentifier */
+#include "storage/lmgr.h"
+#include "storage/lwlock.h"
+#include "storage/shmem.h"
#include "storage/spin.h"
+#include "utils/hsearch.h"
#include "utils/wait_event.h"
diff --git a/src/backend/utils/cache/syscache.c b/src/backend/utils/cache/syscache.c
index 007a9a15d71..f4233f9e31a 100644
--- a/src/backend/utils/cache/syscache.c
+++ b/src/backend/utils/cache/syscache.c
@@ -32,6 +32,7 @@
#include "lib/qunique.h"
#include "miscadmin.h"
#include "storage/lmgr.h"
+#include "storage/lock.h"
#include "utils/catcache.h"
#include "utils/inval.h"
#include "utils/lsyscache.h"
diff --git a/src/include/storage/lmgr.h b/src/include/storage/lmgr.h
index 74a398ffc00..2a985ce5e15 100644
--- a/src/include/storage/lmgr.h
+++ b/src/include/storage/lmgr.h
@@ -16,7 +16,7 @@
#include "lib/stringinfo.h"
#include "storage/itemptr.h"
-#include "storage/lock.h"
+#include "storage/locktag.h"
#include "utils/rel.h"
--
2.47.3
[text/x-patch] 0003-namespace.h-doesn-t-need-lock.h-only-lockdefs.h.patch (2.9K, 4-0003-namespace.h-doesn-t-need-lock.h-only-lockdefs.h.patch)
download | inline diff:
From 35b09d1a4e4e3e65c0754c88098259974c9a1973 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?=C3=81lvaro=20Herrera?= <[email protected]>
Date: Sat, 21 Mar 2026 20:49:41 +0100
Subject: [PATCH 3/4] namespace.h doesn't need lock.h, only lockdefs.h
---
src/backend/access/common/relation.c | 1 +
src/backend/commands/conversioncmds.c | 1 +
src/backend/commands/discard.c | 1 +
src/backend/parser/parse_oper.c | 1 +
src/backend/utils/cache/ts_cache.c | 1 +
src/include/catalog/namespace.h | 2 +-
6 files changed, 6 insertions(+), 1 deletion(-)
diff --git a/src/backend/access/common/relation.c b/src/backend/access/common/relation.c
index 92a6e37d8bd..2e3a37c9272 100644
--- a/src/backend/access/common/relation.c
+++ b/src/backend/access/common/relation.c
@@ -24,6 +24,7 @@
#include "access/xact.h"
#include "catalog/namespace.h"
#include "pgstat.h"
+#include "storage/lock.h"
#include "storage/lmgr.h"
#include "utils/inval.h"
#include "utils/syscache.h"
diff --git a/src/backend/commands/conversioncmds.c b/src/backend/commands/conversioncmds.c
index 61aa8bb9fd1..5f2022d3072 100644
--- a/src/backend/commands/conversioncmds.c
+++ b/src/backend/commands/conversioncmds.c
@@ -19,6 +19,7 @@
#include "catalog/pg_proc.h"
#include "catalog/pg_type.h"
#include "commands/conversioncmds.h"
+#include "fmgr.h"
#include "mb/pg_wchar.h"
#include "miscadmin.h"
#include "parser/parse_func.h"
diff --git a/src/backend/commands/discard.c b/src/backend/commands/discard.c
index 7b5520b9abe..17d172df076 100644
--- a/src/backend/commands/discard.c
+++ b/src/backend/commands/discard.c
@@ -19,6 +19,7 @@
#include "commands/discard.h"
#include "commands/prepare.h"
#include "commands/sequence.h"
+#include "storage/lock.h"
#include "utils/guc.h"
#include "utils/portal.h"
diff --git a/src/backend/parser/parse_oper.c b/src/backend/parser/parse_oper.c
index a6b402f2d7b..2f218c1ab8b 100644
--- a/src/backend/parser/parse_oper.c
+++ b/src/backend/parser/parse_oper.c
@@ -25,6 +25,7 @@
#include "parser/parse_oper.h"
#include "parser/parse_type.h"
#include "utils/builtins.h"
+#include "utils/hsearch.h"
#include "utils/inval.h"
#include "utils/lsyscache.h"
#include "utils/syscache.h"
diff --git a/src/backend/utils/cache/ts_cache.c b/src/backend/utils/cache/ts_cache.c
index 744c8e71d71..9e29f1386b0 100644
--- a/src/backend/utils/cache/ts_cache.c
+++ b/src/backend/utils/cache/ts_cache.c
@@ -44,6 +44,7 @@
#include "utils/catcache.h"
#include "utils/fmgroids.h"
#include "utils/guc_hooks.h"
+#include "utils/hsearch.h"
#include "utils/inval.h"
#include "utils/lsyscache.h"
#include "utils/memutils.h"
diff --git a/src/include/catalog/namespace.h b/src/include/catalog/namespace.h
index 1a25973685c..9453a3e4932 100644
--- a/src/include/catalog/namespace.h
+++ b/src/include/catalog/namespace.h
@@ -15,7 +15,7 @@
#define NAMESPACE_H
#include "nodes/primnodes.h"
-#include "storage/lock.h"
+#include "storage/lockdefs.h"
#include "storage/procnumber.h"
--
2.47.3
[text/x-patch] 0004-vacuum.h-doesn-t-need-lock.h.patch (1.6K, 5-0004-vacuum.h-doesn-t-need-lock.h.patch)
download | inline diff:
From 13fc9223da3fab2cc958e302c00175a6e0c516c8 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?=C3=81lvaro=20Herrera?= <[email protected]>
Date: Sat, 21 Mar 2026 20:53:54 +0100
Subject: [PATCH 4/4] vacuum.h doesn't need lock.h
---
src/backend/access/nbtree/nbtree.c | 1 +
src/backend/catalog/pg_subscription.c | 1 +
src/include/commands/vacuum.h | 1 -
3 files changed, 2 insertions(+), 1 deletion(-)
diff --git a/src/backend/access/nbtree/nbtree.c b/src/backend/access/nbtree/nbtree.c
index aed74590cf4..6d870e4ebe7 100644
--- a/src/backend/access/nbtree/nbtree.c
+++ b/src/backend/access/nbtree/nbtree.c
@@ -30,6 +30,7 @@
#include "storage/indexfsm.h"
#include "storage/ipc.h"
#include "storage/lmgr.h"
+#include "storage/lwlock.h"
#include "storage/read_stream.h"
#include "utils/datum.h"
#include "utils/fmgrprotos.h"
diff --git a/src/backend/catalog/pg_subscription.c b/src/backend/catalog/pg_subscription.c
index 3673d4f0bc1..1d140c513d0 100644
--- a/src/backend/catalog/pg_subscription.c
+++ b/src/backend/catalog/pg_subscription.c
@@ -26,6 +26,7 @@
#include "foreign/foreign.h"
#include "miscadmin.h"
#include "storage/lmgr.h"
+#include "storage/lock.h"
#include "utils/acl.h"
#include "utils/array.h"
#include "utils/builtins.h"
diff --git a/src/include/commands/vacuum.h b/src/include/commands/vacuum.h
index 953a506181e..1f45bca015c 100644
--- a/src/include/commands/vacuum.h
+++ b/src/include/commands/vacuum.h
@@ -23,7 +23,6 @@
#include "catalog/pg_type.h"
#include "parser/parse_node.h"
#include "storage/buf.h"
-#include "storage/lock.h"
#include "utils/relcache.h"
/*
--
2.47.3
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-23 08:18 Bertrand Drouvot <[email protected]>
parent: Álvaro Herrera <[email protected]>
0 siblings, 2 replies; 26+ messages in thread
From: Bertrand Drouvot @ 2026-03-23 08:18 UTC (permalink / raw)
To: Álvaro Herrera <[email protected]>; +Cc: Michael Paquier <[email protected]>; Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; L. pgsql-hackers <[email protected]>
Hi,
On Sun, Mar 22, 2026 at 08:37:47PM +0100, Álvaro Herrera wrote:
> On 2026-Mar-21, Álvaro Herrera wrote:
>
> > I checked this, and found a couple of headers that can benefit from a
> > removal, as shown in the attached patches.
>
> I looked again and found some more; the first 14 patches attached here
> do so. A couple of them have no fallout to speak of, which I find
> really surprising; for the majority we just need a couple of extra
> includes somewhere or a typedef or two. I unleashed CI on it to see
> what would happen,
> https://cirrus-ci.com/build/5522804717649920
Thanks for looking at it!
I looked at the C files changes that now need to include lock.h (or other ones)
directly:
verify_heapam.c: lock.h was indirectly included through procarray.h
heapam_handler.c: lock.h was indirectly included through heapam.h -> tableam.h
-> vacuum.h
relation.c: lock.h was indirectly included through namespace.h
reloptions.c: lock.h was indirectly included through reloptions.h
indexam.c: lock.h was indirectly included through reloptions.h
relcache.c: lock.h was indirectly included through reloptions.h
syscache.c: lock.h was indirectly included through lmgr.h
discard.c: lock.h was indirectly included through namespace.h
pg_subscription.c: lock.h was indirectly included through heapam.h -> tableam.h
-> vacuum.h
nbtree.c: lock.h was indirectly included through vacuum.h
nbtutils.c: lock.h was indirectly included through reloptions.h
pg_inherits.c: lock.h was indirectly included through pg_inherits.h
inherit.c: lock.h was indirectly included through pg_inherits.h
conversioncmds.c: lock.h was indirectly included parse_func.h -> namespace.h
tablespace.c: lock.h was indirectly included through heapam.h -> tableam.h
-> vacuum.h
parse_oper.c: lock.h was indirectly included through parse_func.h -> namespace.h
sequencesync.c: lock.h was indirectly included through worker_internal.h
ts_cache.c: lock.h was indirectly included through namespace.h
So the changes done in your patches make sense to me.
I have 2 comments:
1/ wait_event.c
-#include "storage/lmgr.h" /* for GetLockNameFromTagType */
-#include "storage/lwlock.h" /* for GetLWLockIdentifier */
+#include "storage/lmgr.h"
+#include "storage/lwlock.h"
+#include "storage/shmem.h"
#include "storage/spin.h"
+#include "utils/hsearch.h"
hsearch.h is already included into shmem.h so its direct include is not needed.
That said wait_event.c needs it so including it directly might make sense just from
a coding "style" point of view (given that it is harmless as it is protected by
ifndef HSEARCH_H).
2/ Not directly linked to your patches
It looks like that aio_funcs.c does not need lock.h (reported by include-what-you-use).
If we remove its direct include, it's still indirectly included through proc.h
though. But I think that removing its direct include makes sense as it's not
needed at all.
If we still need to discuss about those lock.h related changes, maybe it's
worth creating a dedicated thread?
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-24 03:15 Michael Paquier <[email protected]>
parent: Bertrand Drouvot <[email protected]>
1 sibling, 0 replies; 26+ messages in thread
From: Michael Paquier @ 2026-03-24 03:15 UTC (permalink / raw)
To: Bertrand Drouvot <[email protected]>; +Cc: Álvaro Herrera <[email protected]>; Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; L. pgsql-hackers <[email protected]>
On Mon, Mar 23, 2026 at 08:18:05AM +0000, Bertrand Drouvot wrote:
> It looks like that aio_funcs.c does not need lock.h (reported by include-what-you-use).
> If we remove its direct include, it's still indirectly included through proc.h
> though. But I think that removing its direct include makes sense as it's not
> needed at all.
>
> If we still need to discuss about those lock.h related changes, maybe it's
> worth creating a dedicated thread?
This patch set is related to an entirely different topic than what we
are discussing, so yes, a different thread would be adapted.
--
Michael
Attachments:
[application/pgp-signature] signature.asc (833B, 2-signature.asc)
download
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-24 07:02 Michael Paquier <[email protected]>
parent: Michael Paquier <[email protected]>
1 sibling, 2 replies; 26+ messages in thread
From: Michael Paquier @ 2026-03-24 07:02 UTC (permalink / raw)
To: Bertrand Drouvot <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
On Sat, Mar 21, 2026 at 02:55:33PM +0900, Michael Paquier wrote:
> On Thu, Mar 19, 2026 at 12:25:41PM +0000, Bertrand Drouvot wrote:
>> I did not check if there are any other files that could benefit of using
>> locktag.h instead of lock.h but that's something I'll do and open a dedicated
>> if any (once locktag.h is in the tree).
>
> I have checked after that, and did not spot an area (except your patch
> of course). And applied this part.
The main patch has some churn in proc.c and lock.c, moving some code
blocks while the main focus of the patch is to add the two pgstat()
calls to report some data, so I have moved this part into its own
commit, and applied it. One thing to not in lock.c: we will calculate
the time difference of the wait even if log_lock_waits is disabled,
without the lock stats part. As this GUC is enabled by default, it
does not matter much in practice, I guess, and it matters even less
with the main patch merged.
The implementation of the main patch is close enough to pgstat_io.c
that your logic is a no-brainer (timestamp protected by the first
LWLock, each field incremented depending on locktags, etc.). Instead
of a boolean flag tracking if some stats have been set, we could also
have used an approach like the checkpointer stats with is_all_zeros on
the pending data, perhaps? At the end, with two incrementation
routines, I've let the code as-is.
Another thing I am not completely sure is if the sleep time of the
isolation tests is long enough. I have tested things with
CLOBBER_CACHE_ALWAYS to make the setup more sensitive to timings but
could not get it to fail. We'll know soon enough if the buildfarm
complains.
After a few more tweaks here and there (code, comments, some
beautification), done.
--
Michael
Attachments:
[application/pgp-signature] signature.asc (833B, 2-signature.asc)
download
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-24 20:09 Andres Freund <[email protected]>
parent: Michael Paquier <[email protected]>
1 sibling, 1 reply; 26+ messages in thread
From: Andres Freund @ 2026-03-24 20:09 UTC (permalink / raw)
To: Michael Paquier <[email protected]>; +Cc: Bertrand Drouvot <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
Hi,
On 2026-03-24 16:02:55 +0900, Michael Paquier wrote:
> Another thing I am not completely sure is if the sleep time of the
> isolation tests is long enough. I have tested things with
> CLOBBER_CACHE_ALWAYS to make the setup more sensitive to timings but
> could not get it to fail. We'll know soon enough if the buildfarm
> complains.
>
> After a few more tweaks here and there (code, comments, some
> beautification), done.
The test is extremely unstable on windows. On CI 10/16 runs since the test in
failed due to it, afaict.
I don't see how a test with a timeout setting that's anywhere remotely close
to 10ms could be expected to be stable.
Also, anything that requires short sleeps (like pg_sleep(0.05);) is extremely
likely to be a long time test stability hazard. It's a huge "test smell" to
me, to the point that I think every single sleep in a test needs a comment
explaining why that one use of sleep is correct, and that comment better be
signed in blood.
Greetings,
Andres Freund
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-24 23:46 Michael Paquier <[email protected]>
parent: Andres Freund <[email protected]>
0 siblings, 1 reply; 26+ messages in thread
From: Michael Paquier @ 2026-03-24 23:46 UTC (permalink / raw)
To: Andres Freund <[email protected]>; +Cc: Bertrand Drouvot <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
On Tue, Mar 24, 2026 at 04:09:37PM -0400, Andres Freund wrote:
> The test is extremely unstable on windows. On CI 10/16 runs since the test in
> failed due to it, afaict.
I am not surprised by that. Windows is good in catching race
conditions.
> I don't see how a test with a timeout setting that's anywhere remotely close
> to 10ms could be expected to be stable.
Well, the low value of deadlock_timeout is not the problem. The
shorter the better to make the test go faster with more deadlock
checks. What the buildfarm is telling is that we do not have the time
to process the deadlock_timeout request, and that we would need to pay
the cost of longer sleep if coded this way. This is going to cost in
runtime on fast machines where the CheckDeadLock() call would happen
quickly. And on slow machines, we don't have the guarantee that the
sleep would be long enough to process the deadlock request.
This test would be better if rewritten as a TAP test, I guess, with a
NOTICE injection point before the CheckDeadLock() call in ProcSleep()
to make sure that the second session processes the deadlock timeout
request while it is waiting on its lock to be acquired. One trickier
part is that we only care about the deadlock_timeout in s2, because we
want to measure the wait it has waited until the lock could be
acquired, meaning that we should make s1 use a large deadlock_timeout
to avoid interferences with a global injpoint.
I don't have the credits to test that in the CI for this month,
unfortunately, and this creates noise in the CI for the work of other
folks in this release cycle, so I am going to remove this test for
now.
> Also, anything that requires short sleeps (like pg_sleep(0.05);) is extremely
> likely to be a long time test stability hazard. It's a huge "test smell" to
> me, to the point that I think every single sleep in a test needs a comment
> explaining why that one use of sleep is correct, and that comment better be
> signed in blood.
Yep, agreed.
--
Michael
Attachments:
[application/pgp-signature] signature.asc (833B, 2-signature.asc)
download
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-25 03:15 Bertrand Drouvot <[email protected]>
parent: Michael Paquier <[email protected]>
0 siblings, 1 reply; 26+ messages in thread
From: Bertrand Drouvot @ 2026-03-25 03:15 UTC (permalink / raw)
To: Michael Paquier <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
Hi,
On Wed, Mar 25, 2026 at 08:46:23AM +0900, Michael Paquier wrote:
> On Tue, Mar 24, 2026 at 04:09:37PM -0400, Andres Freund wrote:
> > The test is extremely unstable on windows. On CI 10/16 runs since the test in
> > failed due to it, afaict.
Thanks for the warning!
> I am not surprised by that. Windows is good in catching race
> conditions.
>
> > I don't see how a test with a timeout setting that's anywhere remotely close
> > to 10ms could be expected to be stable.
>
> Well, the low value of deadlock_timeout is not the problem.
Yeah, there are other tests making use of a 10ms deadlock timeout.
> This test would be better if rewritten as a TAP test, I guess, with a
> NOTICE injection point before the CheckDeadLock() call in ProcSleep()
> to make sure that the second session processes the deadlock timeout
> request while it is waiting on its lock to be acquired. One trickier
> part is that we only care about the deadlock_timeout in s2, because we
> want to measure the wait it has waited until the lock could be
> acquired, meaning that we should make s1 use a large deadlock_timeout
> to avoid interferences with a global injpoint.
>
> I don't have the credits to test that in the CI for this month,
> unfortunately, and this creates noise in the CI for the work of other
> folks in this release cycle, so I am going to remove this test for
> now.
Thanks for the test removal. I created an open item for v19 so that we
don't forget to re-add a new version of the tests. I'll work on it.
[1]: https://wiki.postgresql.org/wiki/PostgreSQL_19_Open_Items
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-25 03:32 Bertrand Drouvot <[email protected]>
parent: Bertrand Drouvot <[email protected]>
1 sibling, 0 replies; 26+ messages in thread
From: Bertrand Drouvot @ 2026-03-25 03:32 UTC (permalink / raw)
To: Álvaro Herrera <[email protected]>; +Cc: Michael Paquier <[email protected]>; Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; L. pgsql-hackers <[email protected]>
Hi,
On Tue, Mar 24, 2026 at 05:16:11PM +0100, Álvaro Herrera wrote:
> Hello,
>
> On 2026-Mar-23, Bertrand Drouvot wrote:
>
> > 2/ Not directly linked to your patches
> >
> > It looks like that aio_funcs.c does not need lock.h (reported by include-what-you-use).
> > If we remove its direct include, it's still indirectly included through proc.h
> > though. But I think that removing its direct include makes sense as it's not
> > needed at all.
>
> I'm not opposed to somebody else making this change, if they want, but I
> think there's little practical impact.
yeah, not sure it deserves its own commit... I was just mentioning here in case
you want to change that in passing while working on lock.h includes.
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-25 05:25 Michael Paquier <[email protected]>
parent: Bertrand Drouvot <[email protected]>
0 siblings, 2 replies; 26+ messages in thread
From: Michael Paquier @ 2026-03-25 05:25 UTC (permalink / raw)
To: Bertrand Drouvot <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
On Wed, Mar 25, 2026 at 03:15:19AM +0000, Bertrand Drouvot wrote:
> Thanks for the test removal. I created an open item for v19 so that we
> don't forget to re-add a new version of the tests. I'll work on it.
>
> [1]: https://wiki.postgresql.org/wiki/PostgreSQL_19_Open_Items
Thanks for adding that. We are most likely going to need the help of
the CI here. The buildfarm has been fortunately (unfortunately?)
stable on this one, and that would make for less noise overall.
--
Michael
Attachments:
[application/pgp-signature] signature.asc (833B, 2-signature.asc)
download
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-25 07:24 Bertrand Drouvot <[email protected]>
parent: Michael Paquier <[email protected]>
1 sibling, 0 replies; 26+ messages in thread
From: Bertrand Drouvot @ 2026-03-25 07:24 UTC (permalink / raw)
To: Michael Paquier <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
Hi,
On Wed, Mar 25, 2026 at 02:25:01PM +0900, Michael Paquier wrote:
> On Wed, Mar 25, 2026 at 03:15:19AM +0000, Bertrand Drouvot wrote:
> > Thanks for the test removal. I created an open item for v19 so that we
> > don't forget to re-add a new version of the tests. I'll work on it.
> >
> > [1]: https://wiki.postgresql.org/wiki/PostgreSQL_19_Open_Items
>
> Thanks for adding that. We are most likely going to need the help of
> the CI here.
Yeah. FWIW I always use the CI before submiting patches. This one was
green and did not catch the failure:
https://github.com/bdrouvot/postgres/runs/67730691634
Would probably had to be launched multiple times to catch it (as Andres mentioned
that 10/16 runs failed).
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-25 19:54 Bertrand Drouvot <[email protected]>
parent: Michael Paquier <[email protected]>
1 sibling, 1 reply; 26+ messages in thread
From: Bertrand Drouvot @ 2026-03-25 19:54 UTC (permalink / raw)
To: Michael Paquier <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
Hi,
On Wed, Mar 25, 2026 at 02:25:01PM +0900, Michael Paquier wrote:
> On Wed, Mar 25, 2026 at 03:15:19AM +0000, Bertrand Drouvot wrote:
> > Thanks for the test removal. I created an open item for v19 so that we
> > don't forget to re-add a new version of the tests. I'll work on it.
> >
> > [1]: https://wiki.postgresql.org/wiki/PostgreSQL_19_Open_Items
>
> Thanks for adding that. We are most likely going to need the help of
> the CI here. The buildfarm has been fortunately (unfortunately?)
> stable on this one, and that would make for less noise overall.
PFA a new version of the tests using an injection point. This new injection
point is created in ProcSleep() when we know that the deadlock timeout fired.
The patch adds a new query_until_stderr() subroutine in BackgroundPsql.pm:
It does the same as query_until() except that it is waiting for a desired
stderr (and not stdout). Thanks to it the session can wait until it gets the
injection point notice.
I think that looks clearer that way than using the logfile to look for the
notice (should log_min_messages be set to an appropriate value).
If you like the idea, maybe we could introduce query_until_stderr() in a separate
commit. If you don't, then we could switch to looking in the server logfile
instead of the session stderr.
Then the new tests follow this workflow:
- session 1 holds a lock
- session 2 attaches to the new injection point with the notice action
- session 2 is blocked by session 1 and waits until the injection point notice
is received
- session 1 releases its lock, session 2 commits
- pg_stat_lock is polled until we get the counters for the lock type or die
with a timeout
That way there is no sleep at all. Once we know that session 2 has waited longer
than the deadlock timeout (thanks to the new injection point notice) then we
can release the locks and poll pg_stat_lock to get the updated stats.
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-25 23:06 Michael Paquier <[email protected]>
parent: Bertrand Drouvot <[email protected]>
0 siblings, 1 reply; 26+ messages in thread
From: Michael Paquier @ 2026-03-25 23:06 UTC (permalink / raw)
To: Bertrand Drouvot <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
On Wed, Mar 25, 2026 at 07:54:42PM +0000, Bertrand Drouvot wrote:
> If you like the idea, maybe we could introduce query_until_stderr() in a separate
> commit. If you don't, then we could switch to looking in the server logfile
> instead of the session stderr.
I like the patch, but I happen to not like my initial idea of relying
on a NOTICE in an injection point combined with your new API in
BackgroundPsql because we can already achieve the same with a wait
injection point and use BackgroundPsql::query_until() with an \echo to
detect that the command is blocked.
The updated version attached uses this method (edited quickly your
commit message). Like your patch there is no need for hardcoded
sleeps and the CI's first impressions are actually good, but I am
going to need more runs to gain more confidence. Note I should be
able to do something here in 10 days or so. If you could confirm the
stability on your side for the time being with more runs, that would
help, of course.
--
Michael
From fd56d27596834eb019460bffb038aebfa0fa94a4 Mon Sep 17 00:00:00 2001
From: Michael Paquier <[email protected]>
Date: Thu, 26 Mar 2026 08:03:31 +0900
Subject: [PATCH v2] Add tests for lock stats, take two
commit 7c64d56fd97 removed isolation test lock-stats because it was
unstable in the CI for Windows, at least. This commit creates a new
test for the lock stats using an injection point. This new injection
point is created in ProcSleep() when we know that the deadlock timeout
fired.
Then the new tests follow this workflow:
- session 1 holds a lock
- session 2 attaches to the new injection point with the wait action.
- session 2 is blocked by session 1 and waits until the injection point
wait is reached.
- session 1 releases its lock, session 2 commits
- pg_stat_lock is polled until we get the counters for the lock type or
die with a timeout.
That way there is no sleep at all. Once we know that session 2 has
waited longer the deadlock_timeout (thanks to the new injection point
wait) then we can poll pg_stat_lock to get the updated stats.
Author: Bertrand Drouvot <[email protected]>
Discussion: https://postgr.es/m/acNTR1lLHwQJ0o%2BP%40ip-10-97-1-34.eu-west-3.compute.internal
---
src/backend/storage/lmgr/proc.c | 2 +
src/test/modules/test_misc/meson.build | 1 +
.../modules/test_misc/t/011_lock_stats.pl | 249 ++++++++++++++++++
3 files changed, 252 insertions(+)
create mode 100644 src/test/modules/test_misc/t/011_lock_stats.pl
diff --git a/src/backend/storage/lmgr/proc.c b/src/backend/storage/lmgr/proc.c
index 5c47cf13473e..b857a10354f7 100644
--- a/src/backend/storage/lmgr/proc.c
+++ b/src/backend/storage/lmgr/proc.c
@@ -52,6 +52,7 @@
#include "storage/procsignal.h"
#include "storage/spin.h"
#include "storage/standby.h"
+#include "utils/injection_point.h"
#include "utils/timeout.h"
#include "utils/timestamp.h"
#include "utils/wait_event.h"
@@ -1560,6 +1561,7 @@ ProcSleep(LOCALLOCK *locallock)
int usecs;
long msecs;
+ INJECTION_POINT("deadlock-timeout-fired", NULL);
TimestampDifference(get_timeout_start_time(DEADLOCK_TIMEOUT),
GetCurrentTimestamp(),
&secs, &usecs);
diff --git a/src/test/modules/test_misc/meson.build b/src/test/modules/test_misc/meson.build
index 6e8db1621a74..1b25d98f7f33 100644
--- a/src/test/modules/test_misc/meson.build
+++ b/src/test/modules/test_misc/meson.build
@@ -19,6 +19,7 @@ tests += {
't/008_replslot_single_user.pl',
't/009_log_temp_files.pl',
't/010_index_concurrently_upsert.pl',
+ 't/011_lock_stats.pl',
],
# The injection points are cluster-wide, so disable installcheck
'runningcheck': false,
diff --git a/src/test/modules/test_misc/t/011_lock_stats.pl b/src/test/modules/test_misc/t/011_lock_stats.pl
new file mode 100644
index 000000000000..4281e842c981
--- /dev/null
+++ b/src/test/modules/test_misc/t/011_lock_stats.pl
@@ -0,0 +1,249 @@
+
+# Copyright (c) 2026, PostgreSQL Global Development Group
+
+# Test for the lock statistics
+#
+# 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.
+
+use strict;
+use warnings FATAL => 'all';
+
+use PostgreSQL::Test::Cluster;
+use PostgreSQL::Test::Utils;
+use Test::More;
+
+plan skip_all => 'Injection points not supported by this build'
+ unless $ENV{enable_injection_points} eq 'yes';
+
+my $deadlock_timeout = 10;
+my $s1;
+my $s2;
+my $node;
+
+# Setup the 2 sessions
+sub setup_sessions
+{
+ $s1 = $node->background_psql('postgres');
+ $s2 = $node->background_psql('postgres', on_error_stop => 0);
+
+ # Setup injection points for the waiting session
+ $s2->query_safe(q[
+ SELECT injection_points_set_local();
+ SELECT injection_points_attach('deadlock-timeout-fired', 'wait');
+ ]);
+}
+
+# Fetch waits and wait_time from pg_stat_lock for a given lock type
+# until they reached expected values: at least one wait and waiting longer
+# than the deadlock_timeout.
+sub wait_for_pg_stat_lock
+{
+ my ($node, $lock_type) = @_;
+
+ $node->poll_query_until(
+ 'postgres', qq[
+ SELECT waits > 0 AND wait_time >= $deadlock_timeout
+ FROM pg_stat_lock
+ WHERE locktype = '$lock_type';
+ ]) or die "Timed out waiting for pg_stat_lock for $lock_type"
+}
+
+# Convenience wrapper to wait for a point, then detach it.
+sub wait_and_detach
+{
+ my ($node, $point_name) = @_;
+
+ $node->wait_for_event('client backend', $point_name);
+ $node->safe_psql('postgres',
+ "SELECT injection_points_detach('$point_name');");
+ $node->safe_psql('postgres',
+ "SELECT injection_points_wakeup('$point_name');");
+}
+
+# Node initialization
+$node = PostgreSQL::Test::Cluster->new('node');
+$node->init();
+$node->append_conf('postgresql.conf', "deadlock_timeout = ${deadlock_timeout}ms");
+$node->start();
+
+# Check if the extension injection_points is available
+plan skip_all => 'Extension injection_points not installed'
+ unless $node->check_extension('injection_points');
+
+$node->safe_psql('postgres', 'CREATE EXTENSION injection_points;');
+
+$node->safe_psql(
+ 'postgres', q[
+CREATE TABLE test_stat_tab(key text not null, value int);
+INSERT INTO test_stat_tab(key, value) VALUES('k0', 1);
+]);
+
+############################################################################
+
+####### Relation lock
+
+setup_sessions();
+
+$s1->query_safe(
+ q[
+SELECT pg_stat_reset_shared('lock');
+BEGIN;
+LOCK TABLE test_stat_tab;
+]);
+
+# s2 setup
+$s2->query_safe(
+ q[
+BEGIN;
+SELECT pg_stat_force_next_flush();
+]);
+# s2 blocks on LOCK.
+$s2->query_until(
+ qr/lock_s2/, q[
+\echo lock_s2
+LOCK TABLE test_stat_tab;
+]);
+
+wait_and_detach($node, 'deadlock-timeout-fired');
+
+# deadlock_timeout fired, now commit in s1 and s2
+$s1->query_safe(q(COMMIT));
+$s2->query_safe(q(COMMIT));
+
+# check that pg_stat_lock has been updated
+wait_for_pg_stat_lock($node, 'relation');
+ok(1, "Lock stats ok for relation");
+
+# close sessions
+$s1->quit;
+$s2->quit;
+
+####### transaction lock
+
+setup_sessions();
+
+$s1->query_safe(
+ q[
+SELECT pg_stat_reset_shared('lock');
+INSERT INTO test_stat_tab(key, value) VALUES('k1', 1), ('k2', 1), ('k3', 1);
+BEGIN;
+UPDATE test_stat_tab SET value = value + 1 WHERE key = 'k1';
+]);
+
+# s2 setup
+$s2->query_safe(
+ q[
+SET log_lock_waits = on;
+BEGIN;
+SELECT pg_stat_force_next_flush();
+]);
+# s2 blocks here on UPDATE
+$s2->query_until(
+ qr/lock_s2/, q[
+\echo lock_s2
+UPDATE test_stat_tab SET value = value + 1 WHERE key = 'k1';
+]);
+
+wait_and_detach($node, 'deadlock-timeout-fired');
+
+# deadlock_timeout fired, now commit in s1 and s2
+$s1->query_safe(q(COMMIT));
+$s2->query_safe(q(COMMIT));
+
+# check that pg_stat_lock has been updated
+wait_for_pg_stat_lock($node, 'transactionid');
+ok(1, "Lock stats ok for transactionid");
+
+# Close sessions
+$s1->quit;
+$s2->quit;
+
+####### advisory lock
+
+setup_sessions();
+
+$s1->query_safe(
+ q[
+SELECT pg_stat_reset_shared('lock');
+SELECT pg_advisory_lock(1);
+]);
+
+# s2 setup
+$s2->query_safe(
+ q[
+SET log_lock_waits = on;
+BEGIN;
+SELECT pg_stat_force_next_flush();
+]);
+# s2 blocks on the advisory lock.
+$s2->query_until(
+ qr/lock_s2/, q[
+\echo lock_s2
+SELECT pg_advisory_lock(1);
+]);
+
+wait_and_detach($node, 'deadlock-timeout-fired');
+
+# deadlock_timeout fired, now unlock and commit s2
+$s1->query_safe(q(SELECT pg_advisory_unlock(1)));
+$s2->query_safe(
+ q[
+SELECT pg_advisory_unlock(1);
+COMMIT;
+]);
+
+# check that pg_stat_lock has been updated
+wait_for_pg_stat_lock($node, 'advisory');
+ok(1, "Lock stats ok for advisory");
+
+# Close sessions
+$s1->quit;
+$s2->quit;
+
+####### Ensure log_lock_waits has no impact
+
+setup_sessions();
+
+$s1->query_safe(
+ q[
+SELECT pg_stat_reset_shared('lock');
+BEGIN;
+LOCK TABLE test_stat_tab;
+]);
+
+# s2 setup
+$s2->query_safe(
+ q[
+SET log_lock_waits = off;
+BEGIN;
+SELECT pg_stat_force_next_flush();
+]);
+# s2 blocks on LOCK.
+$s2->query_until(
+ qr/lock_s2/, q[
+\echo lock_s2
+LOCK TABLE test_stat_tab;
+]);
+
+wait_and_detach($node, 'deadlock-timeout-fired');
+
+# deadlock_timeout fired, now commit in s1 and s2
+$s1->query_safe(q(COMMIT));
+$s2->query_safe(q(COMMIT));
+
+# check that pg_stat_lock has been updated
+wait_for_pg_stat_lock($node, 'relation');
+ok(1, "log_lock_waits has no impact on Lock stats");
+
+# close sessions
+$s1->quit;
+$s2->quit;
+
+# cleanup
+$node->safe_psql('postgres', q[DROP TABLE test_stat_tab;]);
+
+done_testing();
--
2.53.0
Attachments:
[text/plain] v2-0001-Add-tests-for-lock-stats-take-two.patch (8.4K, 2-v2-0001-Add-tests-for-lock-stats-take-two.patch)
download | inline diff:
From fd56d27596834eb019460bffb038aebfa0fa94a4 Mon Sep 17 00:00:00 2001
From: Michael Paquier <[email protected]>
Date: Thu, 26 Mar 2026 08:03:31 +0900
Subject: [PATCH v2] Add tests for lock stats, take two
commit 7c64d56fd97 removed isolation test lock-stats because it was
unstable in the CI for Windows, at least. This commit creates a new
test for the lock stats using an injection point. This new injection
point is created in ProcSleep() when we know that the deadlock timeout
fired.
Then the new tests follow this workflow:
- session 1 holds a lock
- session 2 attaches to the new injection point with the wait action.
- session 2 is blocked by session 1 and waits until the injection point
wait is reached.
- session 1 releases its lock, session 2 commits
- pg_stat_lock is polled until we get the counters for the lock type or
die with a timeout.
That way there is no sleep at all. Once we know that session 2 has
waited longer the deadlock_timeout (thanks to the new injection point
wait) then we can poll pg_stat_lock to get the updated stats.
Author: Bertrand Drouvot <[email protected]>
Discussion: https://postgr.es/m/acNTR1lLHwQJ0o%2BP%40ip-10-97-1-34.eu-west-3.compute.internal
---
src/backend/storage/lmgr/proc.c | 2 +
src/test/modules/test_misc/meson.build | 1 +
.../modules/test_misc/t/011_lock_stats.pl | 249 ++++++++++++++++++
3 files changed, 252 insertions(+)
create mode 100644 src/test/modules/test_misc/t/011_lock_stats.pl
diff --git a/src/backend/storage/lmgr/proc.c b/src/backend/storage/lmgr/proc.c
index 5c47cf13473e..b857a10354f7 100644
--- a/src/backend/storage/lmgr/proc.c
+++ b/src/backend/storage/lmgr/proc.c
@@ -52,6 +52,7 @@
#include "storage/procsignal.h"
#include "storage/spin.h"
#include "storage/standby.h"
+#include "utils/injection_point.h"
#include "utils/timeout.h"
#include "utils/timestamp.h"
#include "utils/wait_event.h"
@@ -1560,6 +1561,7 @@ ProcSleep(LOCALLOCK *locallock)
int usecs;
long msecs;
+ INJECTION_POINT("deadlock-timeout-fired", NULL);
TimestampDifference(get_timeout_start_time(DEADLOCK_TIMEOUT),
GetCurrentTimestamp(),
&secs, &usecs);
diff --git a/src/test/modules/test_misc/meson.build b/src/test/modules/test_misc/meson.build
index 6e8db1621a74..1b25d98f7f33 100644
--- a/src/test/modules/test_misc/meson.build
+++ b/src/test/modules/test_misc/meson.build
@@ -19,6 +19,7 @@ tests += {
't/008_replslot_single_user.pl',
't/009_log_temp_files.pl',
't/010_index_concurrently_upsert.pl',
+ 't/011_lock_stats.pl',
],
# The injection points are cluster-wide, so disable installcheck
'runningcheck': false,
diff --git a/src/test/modules/test_misc/t/011_lock_stats.pl b/src/test/modules/test_misc/t/011_lock_stats.pl
new file mode 100644
index 000000000000..4281e842c981
--- /dev/null
+++ b/src/test/modules/test_misc/t/011_lock_stats.pl
@@ -0,0 +1,249 @@
+
+# Copyright (c) 2026, PostgreSQL Global Development Group
+
+# Test for the lock statistics
+#
+# 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.
+
+use strict;
+use warnings FATAL => 'all';
+
+use PostgreSQL::Test::Cluster;
+use PostgreSQL::Test::Utils;
+use Test::More;
+
+plan skip_all => 'Injection points not supported by this build'
+ unless $ENV{enable_injection_points} eq 'yes';
+
+my $deadlock_timeout = 10;
+my $s1;
+my $s2;
+my $node;
+
+# Setup the 2 sessions
+sub setup_sessions
+{
+ $s1 = $node->background_psql('postgres');
+ $s2 = $node->background_psql('postgres', on_error_stop => 0);
+
+ # Setup injection points for the waiting session
+ $s2->query_safe(q[
+ SELECT injection_points_set_local();
+ SELECT injection_points_attach('deadlock-timeout-fired', 'wait');
+ ]);
+}
+
+# Fetch waits and wait_time from pg_stat_lock for a given lock type
+# until they reached expected values: at least one wait and waiting longer
+# than the deadlock_timeout.
+sub wait_for_pg_stat_lock
+{
+ my ($node, $lock_type) = @_;
+
+ $node->poll_query_until(
+ 'postgres', qq[
+ SELECT waits > 0 AND wait_time >= $deadlock_timeout
+ FROM pg_stat_lock
+ WHERE locktype = '$lock_type';
+ ]) or die "Timed out waiting for pg_stat_lock for $lock_type"
+}
+
+# Convenience wrapper to wait for a point, then detach it.
+sub wait_and_detach
+{
+ my ($node, $point_name) = @_;
+
+ $node->wait_for_event('client backend', $point_name);
+ $node->safe_psql('postgres',
+ "SELECT injection_points_detach('$point_name');");
+ $node->safe_psql('postgres',
+ "SELECT injection_points_wakeup('$point_name');");
+}
+
+# Node initialization
+$node = PostgreSQL::Test::Cluster->new('node');
+$node->init();
+$node->append_conf('postgresql.conf', "deadlock_timeout = ${deadlock_timeout}ms");
+$node->start();
+
+# Check if the extension injection_points is available
+plan skip_all => 'Extension injection_points not installed'
+ unless $node->check_extension('injection_points');
+
+$node->safe_psql('postgres', 'CREATE EXTENSION injection_points;');
+
+$node->safe_psql(
+ 'postgres', q[
+CREATE TABLE test_stat_tab(key text not null, value int);
+INSERT INTO test_stat_tab(key, value) VALUES('k0', 1);
+]);
+
+############################################################################
+
+####### Relation lock
+
+setup_sessions();
+
+$s1->query_safe(
+ q[
+SELECT pg_stat_reset_shared('lock');
+BEGIN;
+LOCK TABLE test_stat_tab;
+]);
+
+# s2 setup
+$s2->query_safe(
+ q[
+BEGIN;
+SELECT pg_stat_force_next_flush();
+]);
+# s2 blocks on LOCK.
+$s2->query_until(
+ qr/lock_s2/, q[
+\echo lock_s2
+LOCK TABLE test_stat_tab;
+]);
+
+wait_and_detach($node, 'deadlock-timeout-fired');
+
+# deadlock_timeout fired, now commit in s1 and s2
+$s1->query_safe(q(COMMIT));
+$s2->query_safe(q(COMMIT));
+
+# check that pg_stat_lock has been updated
+wait_for_pg_stat_lock($node, 'relation');
+ok(1, "Lock stats ok for relation");
+
+# close sessions
+$s1->quit;
+$s2->quit;
+
+####### transaction lock
+
+setup_sessions();
+
+$s1->query_safe(
+ q[
+SELECT pg_stat_reset_shared('lock');
+INSERT INTO test_stat_tab(key, value) VALUES('k1', 1), ('k2', 1), ('k3', 1);
+BEGIN;
+UPDATE test_stat_tab SET value = value + 1 WHERE key = 'k1';
+]);
+
+# s2 setup
+$s2->query_safe(
+ q[
+SET log_lock_waits = on;
+BEGIN;
+SELECT pg_stat_force_next_flush();
+]);
+# s2 blocks here on UPDATE
+$s2->query_until(
+ qr/lock_s2/, q[
+\echo lock_s2
+UPDATE test_stat_tab SET value = value + 1 WHERE key = 'k1';
+]);
+
+wait_and_detach($node, 'deadlock-timeout-fired');
+
+# deadlock_timeout fired, now commit in s1 and s2
+$s1->query_safe(q(COMMIT));
+$s2->query_safe(q(COMMIT));
+
+# check that pg_stat_lock has been updated
+wait_for_pg_stat_lock($node, 'transactionid');
+ok(1, "Lock stats ok for transactionid");
+
+# Close sessions
+$s1->quit;
+$s2->quit;
+
+####### advisory lock
+
+setup_sessions();
+
+$s1->query_safe(
+ q[
+SELECT pg_stat_reset_shared('lock');
+SELECT pg_advisory_lock(1);
+]);
+
+# s2 setup
+$s2->query_safe(
+ q[
+SET log_lock_waits = on;
+BEGIN;
+SELECT pg_stat_force_next_flush();
+]);
+# s2 blocks on the advisory lock.
+$s2->query_until(
+ qr/lock_s2/, q[
+\echo lock_s2
+SELECT pg_advisory_lock(1);
+]);
+
+wait_and_detach($node, 'deadlock-timeout-fired');
+
+# deadlock_timeout fired, now unlock and commit s2
+$s1->query_safe(q(SELECT pg_advisory_unlock(1)));
+$s2->query_safe(
+ q[
+SELECT pg_advisory_unlock(1);
+COMMIT;
+]);
+
+# check that pg_stat_lock has been updated
+wait_for_pg_stat_lock($node, 'advisory');
+ok(1, "Lock stats ok for advisory");
+
+# Close sessions
+$s1->quit;
+$s2->quit;
+
+####### Ensure log_lock_waits has no impact
+
+setup_sessions();
+
+$s1->query_safe(
+ q[
+SELECT pg_stat_reset_shared('lock');
+BEGIN;
+LOCK TABLE test_stat_tab;
+]);
+
+# s2 setup
+$s2->query_safe(
+ q[
+SET log_lock_waits = off;
+BEGIN;
+SELECT pg_stat_force_next_flush();
+]);
+# s2 blocks on LOCK.
+$s2->query_until(
+ qr/lock_s2/, q[
+\echo lock_s2
+LOCK TABLE test_stat_tab;
+]);
+
+wait_and_detach($node, 'deadlock-timeout-fired');
+
+# deadlock_timeout fired, now commit in s1 and s2
+$s1->query_safe(q(COMMIT));
+$s2->query_safe(q(COMMIT));
+
+# check that pg_stat_lock has been updated
+wait_for_pg_stat_lock($node, 'relation');
+ok(1, "log_lock_waits has no impact on Lock stats");
+
+# close sessions
+$s1->quit;
+$s2->quit;
+
+# cleanup
+$node->safe_psql('postgres', q[DROP TABLE test_stat_tab;]);
+
+done_testing();
--
2.53.0
[application/pgp-signature] signature.asc (833B, 3-signature.asc)
download
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-26 04:05 Bertrand Drouvot <[email protected]>
parent: Michael Paquier <[email protected]>
0 siblings, 1 reply; 26+ messages in thread
From: Bertrand Drouvot @ 2026-03-26 04:05 UTC (permalink / raw)
To: Michael Paquier <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
Hi,
On Thu, Mar 26, 2026 at 08:06:20AM +0900, Michael Paquier wrote:
>
> I like the patch, but I happen to not like my initial idea of relying
> on a NOTICE in an injection point combined with your new API in
> BackgroundPsql because we can already achieve the same with a wait
> injection point and use BackgroundPsql::query_until() with an \echo to
> detect that the command is blocked.
Yeah that works too.
> The updated version attached uses this method (edited quickly your
> commit message). Like your patch there is no need for hardcoded
> sleeps and the CI's first impressions are actually good,
Same here.
> but I am
> going to need more runs to gain more confidence. Note I should be
> able to do something here in 10 days or so. If you could confirm the
> stability on your side for the time being with more runs, that would
> help, of course.
With wait + echo we don't need s2 to "on_error_stop => 0" anymore. I changed
that in the attached. I'll run more CI tests during those 10 days. Let's sync
up when you'll be about to push it.
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-26 06:53 Michael Paquier <[email protected]>
parent: Bertrand Drouvot <[email protected]>
0 siblings, 0 replies; 26+ messages in thread
From: Michael Paquier @ 2026-03-26 06:53 UTC (permalink / raw)
To: Bertrand Drouvot <[email protected]>; +Cc: Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
On Thu, Mar 26, 2026 at 04:05:40AM +0000, Bertrand Drouvot wrote:
> With wait + echo we don't need s2 to "on_error_stop => 0" anymore. I changed
> that in the attached.
Indeed.
> I'll run more CI tests during those 10 days. Let's sync
> up when you'll be about to push it.
.
Thanks.
--
Michael
Attachments:
[application/pgp-signature] signature.asc (833B, 2-signature.asc)
download
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-03-31 07:10 Bertrand Drouvot <[email protected]>
parent: Michael Paquier <[email protected]>
1 sibling, 1 reply; 26+ messages in thread
From: Bertrand Drouvot @ 2026-03-31 07:10 UTC (permalink / raw)
To: Tomas Vondra <[email protected]>; +Cc: Michael Paquier <[email protected]>; Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
Hi,
On Mon, Mar 30, 2026 at 06:11:17PM +0200, Tomas Vondra wrote:
> Hi,
>
> Isn't pgstat_lock_flush_cb a bit broken with nowait=true? It'll skip
> flushing stats for that particular lock type, but then it'll happily
> reset the pending stats anyway, forgetting the stats.
>
> AFAIK it should keep the pending stats, and flush them sometime lager,
> when the lock is not contended. That's what the other flush callbacks
> do, at least. This probably means it needs to reset the entries one by
> one, not the whole struct at once.
Oh right, it's currently misbehaving, thanks for the warning!
> TBH I'm rather skeptical about having one lock per entry. Sure, it
> allows two backends to write different entries concurrently. But is it
> actually worth it? With nowait=true it might even be cheaper to try with
> a single lock, and AFAICS that's the case where it matters.
>
> I wouldn't be surprised if this behaved quite poorly with contended
> cases, because the backends will be accessing the locks in exactly the
> same order and synchronize. So if one lock is contended, won't that
> "synchronize" the backends, making the other locks contended too?
>
> Has anyone tested it actually improves the behavior? I only quickly
> skimmed the thread, I might have missed it ...
>
I just did a few tests, with a per entry lock version fixed (to avoid the bug
mentioned above) and with a single lock.
The test is this one:
Setup:
deadlock_timeout set to 1ms.
CREATE TABLE t1(id int primary key, v int);
CREATE TABLE t2(id int primary key, v int);
INSERT INTO t1 SELECT i, 0 FROM generate_series(1,100) i;
INSERT INTO t2 SELECT i, 0 FROM generate_series(1,100) i;
test.sql:
\set id1 random(1, 100)
\set id2 random(1, 100)
BEGIN;
SELECT pg_advisory_xact_lock(:id1);
UPDATE t1 SET v=v+1 WHERE id=:id1;
UPDATE t2 SET v=v+1 WHERE id=:id2;
END;
Launched that way:
pgbench -c 32 -j 32 -T60 -f test.sql
One run produces, something like:
postgres=# select locktype, waits, wait_time from pg_stat_lock where waits > 0;
locktype | waits | wait_time
---------------+--------+-----------
tuple | 5058 | 5092
transactionid | 78287 | 79269
advisory | 105005 | 177253
(3 rows)
With one lock per entry, the avg (the test has been run 5 times) tps is 12099.
With one single lock, the avg (the test has been run 5 times) tps is 12118.
The difference looks like noise so that one lock per entry does not show
improved performance.
Also both kind of tests produce this perf profile:
0.00% 0.00% postgres postgres [.] pgstat_lock_flush_cb
So, I'm tempted to say that one lock per entry adds complexity without observable
performance benefit. Also one single lock matches more naturally the intent of the
nowait path and I would also not be surprised if one lock per entry behaves
worse in some cases.
So, PFA a patch to move to a single lock instead.
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-04-06 05:11 Michael Paquier <[email protected]>
parent: Bertrand Drouvot <[email protected]>
0 siblings, 1 reply; 26+ messages in thread
From: Michael Paquier @ 2026-04-06 05:11 UTC (permalink / raw)
To: Bertrand Drouvot <[email protected]>; +Cc: Tomas Vondra <[email protected]>; Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
On Tue, Mar 31, 2026 at 07:10:51AM +0000, Bertrand Drouvot wrote:
> On Mon, Mar 30, 2026 at 06:11:17PM +0200, Tomas Vondra wrote:
>> Isn't pgstat_lock_flush_cb a bit broken with nowait=true? It'll skip
>> flushing stats for that particular lock type, but then it'll happily
>> reset the pending stats anyway, forgetting the stats.
>>
>> AFAIK it should keep the pending stats, and flush them sometime lager,
>> when the lock is not contended. That's what the other flush callbacks
>> do, at least. This probably means it needs to reset the entries one by
>> one, not the whole struct at once.
>
> Oh right, it's currently misbehaving, thanks for the warning!
Not misbehaving, mistaken. This would create loss of stats data that
should have been flushed. I should not have missed that, sorry about
that. A single-lock approach is also something we do for SLRU and WAL
data, and these are much hotter.
At the exception of one comment that could be simplified, the code
removed is correct, so addressed this one as well.
--
Michael
Attachments:
[application/pgp-signature] signature.asc (833B, 2-signature.asc)
download
^ permalink raw reply [nested|flat] 26+ messages in thread
* Re: Adding locks statistics
@ 2026-04-07 06:02 Bertrand Drouvot <[email protected]>
parent: Michael Paquier <[email protected]>
0 siblings, 0 replies; 26+ messages in thread
From: Bertrand Drouvot @ 2026-04-07 06:02 UTC (permalink / raw)
To: Michael Paquier <[email protected]>; +Cc: Tomas Vondra <[email protected]>; Andres Freund <[email protected]>; Jeff Davis <[email protected]>; Greg Sabino Mullane <[email protected]>; [email protected]
Hi,
On Mon, Apr 06, 2026 at 02:11:21PM +0900, Michael Paquier wrote:
> On Tue, Mar 31, 2026 at 07:10:51AM +0000, Bertrand Drouvot wrote:
> > On Mon, Mar 30, 2026 at 06:11:17PM +0200, Tomas Vondra wrote:
> >> Isn't pgstat_lock_flush_cb a bit broken with nowait=true? It'll skip
> >> flushing stats for that particular lock type, but then it'll happily
> >> reset the pending stats anyway, forgetting the stats.
> >>
> >> AFAIK it should keep the pending stats, and flush them sometime lager,
> >> when the lock is not contended. That's what the other flush callbacks
> >> do, at least. This probably means it needs to reset the entries one by
> >> one, not the whole struct at once.
> >
> > Oh right, it's currently misbehaving, thanks for the warning!
>
> I should not have missed that,
So do I...
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
^ permalink raw reply [nested|flat] 26+ messages in thread
end of thread, other threads:[~2026-04-07 06:02 UTC | newest]
Thread overview: 26+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2026-02-20 16:02 Re: Adding locks statistics Andres Freund <[email protected]>
2026-02-20 17:26 ` Bertrand Drouvot <[email protected]>
2026-02-27 05:14 ` Bertrand Drouvot <[email protected]>
2026-03-18 04:36 ` Bertrand Drouvot <[email protected]>
2026-03-18 08:15 ` Michael Paquier <[email protected]>
2026-03-18 14:51 ` Bertrand Drouvot <[email protected]>
2026-03-19 07:01 ` Michael Paquier <[email protected]>
2026-03-19 12:25 ` Bertrand Drouvot <[email protected]>
2026-03-21 05:55 ` Michael Paquier <[email protected]>
2026-03-21 20:01 ` Álvaro Herrera <[email protected]>
2026-03-23 08:18 ` Bertrand Drouvot <[email protected]>
2026-03-24 03:15 ` Michael Paquier <[email protected]>
2026-03-25 03:32 ` Bertrand Drouvot <[email protected]>
2026-03-24 07:02 ` Michael Paquier <[email protected]>
2026-03-24 20:09 ` Andres Freund <[email protected]>
2026-03-24 23:46 ` Michael Paquier <[email protected]>
2026-03-25 03:15 ` Bertrand Drouvot <[email protected]>
2026-03-25 05:25 ` Michael Paquier <[email protected]>
2026-03-25 07:24 ` Bertrand Drouvot <[email protected]>
2026-03-25 19:54 ` Bertrand Drouvot <[email protected]>
2026-03-25 23:06 ` Michael Paquier <[email protected]>
2026-03-26 04:05 ` Bertrand Drouvot <[email protected]>
2026-03-26 06:53 ` Michael Paquier <[email protected]>
2026-03-31 07:10 ` Bertrand Drouvot <[email protected]>
2026-04-06 05:11 ` Michael Paquier <[email protected]>
2026-04-07 06:02 ` Bertrand Drouvot <[email protected]>
This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox