Thanks for reviewing
On Wed, Jan 22, 2020 at 05:37:06PM +0900, Masahiko Sawada wrote:
> I'm not sure it's worth to have patches separately but I could apply
The later patches expanded on the initial scope, and to my understanding the
1st callback is desirable but the others are maybe still at question.
> 1. * The comment should be updated as we use both relname and
> relnamespace for ereporting.
>
> * We can leave both blkno and stage that are used only for error
> context reporting put both relname and relnamespace to top of
> LVRelStats.
Updated in the 0005 - still not sure if that patch will be desirable, though.
Also, I realized that it's we cannot use vacrelstats->blkno instead of local
blkno variable, since vacrelstats->blkno is used simultaneously by scan heap
and vacuum heap).
> * The 'stage' is missing to support index cleanup.
But the callback isn't used during index cleanup ?
> * It seems to me strange that only initialization of latestRemovedXid
> is done after error callback initialization.
Yes, that was silly - I thought it was just an artifact of diff's inability to
express rearranged code any better.
> * Maybe we can initialize relname and relnamespace in heap_vacuum_rel
> rather than in lazy_scan_heap. BTW variables of vacrelstats are
> initialized different places: some of them in heap_vacuum_rel and
> others in lazy_scan_heap. I think we can gather those that can be
> initialized at that time to heap_vacuum_rel.
I think that's already true ? But topic for a separate patch, if not.
> 3. Maybe we can do like:
done
> 4. These comments can be merged like:
done
> 5. Why do we need to initialize blkno in spite of not using?
removed
> 6.
> + cbarg->blkno, cbarg->relnamespace, cbarg->relname);
> * 'vacrelstats' would be a better name than 'cbarg'.
Really? I'd prefer to avoid repeating long variable three times:
vacrelstats->blkno, vacrelstats->relnamespace,
vacrelstats->relname);
> * In index vacuum, how about "while vacuuming index \"%s.%s\""?
Yes. I'm still unclear if this is useful without a block number, or why it
wouldn't be better to write DEBUG1 log with index name before vacuuming each.
Justin
>From 6332127178e29967dfeb12577eb9a61e813a33a8 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryz...@telsasoft.com>
Date: Thu, 12 Dec 2019 20:54:37 -0600
Subject: [PATCH v13 1/5] 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 | 41 ++++++++++++++++++++++++++++++++++--
1 file changed, 39 insertions(+), 2 deletions(-)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index b331f4c..822fa3d 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -287,8 +287,12 @@ 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;
+} LVRelStats;
/* A few variables that don't seem worth passing around as parameters */
static int elevel = -1;
@@ -358,6 +362,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 +726,7 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
PROGRESS_VACUUM_MAX_DEAD_TUPLES
};
int64 initprog_val[3];
+ ErrorContextCallback errcallback;
pg_rusage_init(&ru0);
@@ -867,6 +873,16 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
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 */
+
+ 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 +904,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)
@@ -984,13 +1002,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
@@ -1594,6 +1617,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);
@@ -3372,3 +3398,14 @@ 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;
+ errcontext("while scanning block %u of relation \"%s.%s\"",
+ cbarg->blkno, cbarg->relnamespace, cbarg->relname);
+}
--
2.7.4
>From 02f53c52a8e5e91f6048c77ceeb65ab12bc008c4 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryz...@telsasoft.com>
Date: Thu, 12 Dec 2019 20:34:03 -0600
Subject: [PATCH v13 2/5] add errcontext callback in lazy_vacuum_heap, too
---
src/backend/access/heap/vacuumlazy.c | 15 +++++++++++++++
1 file changed, 15 insertions(+)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 822fa3d..9d9d342 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -1795,11 +1795,22 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats)
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 */
+ errcallback.callback = vacuum_error_callback;
+ errcallback.arg = (void *) vacrelstats;
+ errcallback.previous = error_context_stack;
+ error_context_stack = &errcallback;
+
pg_rusage_init(&ru0);
npages = 0;
@@ -1814,6 +1825,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))
@@ -1834,6 +1846,9 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats)
npages++;
}
+ /* Pop the error context stack */
+ error_context_stack = errcallback.previous;
+
if (BufferIsValid(vmbuffer))
{
ReleaseBuffer(vmbuffer);
--
2.7.4
>From cf0b6922f510a454a8bbe48008582d26ef1946d9 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryz...@telsasoft.com>
Date: Mon, 20 Jan 2020 14:28:45 -0600
Subject: [PATCH v13 3/5] Add vacrelstats.stage and distinct context message
---
src/backend/access/heap/vacuumlazy.c | 14 +++++++++++---
1 file changed, 11 insertions(+), 3 deletions(-)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 9d9d342..8b053a7 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -292,6 +292,7 @@ typedef struct LVRelStats
char *relname;
char *relnamespace;
BlockNumber blkno;
+ int stage; /* 0: scan heap; 1: vacuum heap */
} LVRelStats;
/* A few variables that don't seem worth passing around as parameters */
@@ -877,6 +878,7 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
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;
@@ -1806,6 +1808,8 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats)
* ->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;
@@ -3421,6 +3425,10 @@ static void
vacuum_error_callback(void *arg)
{
LVRelStats *cbarg = arg;
- errcontext("while scanning block %u of relation \"%s.%s\"",
- cbarg->blkno, cbarg->relnamespace, cbarg->relname);
-}
+
+ 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);
--
2.7.4
>From ff053bf2b2b0525ef203e0d18fbb4c4ab586f110 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryz...@telsasoft.com>
Date: Mon, 20 Jan 2020 14:44:06 -0600
Subject: [PATCH v13 4/5] errcontext for lazy_vacuum_index
---
src/backend/access/heap/vacuumlazy.c | 21 ++++++++++++++++++++-
1 file changed, 20 insertions(+), 1 deletion(-)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 8b053a7..d2673c2 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -292,7 +292,7 @@ typedef struct LVRelStats
char *relname;
char *relnamespace;
BlockNumber blkno;
- int stage; /* 0: scan heap; 1: vacuum heap */
+ int stage; /* 0: scan heap; 1: vacuum heap; 2: vacuum index */
} LVRelStats;
/* A few variables that don't seem worth passing around as parameters */
@@ -2360,6 +2360,8 @@ lazy_vacuum_index(Relation indrel, IndexBulkDeleteResult **stats,
IndexVacuumInfo ivinfo;
const char *msg;
PGRUsage ru0;
+ ErrorContextCallback errcallback;
+ LVRelStats vacrelstats; /* Used for error callback, only */
pg_rusage_init(&ru0);
@@ -2371,10 +2373,23 @@ lazy_vacuum_index(Relation indrel, IndexBulkDeleteResult **stats,
ivinfo.num_heap_tuples = reltuples;
ivinfo.strategy = vac_strategy;
+ /* Setup error traceback support for ereport() */
+ vacrelstats.relnamespace = get_namespace_name(RelationGetNamespace(indrel));
+ vacrelstats.relname = RelationGetRelationName(indrel);
+ vacrelstats.stage = 2;
+
+ errcallback.callback = vacuum_error_callback;
+ errcallback.arg = (void *) &vacrelstats;
+ 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
@@ -3432,3 +3447,7 @@ vacuum_error_callback(void *arg)
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
>From fb36143e74b073a3b07e669cdab72dca2f937d3b Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryz...@telsasoft.com>
Date: Mon, 20 Jan 2020 15:26:39 -0600
Subject: [PATCH v13 5/5] Avoid extra calls like GetRelationName
---
src/backend/access/heap/vacuumlazy.c | 75 ++++++++++++++++++------------------
1 file changed, 37 insertions(+), 38 deletions(-)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index d2673c2..746c86b 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -267,6 +267,9 @@ typedef struct LVParallelState
typedef struct LVRelStats
{
+ char *relname;
+ char *relnamespace;
+
/* useindex = true means two-pass strategy; false means one-pass */
bool useindex;
/* Overall statistics about rel */
@@ -289,8 +292,6 @@ typedef struct LVRelStats
bool lock_waiter_detected;
/* Used by the error callback */
- char *relname;
- char *relnamespace;
BlockNumber blkno;
int stage; /* 0: scan heap; 1: vacuum heap; 2: vacuum index */
} LVRelStats;
@@ -602,8 +603,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,
@@ -702,7 +703,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,
@@ -731,18 +731,6 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
pg_rusage_init(&ru0);
- relname = RelationGetRelationName(onerel);
- if (aggressive)
- ereport(elevel,
- (errmsg("aggressively vacuuming \"%s.%s\"",
- get_namespace_name(RelationGetNamespace(onerel)),
- relname)));
- else
- ereport(elevel,
- (errmsg("vacuuming \"%s.%s\"",
- get_namespace_name(RelationGetNamespace(onerel)),
- relname)));
-
empty_pages = vacuumed_pages = 0;
next_fsm_block_to_vacuum = (BlockNumber) 0;
num_tuples = live_tuples = tups_vacuumed = nkeep = nunused = 0;
@@ -757,6 +745,28 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
vacrelstats->nonempty_pages = 0;
vacrelstats->latestRemovedXid = InvalidTransactionId;
+ /* Setup error traceback support for ereport() */
+ vacrelstats->relnamespace = get_namespace_name(RelationGetNamespace(onerel));
+ vacrelstats->relname = RelationGetRelationName(onerel);
+ 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;
+
+ if (aggressive)
+ ereport(elevel,
+ (errmsg("aggressively vacuuming \"%s.%s\"",
+ vacrelstats->relnamespace,
+ vacrelstats->relname)));
+ else
+ ereport(elevel,
+ (errmsg("vacuuming \"%s.%s\"",
+ vacrelstats->relnamespace,
+ vacrelstats->relname)));
+
/*
* Initialize the state for a parallel vacuum. As of now, only one worker
* can be used for an index, so we invoke parallelism only if there are at
@@ -777,7 +787,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,
@@ -874,17 +884,6 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
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;
@@ -1556,7 +1555,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);
}
@@ -1577,7 +1576,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,
@@ -1690,7 +1689,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)));
/*
@@ -1719,7 +1718,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)));
@@ -1861,7 +1860,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))));
}
@@ -2397,7 +2396,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))));
}
@@ -2540,7 +2539,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;
}
@@ -2605,7 +2604,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))));
@@ -2670,7 +2669,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
