Date: Mon, 27 Jan 2020 16:50:18 -0600
From: Justin Pryzby <pryzby@telsasoft.com>
To: Masahiko Sawada <masahiko.sawada@2ndquadrant.com>
Cc: Andres Freund <andres@anarazel.de>,
	Michael Paquier <michael@paquier.xyz>,
	Alvaro Herrera <alvherre@2ndquadrant.com>,
	pgsql-hackers@postgresql.org
Subject: Re: error context for vacuum to include block number
Message-ID: <20200127225018.GY13621@telsasoft.com>
References: <20191224012428.GK30414@telsasoft.com>
 <20191224041909.GA323806@paquier.xyz>
 <20191226155704.GA12890@telsasoft.com>
 <20200102162701.GA2709@telsasoft.com>
 <20200120054159.GT26045@telsasoft.com>
 <20200120191120.s2pyx4ib4yubavxe@alap3.anarazel.de>
 <20200120214929.GV26045@telsasoft.com>
 <20200126202938.dqtavh6vr3vgpw53@alap3.anarazel.de>
 <20200127053813.GS13621@telsasoft.com>
 <CA+fd4k71fHRYJAeGxigGza5U+_HDJcBAbMniiMK2xz5GHhsMmQ@mail.gmail.com>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="OFtM20PmL5gDcvsL"
Content-Disposition: inline
In-Reply-To: 
 <CA+fd4k71fHRYJAeGxigGza5U+_HDJcBAbMniiMK2xz5GHhsMmQ@mail.gmail.com>
User-Agent: Mutt/1.5.24 (2015-08-30)
Precedence: bulk


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

On Mon, Jan 27, 2020 at 03:59:58PM +0900, Masahiko Sawada wrote:
> On Mon, 27 Jan 2020 at 14:38, Justin Pryzby <pryzby@telsasoft.com> wrote:
> > On Sun, Jan 26, 2020 at 12:29:38PM -0800, Andres Freund wrote:
> > > > CONTEXT:  while vacuuming relation "public.t_a_idx"
> > >
> > > It'd be a bit nicer if it said index "public.t_a_idx" for relation "public.t".
> >
> > I think that tips the scale in favour of making vacrelstats a global.
> > I added that as a 1st patch, and squished the callback patches into one.
> 
> Hmm I don't think it's a good idea to make vacrelstats global. If we
> want to display the relation name and its index name in error context
> we might want to define a new struct dedicated for error context
> reporting. That is it has blkno, stage and relation name and schema
> name for both table and index and then we set these variables of
> callback argument before performing a vacuum phase. We don't change
> LVRelStats at all.

On Mon, Jan 27, 2020 at 12:14:38AM -0600, Justin Pryzby wrote:
> It occured to me that there's an issue with sharing vacrelstats between
> scan/vacuum, since blkno and stage are set by the heap/index vacuum routines,
> but not reset on their return to heap scan.  Not sure if we should reset them,
> or go back to using a separate struct, like it was here:
> https://www.postgresql.org/message-id/20200120054159.GT26045%40telsasoft.com

I went back to this, original, way of doing it.
The parallel vacuum patch made it harder to pass the table around :(
And has to be separately tested:

| SET statement_timeout=0; DROP TABLE t; CREATE TABLE t AS SELECT generate_series(1,99999)a; CREATE INDEX ON t(a); CREATE INDEX ON t(a); UPDATE t SET a=1+a; SET statement_timeout=99;VACUUM(VERBOSE, PARALLEL 2) t;

I had to allocate space for the table name within the LVShared struct, not just
a pointer, otherwise it would variously crash or fail to output the index name.
I think pointers can't be passed to parallel process except using some
heavyweight thing like shm_toc_...

I guess the callback could also take the index relid instead of name, and use
something like IndexGetRelation().

> Although the patch replaces get_namespace_name and
> RelationGetRelationName but we use namespace name of relation at only
> two places and almost ereport/elog messages use only relation name
> gotten by RelationGetRelationName which is a macro to access the
> relation name in Relation struct. So I think adding relname to
> LVRelStats would not be a big benefit. Similarly, adding table
> namespace to LVRelStats would be good to avoid calling
> get_namespace_name whereas I'm not sure it's worth to have it because
> it's expected not to be really many times.

Right, I only tried that to save a few LOC and maybe make shorter lines.
It's not important so I'll drop that patch.

--OFtM20PmL5gDcvsL
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
 filename="v15-0001-vacuum-errcontext-to-show-block-being-processed.patch"

From fb53a62620aab180e8b250be50fefac1b40f50c2 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryzbyj@telsasoft.com>
Date: Thu, 12 Dec 2019 20:54:37 -0600
Subject: [PATCH v15 1/2] vacuum errcontext to show block being processed

As requested here.
https://www.postgresql.org/message-id/20190807235154.erbmr4o4bo6vgnjv%40alap3.anarazel.de
---
 src/backend/access/heap/vacuumlazy.c | 85 +++++++++++++++++++++++++++++++++++-
 1 file changed, 84 insertions(+), 1 deletion(-)

diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 8ce5011..d11c7af 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -292,6 +292,13 @@ typedef struct LVRelStats
 	bool		lock_waiter_detected;
 } LVRelStats;
 
