On Wed, Aug 07, 2019 at 04:51:54PM -0700, Andres Freund wrote: https://www.postgresql.org/message-id/20190807235154.erbmr4o4bo6vgnjv%40alap3.anarazel.de | Ugh :( | | We really need to add a error context to vacuumlazy that shows which | block is being processed.
I eeked out a minimal patch. I renamed "StringInfoData buf", since it wasn't nice to mask it by "Buffer buf". postgres=# SET statement_timeout=99;vacuum t; SET 2019-11-20 14:52:49.521 CST [6319] ERROR: canceling statement due to statement timeout 2019-11-20 14:52:49.521 CST [6319] CONTEXT: block 596 2019-11-20 14:52:49.521 CST [6319] STATEMENT: vacuum t; Justin
>From 2aac5cdc16c222a053c02818ea2b3a6a5adfb89a Mon Sep 17 00:00:00 2001 From: Justin Pryzby <pryz...@telsasoft.com> Date: Wed, 20 Nov 2019 14:53:20 -0600 Subject: [PATCH v1] 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 | 43 +++++++++++++++++++++++++++--------- 1 file changed, 33 insertions(+), 10 deletions(-) diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c index a3c4a1d..6e0938b 100644 --- a/src/backend/access/heap/vacuumlazy.c +++ b/src/backend/access/heap/vacuumlazy.c @@ -175,6 +175,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); /* @@ -517,13 +518,14 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, BlockNumber next_unskippable_block; bool skipping_blocks; xl_heap_freeze_tuple *frozen; - StringInfoData buf; + StringInfoData sbuf; const int initprog_index[] = { PROGRESS_VACUUM_PHASE, PROGRESS_VACUUM_TOTAL_HEAP_BLKS, PROGRESS_VACUUM_MAX_DEAD_TUPLES }; int64 initprog_val[3]; + ErrorContextCallback errcallback; pg_rusage_init(&ru0); @@ -635,6 +637,12 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, else skipping_blocks = false; + /* Setup error traceback support for ereport() */ + errcallback.callback = vacuum_error_callback; + errcallback.arg = (void *) &blkno; + errcallback.previous = error_context_stack; + error_context_stack = &errcallback; + for (blkno = 0; blkno < nblocks; blkno++) { Buffer buf; @@ -1388,6 +1396,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); @@ -1481,33 +1492,33 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, * This is pretty messy, but we split it up so that we can skip emitting * individual parts of the message when not applicable. */ - initStringInfo(&buf); - appendStringInfo(&buf, + initStringInfo(&sbuf); + appendStringInfo(&sbuf, _("%.0f dead row versions cannot be removed yet, oldest xmin: %u\n"), nkeep, OldestXmin); - appendStringInfo(&buf, _("There were %.0f unused item identifiers.\n"), + appendStringInfo(&sbuf, _("There were %.0f unused item identifiers.\n"), nunused); - appendStringInfo(&buf, ngettext("Skipped %u page due to buffer pins, ", + appendStringInfo(&sbuf, ngettext("Skipped %u page due to buffer pins, ", "Skipped %u pages due to buffer pins, ", vacrelstats->pinskipped_pages), vacrelstats->pinskipped_pages); - appendStringInfo(&buf, ngettext("%u frozen page.\n", + appendStringInfo(&sbuf, ngettext("%u frozen page.\n", "%u frozen pages.\n", vacrelstats->frozenskipped_pages), vacrelstats->frozenskipped_pages); - appendStringInfo(&buf, ngettext("%u page is entirely empty.\n", + appendStringInfo(&sbuf, ngettext("%u page is entirely empty.\n", "%u pages are entirely empty.\n", empty_pages), empty_pages); - appendStringInfo(&buf, _("%s."), pg_rusage_show(&ru0)); + appendStringInfo(&sbuf, _("%s."), pg_rusage_show(&ru0)); ereport(elevel, (errmsg("\"%s\": found %.0f removable, %.0f nonremovable row versions in %u out of %u pages", RelationGetRelationName(onerel), tups_vacuumed, num_tuples, vacrelstats->scanned_pages, nblocks), - errdetail_internal("%s", buf.data))); - pfree(buf.data); + errdetail_internal("%s", sbuf.data))); + pfree(sbuf.data); } @@ -2354,3 +2365,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) +{ + // BufferDesc *bufHdr = (BufferDesc *) arg; + Buffer *buf = (int *) arg; + + errcontext("block %u", *buf); +} -- 2.7.4
