Date: Mon, 27 Jan 2020 00:14:38 -0600
From: Justin Pryzby <pryzby@telsasoft.com>
To: Andres Freund <andres@anarazel.de>
Cc: 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: <20200127061438.GA877@telsasoft.com>
References: <20191216024956.GC2344@paquier.xyz>
 <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>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <20200127053813.GS13621@telsasoft.com>
User-Agent: Mutt/1.5.24 (2015-08-30)
Precedence: bulk

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

On Sun, Jan 26, 2020 at 11:38:13PM -0600, Justin Pryzby wrote:
> From 592a77554f99b5ff9035c55bf19a79a1443ae59e Mon Sep 17 00:00:00 2001
> From: Justin Pryzby <pryzbyj@telsasoft.com>
> Date: Thu, 12 Dec 2019 20:54:37 -0600
> Subject: [PATCH v14 2/3] 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 114428b..a62dc79 100644
> --- a/src/backend/access/heap/vacuumlazy.c
> +++ b/src/backend/access/heap/vacuumlazy.c
> @@ -290,8 +290,14 @@ typedef struct LVRelStats
>  	int			num_index_scans;
>  	TransactionId latestRemovedXid;
>  	bool		lock_waiter_detected;
> -} LVRelStats;
>  
> +	/* Used by the error callback */
> +	char		*relname;
> +	char 		*relnamespace;
> +	BlockNumber blkno;
> +	char 		*indname;
> +	int			stage;	/* 0: scan heap; 1: vacuum heap; 2: vacuum index */
> +} LVRelStats;
>  
>  /* A few variables that don't seem worth passing around as parameters */
>  static int	elevel = -1;
> @@ -360,6 +366,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);
>  
>  
>  /*
> @@ -721,6 +728,7 @@ lazy_scan_heap(Relation onerel, VacuumParams *params,
>  		PROGRESS_VACUUM_MAX_DEAD_TUPLES
>  	};
>  	int64		initprog_val[3];
> +	ErrorContextCallback errcallback;
>  
>  	pg_rusage_init(&ru0);
>  
> @@ -867,6 +875,17 @@ lazy_scan_heap(Relation onerel, VacuumParams *params,
>  	else
>  		skipping_blocks = false;
>  
> +	/* Setup error traceback support for ereport() */
> +	vacrelstats.relnamespace = get_namespace_name(RelationGetNamespace(onerel));
> +	vacrelstats.relname = relname;
> +	vacrelstats.blkno = InvalidBlockNumber; /* Not known yet */
> +	vacrelstats.stage = 0;
> +
> +	errcallback.callback = vacuum_error_callback;
> +	errcallback.arg = (void *) &vacrelstats;
> +	errcallback.previous = error_context_stack;
> +	error_context_stack = &errcallback;
> +
>  	for (blkno = 0; blkno < nblocks; blkno++)
>  	{
>  		Buffer		buf;
> @@ -888,6 +907,8 @@ lazy_scan_heap(Relation onerel, VacuumParams *params,
>  #define FORCE_CHECK_PAGE() \
>  		(blkno == nblocks - 1 && should_attempt_truncation(params))
>  
> +		vacrelstats.blkno = blkno;
> +
>  		pgstat_progress_update_param(PROGRESS_VACUUM_HEAP_BLKS_SCANNED, blkno);
>  
>  		if (blkno == next_unskippable_block)
> @@ -984,12 +1005,18 @@ lazy_scan_heap(Relation onerel, VacuumParams *params,
>  				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,
>  									lps, nindexes);
>  			/* Remove tuples from heap */
>  			lazy_vacuum_heap(onerel);
>  
> +			/* 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
> @@ -1593,6 +1620,9 @@ lazy_scan_heap(Relation onerel, VacuumParams *params,
>  			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);
>  
> @@ -1768,11 +1798,24 @@ lazy_vacuum_heap(Relation onerel)
>  	int			npages;
>  	PGRUsage	ru0;
>  	Buffer		vmbuffer = InvalidBuffer;
> +	ErrorContextCallback errcallback;
>  
>  	/* 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
> +	 */
> +	vacrelstats.blkno = InvalidBlockNumber; /* Not known yet */
> +	vacrelstats.stage = 1;
> +
> +	errcallback.callback = vacuum_error_callback;
> +	errcallback.arg = (void *) &vacrelstats;
> +	errcallback.previous = error_context_stack;
> +	error_context_stack = &errcallback;
> +
>  	pg_rusage_init(&ru0);
>  	npages = 0;
>  
> @@ -1787,6 +1830,7 @@ lazy_vacuum_heap(Relation onerel)
>  		vacuum_delay_point();
>  
>  		tblk = ItemPointerGetBlockNumber(&vacrelstats.dead_tuples->itemptrs[tupindex]);
> +		vacrelstats.blkno = tblk;
>  		buf = ReadBufferExtended(onerel, MAIN_FORKNUM, tblk, RBM_NORMAL,
>  								 vac_strategy);
>  		if (!ConditionalLockBufferForCleanup(buf))
> @@ -1807,6 +1851,9 @@ lazy_vacuum_heap(Relation onerel)
>  		npages++;
>  	}
>  
> +	/* Pop the error context stack */
> +	error_context_stack = errcallback.previous;
> +
>  	if (BufferIsValid(vmbuffer))
>  	{
>  		ReleaseBuffer(vmbuffer);
> @@ -2314,6 +2361,8 @@ lazy_vacuum_index(Relation indrel, IndexBulkDeleteResult **stats,
>  	IndexVacuumInfo ivinfo;
>  	const char *msg;
>  	PGRUsage	ru0;
> +	ErrorContextCallback errcallback;
> +	LVRelStats	errcbarg; /* Used for error callback, only */
>  
>  	pg_rusage_init(&ru0);
>  
> @@ -2325,10 +2374,24 @@ 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.indname = RelationGetRelationName(indrel);
> +	errcbarg.relname = vacrelstats.relname;
> +	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
> @@ -3371,3 +3434,23 @@ 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)
> +{
> +	LVRelStats *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\" on table \"%s.%s\""),
> +				cbarg->indname, cbarg->relnamespace, cbarg->relname);
> +
> +}
> -- 
> 2.7.4
>