Date: Tue, 14 May 2024 10:07:14 +0000
From: Bertrand Drouvot <bertranddrouvot.pg@gmail.com>
To: pgsql-hackers@lists.postgresql.org
Subject: Log details for stats dropped more than once
Message-ID: <ZkM30paAD8Cr/Bix@ip-10-97-1-34.eu-west-3.compute.internal>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="qS8sjQN0UyT4zcze"
Content-Disposition: inline
Archived-At: 
 <https://www.postgresql.org/message-id/ZkM30paAD8Cr/Bix%40ip-10-97-1-34.eu-west-3.compute.internal>
Precedence: bulk


--qS8sjQN0UyT4zcze
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline

Hi hackers,

While resuming the work on refilenode stats (mentioned in [1] but did not share
the patch yet), I realized that my current POC patch is buggy enough to produce
things like:

024-05-14 09:51:14.783 UTC [1788714] FATAL:  can only drop stats once

While the CONTEXT provides the list of dropped stats:

2024-05-14 09:51:14.783 UTC [1788714] CONTEXT:  WAL redo at 0/D75F478 for Transaction/ABORT: 2024-05-14 09:51:14.782223+00; dropped stats: 2/16384/27512/0 2/16384/27515/0 2/16384/27516/0

It's not clear which one generates the error (don't pay attention to the actual
values, the issue comes from the new refilenode stats that I removed from the
output).

Attached a tiny patch to report the stat that generates the error. The patch uses
errdetail_internal() as the extra details don't seem to be useful to average
users.

[1]: https://www.postgresql.org/message-id/ZbIdgTjR2QcFJ2mE%40ip-10-97-1-34.eu-west-3.compute.internal

Looking forward to your feedback,

Regards

-- 
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com

--qS8sjQN0UyT4zcze
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v1-0001-Log-details-for-stats-dropped-more-than-once.patch"

From f296d4092f5e87ed63a323db3f1bc9cfa807e2e8 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot.pg@gmail.com>
Date: Tue, 14 May 2024 09:10:50 +0000
Subject: [PATCH v1] Log details for stats dropped more than once

Adding errdetail_internal() in pgstat_drop_entry_internal() to display the
PgStat_HashKey when the "can only drop stats once" error is reported.
---
 src/backend/utils/activity/pgstat_shmem.c | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)
 100.0% src/backend/utils/activity/

diff --git a/src/backend/utils/activity/pgstat_shmem.c b/src/backend/utils/activity/pgstat_shmem.c
index 91591da395..1308c4439a 100644
--- a/src/backend/utils/activity/pgstat_shmem.c
+++ b/src/backend/utils/activity/pgstat_shmem.c
@@ -785,7 +785,11 @@ pgstat_drop_entry_internal(PgStatShared_HashEntry *shent,
 	 * backends to release their references.
 	 */
 	if (shent->dropped)
-		elog(ERROR, "can only drop stats once");
+		ereport(ERROR,
+				errmsg("can only drop stats once"),
+				errdetail_internal("Stats kind=%s dboid=%u objoid=%u.",
+								   pgstat_get_kind_info(shent->key.kind)->name,
+								   shent->key.dboid, shent->key.objoid));
 	shent->dropped = true;
 
 	/* release refcount marking entry as not dropped */
-- 
2.34.1


--qS8sjQN0UyT4zcze--