On Thu, Feb 20, 2020 at 02:02:36PM -0300, Alvaro Herrera wrote: > On 2020-Feb-19, Justin Pryzby wrote: > > > Also, I was thinking that lazy_scan_heap doesn't needs to do this: > > > > + /* Pop the error context stack while calling vacuum */ > > + error_context_stack = errcallback.previous; > > ... > > + /* Set the error context while continuing heap scan */ > > + error_context_stack = &errcallback; > > > > It seems to me that's not actually necessary, since lazy_vacuum_heap will > > just > > *push* a context handler onto the stack, and then pop it back off. > > So if you don't pop before pushing, you'll end up with two context > lines, right?
Hm, looks like you're right, but that's not what I intended (and I didn't hit that in my test). > I think it would make sense to > initialize the context callback just *once* for a vacuum run, and from > that point onwards, just update the errcbarg struct to match what > you're currently doing -- not continually pop/push error callback stack > entries. See below ... Originally, the patch only supported "scanning heap", and set the callback strictly, to avoid having callback installed when calling other functions (like vacuuming heap/indexes). Then incrementally added callbacks in increasing number of places. We only need one errcontext. And possibly you're right that the callback could always be in place (?). But what about things like vacuuming FSM ? I think we'd need another "phase" for that (or else invent a PHASE_IGNORE to do nothing). Would VACUUM_FSM be added to progress reporting, too? We're also talking about new phase for TRUNCATE_PREFETCH and TRUNCATE_WAIT. Regarding the cbarg, at one point I took a suggestion from Andres to use the LVRelStats struct. I got rid of that since I didn't like sharing "blkno" between heap scanning and heap vacuuming, and needs to be reset when switching back to scanning heap. I experimented now going back to that now. The only utility is in having an single allocation of relname/space. -- Justin
>From cad1177c7b61f1543fca1ac2120a238fe6f9e555 Mon Sep 17 00:00:00 2001 From: Justin Pryzby <pryz...@telsasoft.com> Date: Thu, 12 Dec 2019 20:54:37 -0600 Subject: [PATCH v22 1/3] vacuum errcontext to show block being processed Discussion: https://www.postgresql.org/message-id/20191120210600.gc30...@telsasoft.com --- src/backend/access/heap/vacuumlazy.c | 162 +++++++++++++++++++++++++++++++---- 1 file changed, 144 insertions(+), 18 deletions(-) diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c index 03c43ef..d34d0c5 100644 --- a/src/backend/access/heap/vacuumlazy.c +++ b/src/backend/access/heap/vacuumlazy.c @@ -270,6 +270,8 @@ typedef struct LVParallelState typedef struct LVRelStats { + char *relnamespace; + char *relname; /* useindex = true means two-pass strategy; false means one-pass */ bool useindex; /* Overall statistics about rel */ @@ -290,8 +292,12 @@ typedef struct LVRelStats int num_index_scans; TransactionId latestRemovedXid; bool lock_waiter_detected; -} LVRelStats; + /* Used for error callback: */ + char *indname; + BlockNumber blkno; /* used only for heap operations */ + int phase; /* Reusing same constants as for progress reporting */ +} LVRelStats; /* A few variables that don't seem worth passing around as parameters */ static int elevel = -1; @@ -314,10 +320,10 @@ 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, LVRelStats *vacrelstats); static void lazy_cleanup_index(Relation indrel, IndexBulkDeleteResult **stats, - double reltuples, bool estimated_count); + double reltuples, bool estimated_count, LVRelStats *vacrelstats); static int lazy_vacuum_page(Relation onerel, BlockNumber blkno, Buffer buffer, int tupindex, LVRelStats *vacrelstats, Buffer *vmbuffer); static bool should_attempt_truncation(VacuumParams *params, @@ -361,6 +367,9 @@ 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); +static void update_vacuum_error_cbarg(LVRelStats *errcbarg, int phase, + BlockNumber blkno, Relation rel); /* @@ -460,6 +469,9 @@ heap_vacuum_rel(Relation onerel, VacuumParams *params, vacrelstats = (LVRelStats *) palloc0(sizeof(LVRelStats)); + vacrelstats->relnamespace = get_namespace_name(RelationGetNamespace(onerel)); + vacrelstats->relname = pstrdup(RelationGetRelationName(onerel)); + vacrelstats->indname = NULL; vacrelstats->old_rel_pages = onerel->rd_rel->relpages; vacrelstats->old_live_tuples = onerel->rd_rel->reltuples; vacrelstats->num_index_scans = 0; @@ -699,7 +711,6 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, BlockNumber nblocks, blkno; HeapTupleData tuple; - char *relname; TransactionId relfrozenxid = onerel->rd_rel->relfrozenxid; TransactionId relminmxid = onerel->rd_rel->relminmxid; BlockNumber empty_pages, @@ -724,20 +735,20 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, PROGRESS_VACUUM_MAX_DEAD_TUPLES }; int64 initprog_val[3]; + ErrorContextCallback errcallback; pg_rusage_init(&ru0); - relname = RelationGetRelationName(onerel); if (aggressive) ereport(elevel, (errmsg("aggressively vacuuming \"%s.%s\"", - get_namespace_name(RelationGetNamespace(onerel)), - relname))); + vacrelstats->relnamespace, + vacrelstats->relname))); else ereport(elevel, (errmsg("vacuuming \"%s.%s\"", - get_namespace_name(RelationGetNamespace(onerel)), - relname))); + vacrelstats->relnamespace, + vacrelstats->relname))); empty_pages = vacuumed_pages = 0; next_fsm_block_to_vacuum = (BlockNumber) 0; @@ -870,6 +881,14 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, else skipping_blocks = false; + /* Setup error traceback support for ereport() */ + update_vacuum_error_cbarg(vacrelstats, PROGRESS_VACUUM_PHASE_SCAN_HEAP, + InvalidBlockNumber, NULL); + errcallback.callback = vacuum_error_callback; + errcallback.arg = vacrelstats; + errcallback.previous = error_context_stack; + error_context_stack = &errcallback; + for (blkno = 0; blkno < nblocks; blkno++) { Buffer buf; @@ -891,6 +910,8 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, #define FORCE_CHECK_PAGE() \ (blkno == nblocks - 1 && should_attempt_truncation(params, vacrelstats)) + vacrelstats->blkno = blkno; + pgstat_progress_update_param(PROGRESS_VACUUM_HEAP_BLKS_SCANNED, blkno); if (blkno == next_unskippable_block) @@ -1011,6 +1032,10 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, /* Report that we are once again scanning the heap */ pgstat_progress_update_param(PROGRESS_VACUUM_PHASE, PROGRESS_VACUUM_PHASE_SCAN_HEAP); + + /* Set the error context while continuing heap scan */ + update_vacuum_error_cbarg(vacrelstats, + PROGRESS_VACUUM_PHASE_SCAN_HEAP, blkno, NULL); } /* @@ -1534,7 +1559,7 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, && VM_ALL_VISIBLE(onerel, blkno, &vmbuffer)) { elog(WARNING, "page is not marked all-visible but visibility map bit is set in relation \"%s\" page %u", - relname, blkno); + vacrelstats->relname, blkno); visibilitymap_clear(onerel, blkno, vmbuffer, VISIBILITYMAP_VALID_BITS); } @@ -1555,7 +1580,7 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, else if (PageIsAllVisible(page) && has_dead_tuples) { elog(WARNING, "page containing dead tuples is marked as all-visible in relation \"%s\" page %u", - relname, blkno); + vacrelstats->relname, blkno); PageClearAllVisible(page); MarkBufferDirty(buf); visibilitymap_clear(onerel, blkno, vmbuffer, @@ -1651,6 +1676,9 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, if (vacrelstats->useindex) lazy_cleanup_all_indexes(Irel, indstats, vacrelstats, lps, nindexes); + /* Pop the error context stack */ + error_context_stack = errcallback.previous; + /* * End parallel mode before updating index statistics as we cannot write * during parallel mode. @@ -1744,7 +1772,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); } /* Increase and report the number of index scans */ @@ -1778,8 +1806,13 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats) PROGRESS_VACUUM_PHASE_VACUUM_HEAP); pg_rusage_init(&ru0); - npages = 0; + /* Setup error traceback support for ereport() */ + update_vacuum_error_cbarg(vacrelstats, + PROGRESS_VACUUM_PHASE_VACUUM_HEAP, InvalidBlockNumber, + NULL); + + npages = 0; tupindex = 0; while (tupindex < vacrelstats->dead_tuples->num_tuples) { @@ -1791,6 +1824,7 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats) 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)) @@ -2203,6 +2237,26 @@ vacuum_one_index(Relation indrel, IndexBulkDeleteResult **stats, LVDeadTuples *dead_tuples) { IndexBulkDeleteResult *bulkdelete_res = NULL; + /* Init vacrelstats for error callback by parallel workers: */ + LVRelStats vacrelstats = + { + .relnamespace = get_namespace_name(RelationGetNamespace(indrel)), + .relname = pstrdup(get_rel_name(indrel->rd_index->indrelid)), + .indname = pstrdup(RelationGetRelationName(indrel)), + }; + + /* Setup error traceback support for ereport() */ + ErrorContextCallback errcallback; + update_vacuum_error_cbarg(&vacrelstats, + lvshared->for_cleanup ? + PROGRESS_VACUUM_PHASE_INDEX_CLEANUP : + PROGRESS_VACUUM_PHASE_VACUUM_INDEX, + InvalidBlockNumber, NULL); + + errcallback.callback = vacuum_error_callback; + errcallback.arg = &vacrelstats; + errcallback.previous = error_context_stack; + error_context_stack = &errcallback; if (shared_indstats) { @@ -2220,10 +2274,13 @@ vacuum_one_index(Relation indrel, IndexBulkDeleteResult **stats, /* Do vacuum or cleanup of the index */ if (lvshared->for_cleanup) lazy_cleanup_index(indrel, stats, lvshared->reltuples, - lvshared->estimated_count); + lvshared->estimated_count, &vacrelstats); else lazy_vacuum_index(indrel, stats, dead_tuples, - lvshared->reltuples); + lvshared->reltuples, &vacrelstats); + + /* Pop the error context stack */ + error_context_stack = errcallback.previous; /* * Copy the index bulk-deletion result returned from ambulkdelete and @@ -2298,7 +2355,8 @@ lazy_cleanup_all_indexes(Relation *Irel, IndexBulkDeleteResult **stats, for (idx = 0; idx < nindexes; idx++) lazy_cleanup_index(Irel[idx], &stats[idx], vacrelstats->new_rel_tuples, - vacrelstats->tupcount_pages < vacrelstats->rel_pages); + vacrelstats->tupcount_pages < vacrelstats->rel_pages, + vacrelstats); } } @@ -2313,7 +2371,7 @@ lazy_cleanup_all_indexes(Relation *Irel, IndexBulkDeleteResult **stats, */ static void lazy_vacuum_index(Relation indrel, IndexBulkDeleteResult **stats, - LVDeadTuples *dead_tuples, double reltuples) + LVDeadTuples *dead_tuples, double reltuples, LVRelStats *vacrelstats) { IndexVacuumInfo ivinfo; const char *msg; @@ -2329,6 +2387,11 @@ lazy_vacuum_index(Relation indrel, IndexBulkDeleteResult **stats, ivinfo.num_heap_tuples = reltuples; ivinfo.strategy = vac_strategy; + /* Setup error traceback support for ereport() */ + update_vacuum_error_cbarg(vacrelstats, + PROGRESS_VACUUM_PHASE_VACUUM_INDEX, InvalidBlockNumber, + indrel); + /* Do bulk deletion */ *stats = index_bulk_delete(&ivinfo, *stats, lazy_tid_reaped, (void *) dead_tuples); @@ -2354,7 +2417,7 @@ lazy_vacuum_index(Relation indrel, IndexBulkDeleteResult **stats, static void lazy_cleanup_index(Relation indrel, IndexBulkDeleteResult **stats, - double reltuples, bool estimated_count) + double reltuples, bool estimated_count, LVRelStats *vacrelstats) { IndexVacuumInfo ivinfo; const char *msg; @@ -2371,6 +2434,10 @@ lazy_cleanup_index(Relation indrel, ivinfo.num_heap_tuples = reltuples; ivinfo.strategy = vac_strategy; + /* Setup error traceback support for ereport() */ + update_vacuum_error_cbarg(vacrelstats, + PROGRESS_VACUUM_PHASE_INDEX_CLEANUP, InvalidBlockNumber, indrel); + *stats = index_vacuum_cleanup(&ivinfo, *stats); if (!(*stats)) @@ -3376,3 +3443,62 @@ 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; + + switch (cbarg->phase) { + case PROGRESS_VACUUM_PHASE_SCAN_HEAP: + if (BlockNumberIsValid(cbarg->blkno)) + errcontext("while scanning block %u of relation \"%s.%s\"", + cbarg->blkno, cbarg->relnamespace, cbarg->relname); + break; + + case PROGRESS_VACUUM_PHASE_VACUUM_HEAP: + if (BlockNumberIsValid(cbarg->blkno)) + errcontext("while vacuuming block %u of relation \"%s.%s\"", + cbarg->blkno, cbarg->relnamespace, cbarg->relname); + break; + + case PROGRESS_VACUUM_PHASE_VACUUM_INDEX: + errcontext("while vacuuming index \"%s\" of relation \"%s.%s\"", + cbarg->indname, cbarg->relnamespace, cbarg->relname); + break; + + case PROGRESS_VACUUM_PHASE_INDEX_CLEANUP: + errcontext("while cleaning up index \"%s\" of relation \"%s.%s\"", + cbarg->indname, cbarg->relnamespace, cbarg->relname); + break; + + case PROGRESS_VACUUM_PHASE_TRUNCATE: + case PROGRESS_VACUUM_PHASE_FINAL_CLEANUP: + default: + return; /* Shouldn't happen: do nothing */ + } +} + +/* Update vacuum error callback for current phase, block and index */ +static void +update_vacuum_error_cbarg(LVRelStats *errcbarg, int phase, BlockNumber blkno, + Relation indrel) +{ + errcbarg->blkno = blkno; + errcbarg->phase = phase; + + /* Free index name from any previous phase */ + if (errcbarg->indname) { + pfree(errcbarg->indname); + errcbarg->indname = NULL; + } + + /* For index phases, save the name of the current index for the callback */ + if (indrel) { + Assert(indrel->rd_rel->relkind == RELKIND_INDEX); + errcbarg->indname = pstrdup(RelationGetRelationName(indrel)); + } +} -- 2.7.4
>From 2d8d7dea956be57e39de3d00ff5cbe5caf29b3b4 Mon Sep 17 00:00:00 2001 From: Justin Pryzby <pryz...@telsasoft.com> Date: Sun, 16 Feb 2020 20:25:13 -0600 Subject: [PATCH v22 2/3] add callback for truncation --- src/backend/access/heap/vacuumlazy.c | 13 +++++++++++++ 1 file changed, 13 insertions(+) diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c index d34d0c5..75b86ee 100644 --- a/src/backend/access/heap/vacuumlazy.c +++ b/src/backend/access/heap/vacuumlazy.c @@ -2592,6 +2592,10 @@ lazy_truncate_heap(Relation onerel, LVRelStats *vacrelstats) return; } + /* Setup error traceback support for ereport() */ + update_vacuum_error_cbarg(vacrelstats, + PROGRESS_VACUUM_PHASE_TRUNCATE, new_rel_pages, NULL); + /* * Okay to truncate. */ @@ -2699,6 +2703,10 @@ count_nondeletable_pages(Relation onerel, LVRelStats *vacrelstats) blkno--; + /* Setup error traceback support for ereport() */ + update_vacuum_error_cbarg(vacrelstats, PROGRESS_VACUUM_PHASE_TRUNCATE, + blkno, NULL); + /* If we haven't prefetched this lot yet, do so now. */ if (prefetchedUntil > blkno) { @@ -3476,6 +3484,11 @@ vacuum_error_callback(void *arg) break; case PROGRESS_VACUUM_PHASE_TRUNCATE: + if (BlockNumberIsValid(cbarg->blkno)) + errcontext("while truncating relation \"%s.%s\" to %u blocks", + cbarg->relnamespace, cbarg->relname, cbarg->blkno); + break; + case PROGRESS_VACUUM_PHASE_FINAL_CLEANUP: default: return; /* Shouldn't happen: do nothing */ -- 2.7.4
>From 626c24d89690c9ea9572664fa7e0bb45751879cd Mon Sep 17 00:00:00 2001 From: Justin Pryzby <pryz...@telsasoft.com> Date: Wed, 26 Feb 2020 19:22:55 -0600 Subject: [PATCH v22 3/3] Avoid some calls to RelationGetRelationName --- src/backend/access/heap/vacuumlazy.c | 20 ++++++++++---------- 1 file changed, 10 insertions(+), 10 deletions(-) diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c index 75b86ee..a086ecf 100644 --- a/src/backend/access/heap/vacuumlazy.c +++ b/src/backend/access/heap/vacuumlazy.c @@ -611,8 +611,8 @@ heap_vacuum_rel(Relation onerel, VacuumParams *params, } appendStringInfo(&buf, msgfmt, get_database_name(MyDatabaseId), - get_namespace_name(RelationGetNamespace(onerel)), - RelationGetRelationName(onerel), + vacrelstats->relnamespace, + vacrelstats->relname, vacrelstats->num_index_scans); appendStringInfo(&buf, _("pages: %u removed, %u remain, %u skipped due to pins, %u skipped frozen\n"), vacrelstats->pages_removed, @@ -784,7 +784,7 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, if (params->nworkers > 0) ereport(WARNING, (errmsg("disabling parallel option of vacuum on \"%s\" --- cannot vacuum temporary tables in parallel", - RelationGetRelationName(onerel)))); + vacrelstats->relname))); } else lps = begin_parallel_vacuum(RelationGetRelid(onerel), Irel, @@ -1693,7 +1693,7 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, if (vacuumed_pages) ereport(elevel, (errmsg("\"%s\": removed %.0f row versions in %u pages", - RelationGetRelationName(onerel), + vacrelstats->relname, tups_vacuumed, vacuumed_pages))); /* @@ -1722,7 +1722,7 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats, ereport(elevel, (errmsg("\"%s\": found %.0f removable, %.0f nonremovable row versions in %u out of %u pages", - RelationGetRelationName(onerel), + vacrelstats->relname, tups_vacuumed, num_tuples, vacrelstats->scanned_pages, nblocks), errdetail_internal("%s", buf.data))); @@ -1853,7 +1853,7 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats) ereport(elevel, (errmsg("\"%s\": removed %d row versions in %d pages", - RelationGetRelationName(onerel), + vacrelstats->relname, tupindex, npages), errdetail_internal("%s", pg_rusage_show(&ru0)))); } @@ -2403,7 +2403,7 @@ lazy_vacuum_index(Relation indrel, IndexBulkDeleteResult **stats, ereport(elevel, (errmsg(msg, - RelationGetRelationName(indrel), + vacrelstats->relname, dead_tuples->num_tuples), errdetail_internal("%s", pg_rusage_show(&ru0)))); } @@ -2551,7 +2551,7 @@ lazy_truncate_heap(Relation onerel, LVRelStats *vacrelstats) vacrelstats->lock_waiter_detected = true; ereport(elevel, (errmsg("\"%s\": stopping truncate due to conflicting lock request", - RelationGetRelationName(onerel)))); + vacrelstats->relname))); return; } @@ -2620,7 +2620,7 @@ lazy_truncate_heap(Relation onerel, LVRelStats *vacrelstats) ereport(elevel, (errmsg("\"%s\": truncated %u to %u pages", - RelationGetRelationName(onerel), + vacrelstats->relname, old_rel_pages, new_rel_pages), errdetail_internal("%s", pg_rusage_show(&ru0)))); @@ -2685,7 +2685,7 @@ count_nondeletable_pages(Relation onerel, LVRelStats *vacrelstats) { ereport(elevel, (errmsg("\"%s\": suspending truncate due to conflicting lock request", - RelationGetRelationName(onerel)))); + vacrelstats->relname))); vacrelstats->lock_waiter_detected = true; return blkno; -- 2.7.4