+typedef struct
+{
+	char 		*relnamespace;
+	char		*relname;
+	BlockNumber blkno;
+	int			stage;	/* 0: scan heap; 1: vacuum heap; 2: vacuum index */
+} vacuum_error_callback_arg;
 
 /* A few variables that don't seem worth passing around as parameters */
 static int	elevel = -1;
@@ -361,6 +368,7 @@ static void end_parallel_vacuum(Relation *Irel, IndexBulkDeleteResult **stats,
 								LVParallelState *lps, int nindexes);
 static LVSharedIndStats *get_indstats(LVShared *lvshared, int n);
 static bool skip_parallel_vacuum_index(Relation indrel, LVShared *lvshared);
+static void vacuum_error_callback(void *arg);
 
 
 /*
@@ -724,6 +732,8 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
 		PROGRESS_VACUUM_MAX_DEAD_TUPLES
 	};
 	int64		initprog_val[3];
+	ErrorContextCallback errcallback;
+	vacuum_error_callback_arg errcbarg;
 
 	pg_rusage_init(&ru0);
 
@@ -870,6 +880,17 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
 	else
 		skipping_blocks = false;
 
+	/* Setup error traceback support for ereport() */
+	errcbarg.relnamespace = get_namespace_name(RelationGetNamespace(onerel));
+	errcbarg.relname = relname;
+	errcbarg.blkno = InvalidBlockNumber; /* Not known yet */
+	errcbarg.stage = 0;
+
+	errcallback.callback = vacuum_error_callback;
+	errcallback.arg = (void *) &errcbarg;
+	errcallback.previous = error_context_stack;
+	error_context_stack = &errcallback;
+
 	for (blkno = 0; blkno < nblocks; blkno++)
 	{
 		Buffer		buf;
@@ -891,6 +912,8 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
 #define FORCE_CHECK_PAGE() \
 		(blkno == nblocks - 1 && should_attempt_truncation(params, vacrelstats))
 
+		errcbarg.blkno = blkno;
+
 		pgstat_progress_update_param(PROGRESS_VACUUM_HEAP_BLKS_SCANNED, blkno);
 
 		if (blkno == next_unskippable_block)
@@ -987,13 +1010,18 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
 				vmbuffer = InvalidBuffer;
 			}
 
+			/* Pop the error context stack */
+			error_context_stack = errcallback.previous;
+
 			/* Work on all the indexes, then the heap */
 			lazy_vacuum_all_indexes(onerel, Irel, indstats,
 									vacrelstats, lps, nindexes);
-
 			/* Remove tuples from heap */
 			lazy_vacuum_heap(onerel, vacrelstats);
 
+			/* Replace error context while continuing heap scan */
+			error_context_stack = &errcallback;
+
 			/*
 			 * Forget the now-vacuumed tuples, and press on, but be careful
 			 * not to reset latestRemovedXid since we want that value to be
@@ -1597,6 +1625,9 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
 			RecordPageWithFreeSpace(onerel, blkno, freespace);
 	}
 
+	/* Pop the error context stack */
+	error_context_stack = errcallback.previous;
+
 	/* report that everything is scanned and vacuumed */
 	pgstat_progress_update_param(PROGRESS_VACUUM_HEAP_BLKS_SCANNED, blkno);
 
@@ -1772,11 +1803,25 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats)
 	int			npages;
 	PGRUsage	ru0;
 	Buffer		vmbuffer = InvalidBuffer;
+	ErrorContextCallback errcallback;
+	vacuum_error_callback_arg errcbarg;
 
 	/* Report that we are now vacuuming the heap */
 	pgstat_progress_update_param(PROGRESS_VACUUM_PHASE,
 								 PROGRESS_VACUUM_PHASE_VACUUM_HEAP);
 
