From 30fe57ed7fd72f86f233edd9bab0fd8c20099dba Mon Sep 17 00:00:00 2001 From: Michael Paquier Date: Thu, 5 Dec 2024 13:25:35 +0900 Subject: [PATCH 2/2] Add various logs in pgstats to debug entry handling Not for commit, nice to play with. --- src/backend/utils/activity/pgstat_replslot.c | 1 + src/backend/utils/activity/pgstat_shmem.c | 37 ++++++++++++++++++++ 2 files changed, 38 insertions(+) diff --git a/src/backend/utils/activity/pgstat_replslot.c b/src/backend/utils/activity/pgstat_replslot.c index ddf2ab9928..e41806d7f6 100644 --- a/src/backend/utils/activity/pgstat_replslot.c +++ b/src/backend/utils/activity/pgstat_replslot.c @@ -157,6 +157,7 @@ pgstat_drop_replslot(ReplicationSlot *slot) { Assert(LWLockHeldByMeInMode(ReplicationSlotAllocationLock, LW_EXCLUSIVE)); + elog(WARNING, "XXX pgstat_drop_replslot index %d", ReplicationSlotIndex(slot)); if (!pgstat_drop_entry(PGSTAT_KIND_REPLSLOT, InvalidOid, ReplicationSlotIndex(slot))) pgstat_request_entry_refs_gc(); diff --git a/src/backend/utils/activity/pgstat_shmem.c b/src/backend/utils/activity/pgstat_shmem.c index ccb5e5f6de..f717b52226 100644 --- a/src/backend/utils/activity/pgstat_shmem.c +++ b/src/backend/utils/activity/pgstat_shmem.c @@ -296,6 +296,7 @@ pgstat_init_entry(PgStat_Kind kind, /* Create new stats entry. */ dsa_pointer chunk; PgStatShared_Common *shheader; + PgStat_HashKey key = shhashent->key; /* * Initialize refcount to 1, marking it as valid / not dropped. The entry @@ -310,6 +311,8 @@ pgstat_init_entry(PgStat_Kind kind, */ pg_atomic_init_u32(&shhashent->generation, 0); shhashent->dropped = false; + elog(WARNING, "XXX key %u/%u/%llu pgstat_init_entry generation 0", + key.kind, key.dboid, (unsigned long long) key.objid); chunk = dsa_allocate0(pgStatLocal.dsa, pgstat_get_kind_info(kind)->shared_size); shheader = dsa_get_address(pgStatLocal.dsa, chunk); @@ -327,6 +330,7 @@ static PgStatShared_Common * pgstat_reinit_entry(PgStat_Kind kind, PgStatShared_HashEntry *shhashent) { PgStatShared_Common *shheader; + PgStat_HashKey key = shhashent->key; shheader = dsa_get_address(pgStatLocal.dsa, shhashent->body); @@ -339,6 +343,8 @@ pgstat_reinit_entry(PgStat_Kind kind, PgStatShared_HashEntry *shhashent) */ pg_atomic_fetch_add_u32(&shhashent->generation, 1); shhashent->dropped = false; + elog(WARNING, "XXX key %u/%u/%llu pgstat_reinit_entry generation++ refcount++", + key.kind, key.dboid, (unsigned long long) key.objid); /* reinitialize content */ Assert(shheader->magic == 0xdeadbeef); @@ -369,10 +375,13 @@ pgstat_acquire_entry_ref(PgStat_EntryRef *entry_ref, PgStatShared_HashEntry *shhashent, PgStatShared_Common *shheader) { + PgStat_HashKey key = shhashent->key; Assert(shheader->magic == 0xdeadbeef); Assert(pg_atomic_read_u32(&shhashent->refcount) > 0); pg_atomic_fetch_add_u32(&shhashent->refcount, 1); + elog(WARNING, "XXX key %u/%u/%llu pgstat_acquire_entry_ref refcount++", + key.kind, key.dboid, (unsigned long long) key.objid); dshash_release_lock(pgStatLocal.shared_hash, shhashent); @@ -594,6 +603,9 @@ pgstat_release_entry_ref(PgStat_HashKey key, PgStat_EntryRef *entry_ref, * increasing the refcount because it is not "legal" to create * additional references to dropped entries. */ + elog(WARNING, + "XXX: key %u/%u/%llu pgstat_release_entry_ref refcount--", + key.kind, key.dboid, (unsigned long long) key.objid); if (pg_atomic_fetch_sub_u32(&entry_ref->shared_entry->refcount, 1) == 1) { PgStatShared_HashEntry *shent; @@ -620,6 +632,9 @@ pgstat_release_entry_ref(PgStat_HashKey key, PgStat_EntryRef *entry_ref, if (pg_atomic_read_u32(&entry_ref->shared_entry->generation) == entry_ref->generation) { + elog(WARNING, + "XXX: key %u/%u/%llu pgstat_release_entry_ref same generation", + key.kind, key.dboid, (unsigned long long) key.objid); /* Same "generation", so we're OK with the removal */ Assert(pg_atomic_read_u32(&entry_ref->shared_entry->refcount) == 0); Assert(entry_ref->shared_entry == shent); @@ -627,6 +642,12 @@ pgstat_release_entry_ref(PgStat_HashKey key, PgStat_EntryRef *entry_ref, } else { + elog(WARNING, "XXX: key %u/%u/%llu pgstat_release_entry_ref different generation " + "shared_ref=%u entry_ref=%u", + key.kind, key.dboid, (unsigned long long) key.objid, + pg_atomic_read_u32(&entry_ref->shared_entry->generation), + entry_ref->generation); + /* * Shared stats entry has been reinitialized, so do not drop * its shared entry, only release its lock. @@ -753,6 +774,14 @@ pgstat_gc_entry_refs(void) if (entry_ref->pending != NULL) continue; + if (entry_ref->shared_entry->key.kind == PGSTAT_KIND_REPLSLOT) + { + PgStat_HashKey key = entry_ref->shared_entry->key; + elog(WARNING, "XXX key %u/%u/%llu pgstat_gc_entry_refs dropped generation=%d", + key.kind, key.dboid, (unsigned long long) key.objid, + entry_ref->generation); + } + pgstat_release_entry_ref(ent->key, entry_ref, false); } @@ -852,6 +881,7 @@ static bool pgstat_drop_entry_internal(PgStatShared_HashEntry *shent, dshash_seq_status *hstat) { + PgStat_HashKey key = shent->key; Assert(shent->body != InvalidDsaPointer); /* should already have released local reference */ @@ -874,11 +904,15 @@ pgstat_drop_entry_internal(PgStatShared_HashEntry *shent, /* release refcount marking entry as not dropped */ if (pg_atomic_sub_fetch_u32(&shent->refcount, 1) == 0) { + elog(WARNING, "XXX key %u/%u/%llu pgstat_drop_entry_internal refcount=0", + key.kind, key.dboid, (unsigned long long) key.objid); pgstat_free_entry(shent, hstat); return true; } else { + elog(WARNING, "XXX key %u/%u/%llu pgstat_drop_entry_internal refcount>0", + key.kind, key.dboid, (unsigned long long) key.objid); if (!hstat) dshash_release_lock(pgStatLocal.shared_hash, shent); return false; @@ -963,6 +997,9 @@ pgstat_drop_entry(PgStat_Kind kind, Oid dboid, uint64 objid) key.dboid = dboid; key.objid = objid; + elog(WARNING, "XXX key %u/%u/%llu pgstat_drop_entry", + key.kind, key.dboid, (unsigned long long) key.objid); + /* delete local reference */ if (pgStatEntryRefHash) { -- 2.45.2