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
>From d46f85045e7d20f5fead3d1afdd508a3ad270b8d Mon Sep 17 00:00:00 2001 From: Bertrand Drouvot <[email protected]> Date: Thu, 19 Mar 2026 09:50:06 +0000 Subject: [PATCH v11 1/3] Add storage/locktag.h Move LockTagType, LOCKTAG_LAST_TYPE, LockTagTypeNames and LOCKTAG out of storage/lock.h into a new storage/locktag.h header. This will avoid pulling in the heavyweight storage/lock.h header from pgstat.h in a following commit. Author: Bertrand Drouvot <[email protected]> Discussion: https://postgr.es/m/abufUya2oK-_PJ3E%40paquier.xyz --- src/include/storage/lock.h | 47 +------------------------- src/include/storage/locktag.h | 63 +++++++++++++++++++++++++++++++++++ 2 files changed, 64 insertions(+), 46 deletions(-) 100.0% src/include/storage/ diff --git a/src/include/storage/lock.h b/src/include/storage/lock.h index 55ffaa5e4a5..e72d94bba49 100644 --- a/src/include/storage/lock.h +++ b/src/include/storage/lock.h @@ -21,6 +21,7 @@ #include "access/transam.h" #include "lib/ilist.h" #include "storage/lockdefs.h" +#include "storage/locktag.h" #include "storage/lwlock.h" #include "storage/procnumber.h" #include "storage/shmem.h" @@ -127,52 +128,6 @@ typedef uint16 LOCKMETHODID; #define DEFAULT_LOCKMETHOD 1 #define USER_LOCKMETHOD 2 -/* - * LOCKTAG is the key information needed to look up a LOCK item in the - * lock hashtable. A LOCKTAG value uniquely identifies a lockable object. - * - * The LockTagType enum defines the different kinds of objects we can lock. - * We can handle up to 256 different LockTagTypes. - */ -typedef enum LockTagType -{ - LOCKTAG_RELATION, /* whole relation */ - LOCKTAG_RELATION_EXTEND, /* the right to extend a relation */ - LOCKTAG_DATABASE_FROZEN_IDS, /* pg_database.datfrozenxid */ - LOCKTAG_PAGE, /* one page of a relation */ - LOCKTAG_TUPLE, /* one physical tuple */ - LOCKTAG_TRANSACTION, /* transaction (for waiting for xact done) */ - LOCKTAG_VIRTUALTRANSACTION, /* virtual transaction (ditto) */ - LOCKTAG_SPECULATIVE_TOKEN, /* speculative insertion Xid and token */ - LOCKTAG_OBJECT, /* non-relation database object */ - LOCKTAG_USERLOCK, /* reserved for old contrib/userlock code */ - LOCKTAG_ADVISORY, /* advisory user locks */ - LOCKTAG_APPLY_TRANSACTION, /* transaction being applied on a logical - * replication subscriber */ -} LockTagType; - -#define LOCKTAG_LAST_TYPE LOCKTAG_APPLY_TRANSACTION - -extern PGDLLIMPORT const char *const LockTagTypeNames[]; - -/* - * The LOCKTAG struct is defined with malice aforethought to fit into 16 - * bytes with no padding. Note that this would need adjustment if we were - * to widen Oid, BlockNumber, or TransactionId to more than 32 bits. - * - * We include lockmethodid in the locktag so that a single hash table in - * shared memory can store locks of different lockmethods. - */ -typedef struct LOCKTAG -{ - uint32 locktag_field1; /* a 32-bit ID field */ - uint32 locktag_field2; /* a 32-bit ID field */ - uint32 locktag_field3; /* a 32-bit ID field */ - uint16 locktag_field4; /* a 16-bit ID field */ - uint8 locktag_type; /* see enum LockTagType */ - uint8 locktag_lockmethodid; /* lockmethod indicator */ -} LOCKTAG; - /* * These macros define how we map logical IDs of lockable objects into * the physical fields of LOCKTAG. Use these to set up LOCKTAG values, diff --git a/src/include/storage/locktag.h b/src/include/storage/locktag.h new file mode 100644 index 00000000000..22ad9c22798 --- /dev/null +++ b/src/include/storage/locktag.h @@ -0,0 +1,63 @@ +/*------------------------------------------------------------------------- + * + * locktag.h + * POSTGRES LOCKTAG to look up a LOCK item in the lock hashtable. + * + * + * Portions Copyright (c) 1996-2026, PostgreSQL Global Development Group + * Portions Copyright (c) 1994, Regents of the University of California + * + * src/include/storage/locktag.h + * + *------------------------------------------------------------------------- + */ +#ifndef LOCKTAG_H_ +#define LOCKTAG_H_ + +/* + * LOCKTAG is the key information needed to look up a LOCK item in the + * lock hashtable. A LOCKTAG value uniquely identifies a lockable object. + * + * The LockTagType enum defines the different kinds of objects we can lock. + * We can handle up to 256 different LockTagTypes. + */ +typedef enum LockTagType +{ + LOCKTAG_RELATION, /* whole relation */ + LOCKTAG_RELATION_EXTEND, /* the right to extend a relation */ + LOCKTAG_DATABASE_FROZEN_IDS, /* pg_database.datfrozenxid */ + LOCKTAG_PAGE, /* one page of a relation */ + LOCKTAG_TUPLE, /* one physical tuple */ + LOCKTAG_TRANSACTION, /* transaction (for waiting for xact done) */ + LOCKTAG_VIRTUALTRANSACTION, /* virtual transaction (ditto) */ + LOCKTAG_SPECULATIVE_TOKEN, /* speculative insertion Xid and token */ + LOCKTAG_OBJECT, /* non-relation database object */ + LOCKTAG_USERLOCK, /* reserved for old contrib/userlock code */ + LOCKTAG_ADVISORY, /* advisory user locks */ + LOCKTAG_APPLY_TRANSACTION, /* transaction being applied on a logical + * replication subscriber */ +} LockTagType; + +#define LOCKTAG_LAST_TYPE LOCKTAG_APPLY_TRANSACTION + +extern PGDLLIMPORT const char *const LockTagTypeNames[]; + +/* + * The LOCKTAG struct is defined with malice aforethought to fit into 16 + * bytes with no padding. Note that this would need adjustment if we were + * to widen Oid, BlockNumber, or TransactionId to more than 32 bits. + * + * We include lockmethodid in the locktag so that a single hash table in + * shared memory can store locks of different lockmethods. + */ +typedef struct LOCKTAG +{ + uint32 locktag_field1; /* a 32-bit ID field */ + uint32 locktag_field2; /* a 32-bit ID field */ + uint32 locktag_field3; /* a 32-bit ID field */ + uint16 locktag_field4; /* a 16-bit ID field */ + uint8 locktag_type; /* see enum LockTagType */ + uint8 locktag_lockmethodid; /* lockmethod indicator */ +} LOCKTAG; + +#endif /* LOCKTAG_H_ */ -- 2.34.1
>From 48c398db3600cc40e3e75cfd767afa90696472b3 Mon Sep 17 00:00:00 2001 From: Bertrand Drouvot <[email protected]> Date: Tue, 29 Jul 2025 08:36:35 +0000 Subject: [PATCH v11 2/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 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 Author: Bertrand Drouvot <[email protected]> Reviewed-by: Andres Freund <[email protected]> Discussion: https://postgr.es/m/aIyNxBWFCybgBZBS%40ip-10-97-1-34.eu-west-3.compute.internal --- src/backend/storage/lmgr/lock.c | 61 +++++--- src/backend/storage/lmgr/proc.c | 188 ++++++++++++----------- 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 | 170 ++++++++++++++++++++ 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, 384 insertions(+), 112 deletions(-) 61.8% src/backend/storage/lmgr/ 29.9% src/backend/utils/activity/ 3.8% src/include/utils/ 3.9% src/include/ diff --git a/src/backend/storage/lmgr/lock.c b/src/backend/storage/lmgr/lock.c index d930c66cdbd..81319cfff2a 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,36 +985,48 @@ 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; + if (FastPathLocalUseCounts[FAST_PATH_REL_GROUP(locktag->locktag_field2)] < + FP_LOCK_SLOTS_PER_GROUP) + { + 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; + /* + * 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) + { + /* + * 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 - 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. + * Increment the lock statistics counter. That's OK from an + * overhead point of view as we are outside the fastpath code + * path. */ - locallock->lock = NULL; - locallock->proclock = NULL; - GrantLockLocal(locallock, owner); - return LOCKACQUIRE_OK; + 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 8f5ce0e2a8a..72456151aa3 100644 --- a/src/backend/storage/lmgr/proc.c +++ b/src/backend/storage/lmgr/proc.c @@ -1549,122 +1549,138 @@ ProcSleep(LOCALLOCK *locallock) } /* - * If awoken after the deadlock check interrupt has run, and - * log_lock_waits is on, then report about the wait. + * If awoken after the deadlock check interrupt has run, increment the + * lock statistics counters and if log_lock_waits is on, then report + * about the wait. */ - if (log_lock_waits && deadlock_state != DS_NOT_YET_CHECKED) + if (deadlock_state != DS_NOT_YET_CHECKED) { - StringInfoData buf, - lock_waiters_sbuf, - lock_holders_sbuf; - const char *modename; long secs; int usecs; long msecs; - int lockHoldersNum = 0; - initStringInfo(&buf); - initStringInfo(&lock_waiters_sbuf); - initStringInfo(&lock_holders_sbuf); - - DescribeLockTag(&buf, &locallock->tag.lock); - modename = GetLockmodeName(locallock->tag.lock.locktag_lockmethodid, - lockmode); TimestampDifference(get_timeout_start_time(DEADLOCK_TIMEOUT), GetCurrentTimestamp(), &secs, &usecs); msecs = secs * 1000 + usecs / 1000; usecs = usecs % 1000; - /* Gather a list of all lock holders and waiters */ - LWLockAcquire(partitionLock, LW_SHARED); - GetLockHoldersAndWaiters(locallock, &lock_holders_sbuf, - &lock_waiters_sbuf, &lockHoldersNum); - LWLockRelease(partitionLock); - - if (deadlock_state == DS_SOFT_DEADLOCK) - ereport(LOG, - (errmsg("process %d avoided deadlock for %s on %s by rearranging queue order after %ld.%03d ms", - MyProcPid, modename, buf.data, msecs, usecs), - (errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.", - "Processes holding the lock: %s. Wait queue: %s.", - lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data)))); - else if (deadlock_state == DS_HARD_DEADLOCK) - { - /* - * This message is a bit redundant with the error that will be - * reported subsequently, but in some cases the error report - * might not make it to the log (eg, if it's caught by an - * exception handler), and we want to ensure all long-wait - * events get logged. - */ - ereport(LOG, - (errmsg("process %d detected deadlock while waiting for %s on %s after %ld.%03d ms", - MyProcPid, modename, buf.data, msecs, usecs), - (errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.", - "Processes holding the lock: %s. Wait queue: %s.", - lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data)))); - } + /* + * Increment the lock statistics counters. That's OK from an + * overhead point of view as we are already stuck behind a lock + * for more than the deadlock timeout and we can reuse its wait + * time computation here. + */ + if (myWaitStatus == PROC_WAIT_STATUS_OK) + pgstat_count_lock_waits(locallock->tag.lock.locktag_type, msecs); - if (myWaitStatus == PROC_WAIT_STATUS_WAITING) + if (log_lock_waits) { - /* - * Guard the "still waiting on lock" log message so it is - * reported at most once while waiting for the lock. - * - * Without this guard, the message can be emitted whenever the - * lock-wait sleep is interrupted (for example by SIGHUP for - * config reload or by client_connection_check_interval). For - * example, if client_connection_check_interval is set very - * low (e.g., 100 ms), the message could be logged repeatedly, - * flooding the log and making it difficult to use. - */ - if (!logged_lock_wait) - { + StringInfoData buf, + lock_waiters_sbuf, + lock_holders_sbuf; + const char *modename; + int lockHoldersNum = 0; + + initStringInfo(&buf); + initStringInfo(&lock_waiters_sbuf); + initStringInfo(&lock_holders_sbuf); + + DescribeLockTag(&buf, &locallock->tag.lock); + modename = GetLockmodeName(locallock->tag.lock.locktag_lockmethodid, + lockmode); + + /* Gather a list of all lock holders and waiters */ + LWLockAcquire(partitionLock, LW_SHARED); + GetLockHoldersAndWaiters(locallock, &lock_holders_sbuf, + &lock_waiters_sbuf, &lockHoldersNum); + LWLockRelease(partitionLock); + + if (deadlock_state == DS_SOFT_DEADLOCK) ereport(LOG, - (errmsg("process %d still waiting for %s on %s after %ld.%03d ms", + (errmsg("process %d avoided deadlock for %s on %s by rearranging queue order after %ld.%03d ms", MyProcPid, modename, buf.data, msecs, usecs), (errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.", "Processes holding the lock: %s. Wait queue: %s.", lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data)))); - logged_lock_wait = true; - } - } - else if (myWaitStatus == PROC_WAIT_STATUS_OK) - ereport(LOG, - (errmsg("process %d acquired %s on %s after %ld.%03d ms", - MyProcPid, modename, buf.data, msecs, usecs))); - else - { - Assert(myWaitStatus == PROC_WAIT_STATUS_ERROR); - - /* - * Currently, the deadlock checker always kicks its own - * process, which means that we'll only see - * PROC_WAIT_STATUS_ERROR when deadlock_state == - * DS_HARD_DEADLOCK, and there's no need to print redundant - * messages. But for completeness and future-proofing, print - * a message if it looks like someone else kicked us off the - * lock. - */ - if (deadlock_state != DS_HARD_DEADLOCK) + else if (deadlock_state == DS_HARD_DEADLOCK) + { + /* + * This message is a bit redundant with the error that + * will be reported subsequently, but in some cases the + * error report might not make it to the log (eg, if it's + * caught by an exception handler), and we want to ensure + * all long-wait events get logged. + */ ereport(LOG, - (errmsg("process %d failed to acquire %s on %s after %ld.%03d ms", + (errmsg("process %d detected deadlock while waiting for %s on %s after %ld.%03d ms", MyProcPid, modename, buf.data, msecs, usecs), (errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.", "Processes holding the lock: %s. Wait queue: %s.", lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data)))); + } + + if (myWaitStatus == PROC_WAIT_STATUS_WAITING) + { + /* + * Guard the "still waiting on lock" log message so it is + * reported at most once while waiting for the lock. + * + * Without this guard, the message can be emitted whenever + * the lock-wait sleep is interrupted (for example by + * SIGHUP for config reload or by + * client_connection_check_interval). For example, if + * client_connection_check_interval is set very low (e.g., + * 100 ms), the message could be logged repeatedly, + * flooding the log and making it difficult to use. + */ + if (!logged_lock_wait) + { + ereport(LOG, + (errmsg("process %d still waiting for %s on %s after %ld.%03d ms", + MyProcPid, modename, buf.data, msecs, usecs), + (errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.", + "Processes holding the lock: %s. Wait queue: %s.", + lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data)))); + logged_lock_wait = true; + } + } + else if (myWaitStatus == PROC_WAIT_STATUS_OK) + ereport(LOG, + (errmsg("process %d acquired %s on %s after %ld.%03d ms", + MyProcPid, modename, buf.data, msecs, usecs))); + else + { + Assert(myWaitStatus == PROC_WAIT_STATUS_ERROR); + + /* + * Currently, the deadlock checker always kicks its own + * process, which means that we'll only see + * PROC_WAIT_STATUS_ERROR when deadlock_state == + * DS_HARD_DEADLOCK, and there's no need to print + * redundant messages. But for completeness and + * future-proofing, print a message if it looks like + * someone else kicked us off the lock. + */ + if (deadlock_state != DS_HARD_DEADLOCK) + ereport(LOG, + (errmsg("process %d failed to acquire %s on %s after %ld.%03d ms", + MyProcPid, modename, buf.data, msecs, usecs), + (errdetail_log_plural("Process holding the lock: %s. Wait queue: %s.", + "Processes holding the lock: %s. Wait queue: %s.", + lockHoldersNum, lock_holders_sbuf.data, lock_waiters_sbuf.data)))); + } + pfree(buf.data); + pfree(lock_holders_sbuf.data); + pfree(lock_waiters_sbuf.data); } /* * At this point we might still need to wait for the lock. Reset - * state so we don't print the above messages again. + * state so we don't print the above messages again if + * log_lock_waits is on. */ 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/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..fe330eb99b1 --- /dev/null +++ b/src/backend/utils/activity/pgstat_lock.c @@ -0,0 +1,170 @@ +/* ------------------------------------------------------------------------- + * + * 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-2026, 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); + } +} + +/* + * Increment a statistic per lock type + * + * Don't call this function for every lock acquisition and in hot path. + */ +#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) + +/* + * Increment the number of waits and wait time per lock type + * + * Don't call this function for every lock acquisition and in hot path. + */ +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 216b93492ba..553106025da 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/locktag.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" @@ -345,6 +346,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; @@ -617,6 +636,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 4673eca9cd6..cf00072a9b2 100644 --- a/src/tools/pgindent/typedefs.list +++ b/src/tools/pgindent/typedefs.list @@ -2276,6 +2276,7 @@ PgStatShared_Database PgStatShared_Function PgStatShared_HashEntry PgStatShared_IO +PgStatShared_Lock PgStatShared_Relation PgStatShared_ReplSlot PgStatShared_SLRU @@ -2298,8 +2299,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
>From fa264ed2fd5d7ee44f50cd6e3f906b2cc9c13eb3 Mon Sep 17 00:00:00 2001 From: Bertrand Drouvot <[email protected]> Date: Thu, 31 Jul 2025 09:35:31 +0000 Subject: [PATCH v11 3/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 Author: Bertrand Drouvot <[email protected]> Reviewed-by: Andres Freund <[email protected]> Discussion: https://postgr.es/m/aIyNxBWFCybgBZBS%40ip-10-97-1-34.eu-west-3.compute.internal --- doc/src/sgml/monitoring.sgml | 111 ++++++++++++ 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/lock-stats.out | 190 +++++++++++++++++++++ src/test/isolation/isolation_schedule | 1 + src/test/isolation/specs/lock-stats.spec | 125 ++++++++++++++ src/test/regress/expected/rules.out | 6 + src/test/regress/expected/stats.out | 48 ++++++ src/test/regress/sql/stats.sql | 36 ++++ 12 files changed, 583 insertions(+) 19.9% doc/src/sgml/ 6.4% src/backend/utils/adt/ 35.1% src/test/isolation/expected/ 20.8% src/test/isolation/specs/ 7.4% src/test/regress/expected/ 5.2% src/test/regress/sql/ 4.8% src/ diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml index 462019a972c..d590ecad541 100644 --- a/doc/src/sgml/monitoring.sgml +++ b/doc/src/sgml/monitoring.sgml @@ -509,6 +509,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 @@ -3283,6 +3292,102 @@ 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 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 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> @@ -5372,6 +5477,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 f1ed7b58f13..e54018004db 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 fe330eb99b1..76749e4724d 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 5f907335990..9185a8e6b83 100644 --- a/src/backend/utils/adt/pgstatfuncs.c +++ b/src/backend/utils/adt/pgstatfuncs.c @@ -1741,6 +1741,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. */ @@ -1925,6 +1961,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); @@ -1942,6 +1979,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 fc8d82665b8..3e2c43e9d1b 100644 --- a/src/include/catalog/pg_proc.dat +++ b/src/include/catalog/pg_proc.dat @@ -6041,6 +6041,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 553106025da..dadf8b1c1ed 100644 --- a/src/include/pgstat.h +++ b/src/include/pgstat.h @@ -643,6 +643,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/lock-stats.out b/src/test/isolation/expected/lock-stats.out new file mode 100644 index 00000000000..556c210a28b --- /dev/null +++ b/src/test/isolation/expected/lock-stats.out @@ -0,0 +1,190 @@ +Parsed test spec with 2 sessions + +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.05); +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 > 50 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.05); +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 > 50 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.05); +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 > 50 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.05); +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 > 50 FROM pg_stat_lock WHERE locktype = 'relation'; +?column?|?column? +--------+-------- +t |t +(1 row) + diff --git a/src/test/isolation/isolation_schedule b/src/test/isolation/isolation_schedule index 4e466580cd4..2cc86849c9a 100644 --- a/src/test/isolation/isolation_schedule +++ b/src/test/isolation/isolation_schedule @@ -43,6 +43,7 @@ test: eval-plan-qual-trigger test: inplace-inval test: intra-grant-inplace test: intra-grant-inplace-db +test: lock-stats test: lock-update-delete test: lock-update-traversal test: inherit-temp diff --git a/src/test/isolation/specs/lock-stats.spec b/src/test/isolation/specs/lock-stats.spec new file mode 100644 index 00000000000..e4e66a9fb4d --- /dev/null +++ b/src/test/isolation/specs/lock-stats.spec @@ -0,0 +1,125 @@ +# Test for the lock statistics +# +# This test creates multiple locking situations when a session (s2) has to +# wait on a lock for longer than the deadlock timeout. The first permutations +# each test a dedicated lock type. The last permutation ensures that +# log_lock_waits has no impact on the statistics counters. + +setup +{ + CREATE TABLE test_stat_tab(key text not null, value int); + INSERT INTO test_stat_tab(key, value) VALUES('k0', 1); + SELECT pg_stat_force_next_flush(); +} + +teardown +{ + DROP TABLE IF EXISTS test_stat_tab; +} + +session s1 +setup { SET stats_fetch_consistency = 'none'; } +step s1_begin { BEGIN; } +step s1_commit { COMMIT; } +step s1_table_insert { INSERT INTO test_stat_tab(key, value) VALUES('k1', 1), ('k2', 1), ('k3', 1);} +step s1_table_update_k1 { UPDATE test_stat_tab SET value = value + 1 WHERE key = 'k1';} +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.05); } +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'; } +step s2_begin { BEGIN; } +step s2_commit { COMMIT; } +step s2_ff { SELECT pg_stat_force_next_flush(); } +step s2_table_update_k1 { UPDATE test_stat_tab SET value = value + 1 WHERE key = 'k1';} +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 > 50 FROM pg_stat_lock WHERE locktype = 'relation'; } +step s2_report_stat_lock_transactionid { SELECT waits > 0, wait_time > 50 FROM pg_stat_lock WHERE locktype = 'transactionid'; } +step s2_report_stat_lock_advisory { SELECT waits > 0, wait_time > 50 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); } + +###################### +# 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 has no impact + +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 32bea58db2c..2b3cf6d8569 100644 --- a/src/test/regress/expected/rules.out +++ b/src/test/regress/expected/rules.out @@ -1952,6 +1952,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 b99462bf946..ea7f7846895 100644 --- a/src/test/regress/expected/stats.out +++ b/src/test/regress/expected/stats.out @@ -1958,4 +1958,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 941222cf0be..65d8968c83e 100644 --- a/src/test/regress/sql/stats.sql +++ b/src/test/regress/sql/stats.sql @@ -964,4 +964,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