+	/*
+	 * Setup error traceback support for ereport()
+	 * ->relnamespace and ->relname are already set
+	 */
+	errcbarg.blkno = InvalidBlockNumber; /* Not known yet */
+	errcbarg.stage = 1;
+
+	errcallback.callback = vacuum_error_callback;
+	errcallback.arg = (void *) &errcbarg;
+	errcallback.previous = error_context_stack;
+	error_context_stack = &errcallback;
+
 	pg_rusage_init(&ru0);
 	npages = 0;
 
@@ -1791,6 +1836,7 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats)
 		vacuum_delay_point();
 
 		tblk = ItemPointerGetBlockNumber(&vacrelstats->dead_tuples->itemptrs[tupindex]);
+		errcbarg.blkno = tblk;
 		buf = ReadBufferExtended(onerel, MAIN_FORKNUM, tblk, RBM_NORMAL,
 								 vac_strategy);
 		if (!ConditionalLockBufferForCleanup(buf))
@@ -1811,6 +1857,9 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats)
 		npages++;
 	}
 
+	/* Pop the error context stack */
+	error_context_stack = errcallback.previous;
+
 	if (BufferIsValid(vmbuffer))
 	{
 		ReleaseBuffer(vmbuffer);
@@ -2318,6 +2367,8 @@ lazy_vacuum_index(Relation indrel, IndexBulkDeleteResult **stats,
 	IndexVacuumInfo ivinfo;
 	const char *msg;
 	PGRUsage	ru0;
+	ErrorContextCallback errcallback;
+	vacuum_error_callback_arg errcbarg;
 
 	pg_rusage_init(&ru0);
 
@@ -2329,10 +2380,23 @@ lazy_vacuum_index(Relation indrel, IndexBulkDeleteResult **stats,
 	ivinfo.num_heap_tuples = reltuples;
 	ivinfo.strategy = vac_strategy;
 
+	/* Setup error traceback support for ereport() */
+	errcbarg.relnamespace = get_namespace_name(RelationGetNamespace(indrel));
+	errcbarg.relname = RelationGetRelationName(indrel);
+	errcbarg.stage = 2;
+
+	errcallback.callback = vacuum_error_callback;
+	errcallback.arg = (void *) &errcbarg;
+	errcallback.previous = error_context_stack;
+	error_context_stack = &errcallback;
+
 	/* Do bulk deletion */
 	*stats = index_bulk_delete(&ivinfo, *stats,
 							   lazy_tid_reaped, (void *) dead_tuples);
 
+	/* Pop the error context stack */
+	error_context_stack = errcallback.previous;
+
 	if (IsParallelWorker())
 		msg = gettext_noop("scanned index \"%s\" to remove %d row versions by parallel vacuum worker");
 	else
@@ -3375,3 +3439,22 @@ parallel_vacuum_main(dsm_segment *seg, shm_toc *toc)
 	table_close(onerel, ShareUpdateExclusiveLock);
 	pfree(stats);
 }
+
+/*
+ * Error context callback for errors occurring during vacuum.
+ */
+static void
+vacuum_error_callback(void *arg)
+{
+	vacuum_error_callback_arg *cbarg = arg;
+
+	if (cbarg->stage == 0)
+		errcontext(_("while scanning block %u of relation \"%s.%s\""),
+				cbarg->blkno, cbarg->relnamespace, cbarg->relname);
+	else if (cbarg->stage == 1)
+		errcontext(_("while vacuuming block %u of relation \"%s.%s\""),
+				cbarg->blkno, cbarg->relnamespace, cbarg->relname);
+	else if (cbarg->stage == 2)
+		errcontext(_("while vacuuming index \"%s.%s\""),
+				cbarg->relnamespace, cbarg->relname);
+}
-- 
2.7.4


--OFtM20PmL5gDcvsL
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
 filename="v15-0002-Include-name-of-table-in-callback-for-index-vacu.patch"

From f9ad1b8e857c088a3eab5aef88a9016e18fedc6c Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryzbyj@telsasoft.com>
Date: Mon, 27 Jan 2020 08:30:03 -0600
Subject: [PATCH v15 2/2] Include name of table in callback for index vacuum

---
 src/backend/access/heap/vacuumlazy.c | 21 ++++++++++++++-------
 1 file changed, 14 insertions(+), 7 deletions(-)

diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index d11c7af..a57190b 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -177,6 +177,7 @@ typedef struct LVShared
 	 * the lazy vacuum.
 	 */
 	Oid			relid;
+	char		relname[NAMEDATALEN];	/* tablename, used for error callback */
 	int			elevel;
 
 	/*
@@ -270,6 +271,7 @@ typedef struct LVParallelState
 
 typedef struct LVRelStats
 {
+	char		*relname;	/* tablename, used for error callback */
 	/* useindex = true means two-pass strategy; false means one-pass */
 	bool		useindex;
 	/* Overall statistics about rel */
@@ -296,6 +298,7 @@ typedef struct
 {
 	char 		*relnamespace;
 	char		*relname;
+	char 		*indname; /* If vacuuming index */
 	BlockNumber blkno;
 	int			stage;	/* 0: scan heap; 1: vacuum heap; 2: vacuum index */
 } vacuum_error_callback_arg;
@@ -321,7 +324,7 @@ static void lazy_vacuum_all_indexes(Relation onerel, Relation *Irel,
 									LVRelStats *vacrelstats, LVParallelState *lps,
 									int nindexes);
 static void lazy_vacuum_index(Relation indrel, IndexBulkDeleteResult **stats,
-							  LVDeadTuples *dead_tuples, double reltuples);
+							  LVDeadTuples *dead_tuples, double reltuples, char *relname);
 static void lazy_cleanup_index(Relation indrel,
 							   IndexBulkDeleteResult **stats,
 							   double reltuples, bool estimated_count);
@@ -757,6 +760,7 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
 		palloc0(nindexes * sizeof(IndexBulkDeleteResult *));
 
 	nblocks = RelationGetNumberOfBlocks(onerel);
+	vacrelstats->relname = relname;
 	vacrelstats->rel_pages = nblocks;
 	vacrelstats->scanned_pages = 0;
 	vacrelstats->tupcount_pages = 0;
@@ -1775,7 +1779,7 @@ lazy_vacuum_all_indexes(Relation onerel, Relation *Irel,
 
 		for (idx = 0; idx < nindexes; idx++)
 			lazy_vacuum_index(Irel[idx], &stats[idx], vacrelstats->dead_tuples,
-							  vacrelstats->old_live_tuples);
+							  vacrelstats->old_live_tuples, vacrelstats->relname);
 	}
 
 	/* Increase and report the number of index scans */
