Date: Wed, 11 Dec 2019 08:36:48 -0600
From: Justin Pryzby <pryzby@telsasoft.com>
To: Michael Paquier <michael@paquier.xyz>
Cc: pgsql-hackers@postgresql.org, Andres Freund <andres@anarazel.de>
Subject: Re: error context for vacuum to include block number
Message-ID: <20191211143648.GK2082@telsasoft.com>
References: <20191120210600.GC30362@telsasoft.com>
 <20191206162325.GQ2082@telsasoft.com>
 <20191211121507.GA398552@paquier.xyz>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="xaMk4Io5JJdpkLEb"
Content-Disposition: inline
In-Reply-To: <20191211121507.GA398552@paquier.xyz>
User-Agent: Mutt/1.5.24 (2015-08-30)
Precedence: bulk


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

On Wed, Dec 11, 2019 at 09:15:07PM +0900, Michael Paquier wrote:
> On Fri, Dec 06, 2019 at 10:23:25AM -0600, Justin Pryzby wrote:
> > Find attached updated patch:
> >  . Use structure to include relation name.
> >  . Split into a separate patch rename of "StringInfoData buf".
> > 
> > 2019-11-27 20:04:53.640 CST [14244] ERROR:  canceling statement due to statement timeout
> > 2019-11-27 20:04:53.640 CST [14244] CONTEXT:  block 2314 of relation t
> > 2019-11-27 20:04:53.640 CST [14244] STATEMENT:  vacuum t;
> > 
> > I tried to use BufferGetTag() to avoid using a 2ndary structure, but fails if
> > the buffer is not pinned.
> 
> No problem from me to add more context directly in lazy_scan_heap().

Do you mean without a callback ?  I think that's necessary, since the IO errors
would happen within ReadBufferExtended, but we don't want to polute that with
errcontext.  And cannot call errcontext on its own:
FATAL:  errstart was not called

> So I would suggest the following instead:
> "while scanning block %u of relation \"%s.%s\"" 

Done in the attached.

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

From b78505f3008b501b1d427c491bc0f8b796d68879 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryzbyj@telsasoft.com>
Date: Wed, 20 Nov 2019 14:53:20 -0600
Subject: [PATCH v3] 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 | 36 +++++++++++++++++++++++++++++++++++-
 1 file changed, 35 insertions(+), 1 deletion(-)

diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 043ebb4..9376989 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -138,6 +138,12 @@ typedef struct LVRelStats
 	bool		lock_waiter_detected;
 } LVRelStats;
 
+typedef struct
+{
+	char *relname;
+	char *relnamespace;
+	BlockNumber blkno;
+} vacuum_error_callback_arg;
 
 /* A few variables that don't seem worth passing around as parameters */
 static int	elevel = -1;
@@ -175,6 +181,7 @@ static bool lazy_tid_reaped(ItemPointer itemptr, void *state);
 static int	vac_cmp_itemptr(const void *left, const void *right);
 static bool heap_page_is_all_visible(Relation rel, Buffer buf,
 									 TransactionId *visibility_cutoff_xid, bool *all_frozen);
+static void vacuum_error_callback(void *arg);
 
 
 /*
@@ -524,6 +531,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 cbarg;
 
 	pg_rusage_init(&ru0);
 
@@ -635,6 +644,15 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
 	else
 		skipping_blocks = false;
 
+	/* Setup error traceback support for ereport() */
+	errcallback.callback = vacuum_error_callback;
+	cbarg.relname = relname;
+	cbarg.relnamespace = get_namespace_name(RelationGetNamespace(onerel));
+	cbarg.blkno = 0; /* Not known yet */
+	errcallback.arg = (void *) &cbarg;
+	errcallback.previous = error_context_stack;
+	error_context_stack = &errcallback;
+
 	for (blkno = 0; blkno < nblocks; blkno++)
 	{
 		Buffer		buf;
@@ -658,6 +676,8 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
 
 		pgstat_progress_update_param(PROGRESS_VACUUM_HEAP_BLKS_SCANNED, blkno);
 
+		cbarg.blkno = blkno;
+
 		if (blkno == next_unskippable_block)
 		{
 			/* Time to advance next_unskippable_block */
@@ -817,7 +837,6 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
 
 		buf = ReadBufferExtended(onerel, MAIN_FORKNUM, blkno,
 								 RBM_NORMAL, vac_strategy);
-
 		/* We need buffer cleanup lock so that we can prune HOT chains. */
 		if (!ConditionalLockBufferForCleanup(buf))
 		{
@@ -1388,6 +1407,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);
 
@@ -2354,3 +2376,15 @@ heap_page_is_all_visible(Relation rel, Buffer buf,
 
 	return all_visible;
 }
+
+/*
+ * Error context callback for errors occurring during vacuum.
+ */
+static void
+vacuum_error_callback(void *arg)
+{
+	vacuum_error_callback_arg *cbarg = arg;
+
+	errcontext("while scanning block %u of relation \"%s.%s\"",
+			cbarg->blkno, cbarg->relnamespace, cbarg->relname);
+}
-- 
2.7.4


--xaMk4Io5JJdpkLEb--