@@ -2272,7 +2276,7 @@ vacuum_one_index(Relation indrel, IndexBulkDeleteResult **stats,
 						   lvshared->estimated_count);
 	else
 		lazy_vacuum_index(indrel, stats, dead_tuples,
-						  lvshared->reltuples);
+						  lvshared->reltuples, lvshared->relname);
 
 	/*
 	 * Copy the index bulk-deletion result returned from ambulkdelete and
@@ -2359,10 +2363,11 @@ lazy_cleanup_all_indexes(Relation *Irel, IndexBulkDeleteResult **stats,
  *
  *		reltuples is the number of heap tuples to be passed to the
  *		bulkdelete callback.
+ *		relname is the name of the table to be passed to the error callback.
  */
 static void
 lazy_vacuum_index(Relation indrel, IndexBulkDeleteResult **stats,
-				  LVDeadTuples *dead_tuples, double reltuples)
+				  LVDeadTuples *dead_tuples, double reltuples, char *relname)
 {
 	IndexVacuumInfo ivinfo;
 	const char *msg;
@@ -2382,7 +2387,8 @@ lazy_vacuum_index(Relation indrel, IndexBulkDeleteResult **stats,
 
 	/* Setup error traceback support for ereport() */
 	errcbarg.relnamespace = get_namespace_name(RelationGetNamespace(indrel));
-	errcbarg.relname = RelationGetRelationName(indrel);
+	errcbarg.indname = RelationGetRelationName(indrel);
+	errcbarg.relname = relname;
 	errcbarg.stage = 2;
 
 	errcallback.callback = vacuum_error_callback;
@@ -3229,6 +3235,7 @@ begin_parallel_vacuum(Oid relid, Relation *Irel, LVRelStats *vacrelstats,
 	MemSet(shared, 0, est_shared);
 	shared->relid = relid;
 	shared->elevel = elevel;
+	strcpy(shared->relname, vacrelstats->relname);
 	shared->maintenance_work_mem_worker =
 		(nindexes_mwm > 0) ?
 		maintenance_work_mem / Min(parallel_workers, nindexes_mwm) :
@@ -3455,6 +3462,6 @@ vacuum_error_callback(void *arg)
 		errcontext(_("while vacuuming block %u of relation \"%s.%s\""),
 				cbarg->blkno, cbarg->relnamespace, cbarg->relname);
 	else if (cbarg->stage == 2)
-		errcontext(_("while vacuuming index \"%s.%s\""),
-				cbarg->relnamespace, cbarg->relname);
+		errcontext(_("while vacuuming index \"%s.%s\" of table \"%s\""),
+				cbarg->relnamespace, cbarg->indname, cbarg->relname);
 }
-- 
2.7.4


--OFtM20PmL5gDcvsL--