On Sun, Dec 29, 2019 at 01:15:24PM -0500, Jeff Janes wrote:
> On Fri, Dec 20, 2019 at 12:11 PM Justin Pryzby <pry...@telsasoft.com> wrote:
>
> > This is a usability complaint. If one knows enough about vacuum and/or
> > logging, I'm sure there's no issue.
>
> > | 11 DEBUG: "t": found 999 removable, 999 nonremovable row versions in 9
> > out of 9 pages
>
> I agree the mixture of pre-action and after-action reporting is rather
> confusing sometimes. I'm more concerned about what the user sees in their
> terminal, though, rather than the server's log file.
Sorry, I ran vacuum (not verbose) with client_min_messages=debug, which was
confusing.
> Also, the above quoted line is confusing. It makes it sound like it found
> removable items, but didn't actually remove them. I think that that is
> taking grammatical parallelism too far. How about something like:
>
> DEBUG: "t": removed 999 row versions, found 999 nonremovable row versions in
> 9 out of 9 pages
Since da4ed8bf, lazy_vacuum_heap() actually says: "removed %d [row versions] in
%d pages". Strangely, the "found .. removable, .. nonremovable" in
lazy_scan_heap() is also from da4ed8bf. Should we change them to match ?
> Also, I'd appreciate a report on how many hint-bits were set
> and how many pages were marked all-visible and/or frozen.
Possibly should fork this part to a different thread, but..
hint bits are being set by heap_prune_chain():
|#0 HeapTupleSatisfiesVacuum (htup=htup@entry=0x7fffabfcccc0,
OldestXmin=OldestXmin@entry=536, buffer=buffer@entry=167) at
heapam_visibility.c:1245
|#1 0x00007fb6eb3eb848 in heap_prune_chain (prstate=0x7fffabfccf30,
OldestXmin=536, rootoffnum=1, buffer=167, relation=0x7fb6eb1e6858) at
pruneheap.c:488
|#2 heap_page_prune (relation=relation@entry=0x7fb6eb1e6858,
buffer=buffer@entry=167, OldestXmin=536, report_stats=report_stats@entry=false,
latestRemovedXid=latestRemovedXid@entry=0x7fb6ed84a13c) at pruneheap.c:223
|#3 0x00007fb6eb3f02a2 in lazy_scan_heap (aggressive=false, nindexes=0,
Irel=0x0, vacrelstats=0x7fb6ed84a0c0, params=0x7fffabfcdfd0,
onerel=0x7fb6eb1e6858) at vacuumlazy.c:970
|#4 heap_vacuum_rel (onerel=0x7fb6eb1e6858, params=0x7fffabfcdfd0,
bstrategy=<optimized out>) at vacuumlazy.c:302
In the attached, I moved heap_page_prune to avoid a second loop over items.
Then, initdb crashed until I avoided calling heap_prepare_freeze_tuple() for
HEAPTUPLE_DEAD. I'm not sure that's ok or maybe if it's exposing an issue.
I'm also not sure if t_infomask!=oldt_infomask is the right test.
One of my usability complaints was that the DETAIL includes newlines, which
makes it not apparent that it's detail, or that it's associated with the
preceding INFO. Should those all be separate DETAIL messages (currently, only
the first errdetail is used, but maybe they should be catted together
usefully). Should errdetail do something with newlines, like change them to
\n\t for output to the client (but not logfile). Should vacuum itself do
something (but probably no change to logfiles).
I remembered that log_statement_stats looks like this:
2020-01-01 11:28:33.758 CST [3916] LOG: EXECUTOR STATISTICS
2020-01-01 11:28:33.758 CST [3916] DETAIL: ! system usage stats:
! 0.050185 s user, 0.000217 s system, 0.050555 s elapsed
! [2.292346 s user, 0.215656 s system total]
[...]
It calls errdetail_internal("%s", str.data), same as vaccum, but the multi-line
detail messages are written like this:
|appendStringInfo(&str, "!\t...")
|...
|ereport(LOG,
| (errmsg_internal("%s", title),
| errdetail_internal("%s", str.data)));
Since they can run multiple times, including rusage, and there's not currently
any message shown before their action, I propose that lazy_vacuum_index/heap
should write VACUUM VERBOSE logs at DEBUG level. Or otherwise show a log
before starting each action, at least those for which it logs completion.
I'm not sure why this one doesn't use get ngettext() ? Missed at a8d585c0 ?
|appendStringInfo(&buf, _("There were %.0f unused item identifiers.\n"),
Or why this one uses _/gettext() ? (580ddcec suggests that I'm missing
something?).
|appendStringInfo(&buf, _("%s."), pg_rusage_show(&ru0));
Anyway, now it looks like this:
postgres=# VACUUM VERBOSE t;
INFO: vacuuming "pg_temp_3.t"
INFO: "t": removed 1998 row versions in 5 pages
INFO: "t": removed 1998, found 999 nonremovable row versions in 9 out of 9
pages
DETAIL: ! 0 dead row versions cannot be removed yet, oldest xmin: 4505
! There were 0 unused item identifiers.
! Skipped 0 pages due to buffer pins, 0 frozen pages.
! 0 pages are entirely empty.
! Marked 9 pages all visible, 4 pages frozen.
! Wrote 1998 hint bits.
! CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.
VACUUM
Thanks for your input.
Justin
>From d27f2cb5262ec3d3511de44ec7c15d1b1235e5ee Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryz...@telsasoft.com>
Date: Wed, 27 Nov 2019 20:07:10 -0600
Subject: [PATCH v1 1/6] Rename buf to avoid shadowing buf of another type
---
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 5a48b66..1338963 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -609,7 +609,7 @@ 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,
@@ -1443,33 +1443,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);
}
/*
--
2.7.4
>From bb92c8a6220000789e2fc9c852172624d5f9f773 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryz...@telsasoft.com>
Date: Sun, 29 Dec 2019 13:38:49 -0600
Subject: [PATCH v1 2/6] vacuumlazy: typos in comments
---
src/backend/access/heap/vacuumlazy.c | 4 ++--
1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 1338963..532698d 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -1279,7 +1279,7 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
/*
* It should never be the case that the visibility map page is set
* while the page-level bit is clear, but the reverse is allowed
- * (if checksums are not enabled). Regardless, set the both bits
+ * (if checksums are not enabled). Regardless, set both bits
* so that we get back in sync.
*
* NB: If the heap page is all-visible but the VM bit is not set,
@@ -1335,7 +1335,7 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
}
/*
- * If the all-visible page is turned out to be all-frozen but not
+ * If the all-visible page turned out to be all-frozen but not
* marked, we should so mark it. Note that all_frozen is only valid
* if all_visible is true, so we must check both.
*/
--
2.7.4
>From 2e11bd7284727fd4ec05cc2a5c57c6b379752e15 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryz...@telsasoft.com>
Date: Wed, 1 Jan 2020 17:35:35 -0600
Subject: [PATCH v1 3/6] Indent VACUUM VERBOSE multi-line errdetail messages..
I borrowed the format from ShowUsage.
---
src/backend/access/heap/vacuumlazy.c | 38 +++++++++++++++++++++++-------------
1 file changed, 24 insertions(+), 14 deletions(-)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 532698d..c8d5538 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -591,7 +591,8 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
BlockNumber nblocks,
blkno;
HeapTupleData tuple;
- char *relname;
+ char *relname,
+ *msgprefix;
TransactionId relfrozenxid = onerel->rd_rel->relfrozenxid;
TransactionId relminmxid = onerel->rd_rel->relminmxid;
BlockNumber empty_pages,
@@ -1440,28 +1441,37 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
tups_vacuumed, vacuumed_pages)));
/*
+ * Indent multi-line DETAIL if being sent to client (verbose)
+ * We don't know if it's sent to the client (client_min_messages);
+ * Also, that affects output to the logfile, too; assume that it's more
+ * important to format messages requested by the client than to make
+ * verbose logs pretty when also sent to the logfile.
+ */
+ msgprefix = elevel==INFO ? "!\t" : "";
+
+ /*
* This is pretty messy, but we split it up so that we can skip emitting
* individual parts of the message when not applicable.
*/
initStringInfo(&sbuf);
appendStringInfo(&sbuf,
- _("%.0f dead row versions cannot be removed yet, oldest xmin: %u\n"),
+ _("! %.0f dead row versions cannot be removed yet, oldest xmin: %u\n"),
nkeep, OldestXmin);
- appendStringInfo(&sbuf, _("There were %.0f unused item identifiers.\n"),
- nunused);
- appendStringInfo(&sbuf, ngettext("Skipped %u page due to buffer pins, ",
- "Skipped %u pages due to buffer pins, ",
+ appendStringInfo(&sbuf, _("%sThere were %.0f unused item identifiers.\n"),
+ msgprefix, nunused);
+ appendStringInfo(&sbuf, ngettext("%sSkipped %u page due to buffer pins, ",
+ "%sSkipped %u pages due to buffer pins, ",
vacrelstats->pinskipped_pages),
- vacrelstats->pinskipped_pages);
+ msgprefix, vacrelstats->pinskipped_pages);
appendStringInfo(&sbuf, ngettext("%u frozen page.\n",
"%u frozen pages.\n",
vacrelstats->frozenskipped_pages),
vacrelstats->frozenskipped_pages);
- appendStringInfo(&sbuf, ngettext("%u page is entirely empty.\n",
- "%u pages are entirely empty.\n",
+ appendStringInfo(&sbuf, ngettext("%s%u page is entirely empty.\n",
+ "%s%u pages are entirely empty.\n",
empty_pages),
- empty_pages);
- appendStringInfo(&sbuf, _("%s."), pg_rusage_show(&ru0));
+ msgprefix, empty_pages);
+ appendStringInfo(&sbuf, _("%s%s."), msgprefix, pg_rusage_show(&ru0)); // why translate this ??
ereport(elevel,
(errmsg("\"%s\": found %.0f removable, %.0f nonremovable row versions in %u out of %u pages",
@@ -1828,9 +1838,9 @@ lazy_cleanup_index(Relation indrel,
RelationGetRelationName(indrel),
stats->num_index_tuples,
stats->num_pages),
- errdetail("%.0f index row versions were removed.\n"
- "%u index pages have been deleted, %u are currently reusable.\n"
- "%s.",
+ errdetail("! %.0f index row versions were removed.\n"
+ "!\t%u index pages have been deleted, %u are currently reusable.\n"
+ "!\t%s.",
stats->tuples_removed,
stats->pages_deleted, stats->pages_free,
pg_rusage_show(&ru0))));
--
2.7.4
>From 10d3c94e9e38c29086627631564c9e6d4d620ca2 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryz...@telsasoft.com>
Date: Sun, 15 Dec 2019 17:00:29 -0600
Subject: [PATCH v1 4/6] reduce to DEBUG status logged from vacuum_heap/index..
..since they can run multiple times, which is both excessively noisy, and
confusing, due to showing multiple, multi-line messages with rusage.
Also output (at DEBUG) a message indicating the action to be taken, before
starting it. To avoid outputting a message about completion of one step, and
taking a long time before outputting anything about the next/current step.
I'm taking as a guiding principle to elog whenever calling
pgstat_progress_update_param.
---
src/backend/access/heap/vacuumlazy.c | 20 +++++++++++++++-----
1 file changed, 15 insertions(+), 5 deletions(-)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index c8d5538..08ad6b5 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -326,6 +326,7 @@ heap_vacuum_rel(Relation onerel, VacuumParams *params,
/* Report that we are now doing final cleanup */
pgstat_progress_update_param(PROGRESS_VACUUM_PHASE,
PROGRESS_VACUUM_PHASE_FINAL_CLEANUP);
+ elog(DEBUG1, "cleaning up");
/*
* Update statistics in pg_class.
@@ -1429,8 +1430,11 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
/* Do post-vacuum cleanup and statistics update for each index */
if (vacrelstats->useindex)
{
- for (i = 0; i < nindexes; i++)
+ for (i = 0; i < nindexes; i++) {
+ ereport(DEBUG1, (errmsg("cleaning up index \"%s\"",
+ RelationGetRelationName(Irel[i]))));
lazy_cleanup_index(Irel[i], indstats[i], vacrelstats);
+ }
}
/* If no indexes, make log report that lazy_vacuum_heap would've made */
@@ -1503,8 +1507,11 @@ lazy_vacuum_all_indexes(Relation onerel, LVRelStats *vacrelstats,
PROGRESS_VACUUM_PHASE_VACUUM_INDEX);
/* Remove index entries */
- for (i = 0; i < nindexes; i++)
+ for (i = 0; i < nindexes; i++) {
+ ereport(DEBUG1, (errmsg("\"%s\": vacuuming index",
+ RelationGetRelationName(Irel[i]))));
lazy_vacuum_index(Irel[i], &indstats[i], vacrelstats);
+ }
/* Increase and report the number of index scans */
vacrelstats->num_index_scans++;
@@ -1538,6 +1545,8 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats)
/* Report that we are now vacuuming the heap */
pgstat_progress_update_param(PROGRESS_VACUUM_PHASE,
PROGRESS_VACUUM_PHASE_VACUUM_HEAP);
+ ereport(DEBUG1, (errmsg("\"%s\": vacuuming heap",
+ RelationGetRelationName(onerel))));
/* Setup error traceback support for ereport() */
errcbarg.relnamespace = get_namespace_name(RelationGetNamespace(onerel));
@@ -1589,7 +1598,7 @@ lazy_vacuum_heap(Relation onerel, LVRelStats *vacrelstats)
vmbuffer = InvalidBuffer;
}
- ereport(elevel,
+ ereport(DEBUG1,
(errmsg("\"%s\": removed %d row versions in %d pages",
RelationGetRelationName(onerel),
tupindex, npages),
@@ -1780,7 +1789,7 @@ lazy_vacuum_index(Relation indrel,
*stats = index_bulk_delete(&ivinfo, *stats,
lazy_tid_reaped, (void *) vacrelstats);
- ereport(elevel,
+ ereport(DEBUG1,
(errmsg("scanned index \"%s\" to remove %d row versions",
RelationGetRelationName(indrel),
vacrelstats->num_dead_tuples),
@@ -1833,7 +1842,7 @@ lazy_cleanup_index(Relation indrel,
InvalidMultiXactId,
false);
- ereport(elevel,
+ ereport(DEBUG1,
(errmsg("index \"%s\" now contains %.0f row versions in %u pages",
RelationGetRelationName(indrel),
stats->num_index_tuples,
@@ -1901,6 +1910,7 @@ lazy_truncate_heap(Relation onerel, LVRelStats *vacrelstats)
/* Report that we are now truncating */
pgstat_progress_update_param(PROGRESS_VACUUM_PHASE,
PROGRESS_VACUUM_PHASE_TRUNCATE);
+ elog(DEBUG1, "truncating heap");
/*
* Loop until no more truncating can be done.
--
2.7.4
>From aec813b2fe066093ce7355f22b7396dd13b8e11b Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryz...@telsasoft.com>
Date: Sun, 29 Dec 2019 14:56:02 -0600
Subject: [PATCH v1 5/6] Report number of pages_allvisible/frozen..
..as requested by Jeff Janes
---
src/backend/access/heap/vacuumlazy.c | 37 ++++++++++++++++++++++++++++++------
1 file changed, 31 insertions(+), 6 deletions(-)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 08ad6b5..b739d49 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -125,7 +125,9 @@ typedef struct LVRelStats
double new_rel_tuples; /* new estimated total # of tuples */
double new_live_tuples; /* new estimated total # of live tuples */
double new_dead_tuples; /* new estimated total # of dead tuples */
- BlockNumber pages_removed;
+ BlockNumber pages_removed; /* Due to truncation */
+ BlockNumber pages_frozen;
+ BlockNumber pages_allvisible;
double tuples_deleted;
BlockNumber nonempty_pages; /* actually, last nonempty page + 1 */
/* List of TIDs of tuples we intend to delete */
@@ -427,11 +429,13 @@ heap_vacuum_rel(Relation onerel, VacuumParams *params,
get_namespace_name(RelationGetNamespace(onerel)),
RelationGetRelationName(onerel),
vacrelstats->num_index_scans);
- appendStringInfo(&buf, _("pages: %u removed, %u remain, %u skipped due to pins, %u skipped frozen\n"),
+ appendStringInfo(&buf, _("pages: %u removed, %u remain, %u skipped due to pins, %u skipped frozen, %u marked all visible, %u marked frozen\n"),
vacrelstats->pages_removed,
vacrelstats->rel_pages,
vacrelstats->pinskipped_pages,
- vacrelstats->frozenskipped_pages);
+ vacrelstats->frozenskipped_pages,
+ vacrelstats->pages_allvisible,
+ vacrelstats->pages_frozen);
appendStringInfo(&buf,
_("tuples: %.0f removed, %.0f remain, %.0f are dead but not yet removable, oldest xmin: %u\n"),
vacrelstats->tuples_deleted,
@@ -647,6 +651,9 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
vacrelstats->scanned_pages = 0;
vacrelstats->tupcount_pages = 0;
vacrelstats->nonempty_pages = 0;
+ vacrelstats->pages_frozen = 0;
+ vacrelstats->pages_allvisible = 0;
+
vacrelstats->latestRemovedXid = InvalidTransactionId;
lazy_space_alloc(vacrelstats, nblocks);
@@ -944,6 +951,8 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
visibilitymap_set(onerel, blkno, buf, InvalidXLogRecPtr,
vmbuffer, InvalidTransactionId,
VISIBILITYMAP_ALL_VISIBLE | VISIBILITYMAP_ALL_FROZEN);
+ vacrelstats->pages_allvisible++;
+ vacrelstats->pages_frozen++;
END_CRIT_SECTION();
}
@@ -1275,8 +1284,12 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
{
uint8 flags = VISIBILITYMAP_ALL_VISIBLE;
- if (all_frozen)
+ if (all_frozen) {
flags |= VISIBILITYMAP_ALL_FROZEN;
+ vacrelstats->pages_frozen++;
+ }
+
+ vacrelstats->pages_allvisible++;
/*
* It should never be the case that the visibility map page is set
@@ -1475,6 +1488,14 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
"%s%u pages are entirely empty.\n",
empty_pages),
msgprefix, empty_pages);
+ appendStringInfo(&sbuf, ngettext("%sMarked %u page all visible, ",
+ "%sMarked %u pages all visible, ",
+ vacrelstats->pages_allvisible),
+ msgprefix, vacrelstats->pages_allvisible);
+ appendStringInfo(&sbuf, ngettext("%u page frozen.\n",
+ "%u pages frozen.\n",
+ vacrelstats->pages_frozen),
+ vacrelstats->pages_frozen);
appendStringInfo(&sbuf, _("%s%s."), msgprefix, pg_rusage_show(&ru0)); // why translate this ??
ereport(elevel,
@@ -1692,10 +1713,14 @@ lazy_vacuum_page(Relation onerel, BlockNumber blkno, Buffer buffer,
uint8 flags = 0;
/* Set the VM all-frozen bit to flag, if needed */
- if ((vm_status & VISIBILITYMAP_ALL_VISIBLE) == 0)
+ if ((vm_status & VISIBILITYMAP_ALL_VISIBLE) == 0) {
flags |= VISIBILITYMAP_ALL_VISIBLE;
- if ((vm_status & VISIBILITYMAP_ALL_FROZEN) == 0 && all_frozen)
+ vacrelstats->pages_allvisible++;
+ }
+ if ((vm_status & VISIBILITYMAP_ALL_FROZEN) == 0 && all_frozen) {
flags |= VISIBILITYMAP_ALL_FROZEN;
+ vacrelstats->pages_frozen++;
+ }
Assert(BufferIsValid(*vmbuffer));
if (flags != 0)
--
2.7.4
>From 9902620947ae0ce100f58329929518b7e9ec9143 Mon Sep 17 00:00:00 2001
From: Justin Pryzby <pryz...@telsasoft.com>
Date: Sun, 29 Dec 2019 16:02:50 -0600
Subject: [PATCH v1 6/6] Report number of hint bits written..
..as requested by Jeff Janes
---
src/backend/access/heap/vacuumlazy.c | 38 ++++++++++++++++++++++++------------
1 file changed, 26 insertions(+), 12 deletions(-)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index b739d49..d08cac3 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -128,6 +128,7 @@ typedef struct LVRelStats
BlockNumber pages_removed; /* Due to truncation */
BlockNumber pages_frozen;
BlockNumber pages_allvisible;
+ double hintbit_tuples;
double tuples_deleted;
BlockNumber nonempty_pages; /* actually, last nonempty page + 1 */
/* List of TIDs of tuples we intend to delete */
@@ -437,11 +438,12 @@ heap_vacuum_rel(Relation onerel, VacuumParams *params,
vacrelstats->pages_allvisible,
vacrelstats->pages_frozen);
appendStringInfo(&buf,
- _("tuples: %.0f removed, %.0f remain, %.0f are dead but not yet removable, oldest xmin: %u\n"),
+ _("tuples: %.0f removed, %.0f remain, %.0f are dead but not yet removable, oldest xmin: %u, wrote %.0f hint bits\n"),
vacrelstats->tuples_deleted,
vacrelstats->new_rel_tuples,
vacrelstats->new_dead_tuples,
- OldestXmin);
+ OldestXmin,
+ vacrelstats->hintbit_tuples);
appendStringInfo(&buf,
_("buffer usage: %d hits, %d misses, %d dirtied\n"),
VacuumPageHit,
@@ -962,14 +964,6 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
}
/*
- * Prune all HOT-update chains in this page.
- *
- * We count tuples removed by the pruning step as removed by VACUUM.
- */
- tups_vacuumed += heap_page_prune(onerel, buf, OldestXmin, false,
- &vacrelstats->latestRemovedXid);
-
- /*
* Now scan the page to collect vacuumable items and check for tuples
* requiring freezing.
*/
@@ -989,6 +983,8 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
offnum = OffsetNumberNext(offnum))
{
ItemId itemid;
+ HTSV_Result satisfies;
+ int oldmask;
itemid = PageGetItemId(page, offnum);
@@ -1040,7 +1036,11 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
* cases impossible (e.g. in-progress insert from the same
* transaction).
*/
- switch (HeapTupleSatisfiesVacuum(&tuple, OldestXmin, buf))
+ oldmask = tuple.t_data->t_infomask;
+ satisfies = HeapTupleSatisfiesVacuum(&tuple, OldestXmin, buf);
+ if (oldmask != tuple.t_data->t_infomask)
+ vacrelstats->hintbit_tuples++;
+ switch (satisfies)
{
case HEAPTUPLE_DEAD:
@@ -1179,7 +1179,9 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
* Each non-removable tuple must be checked to see if it needs
* freezing. Note we already have exclusive buffer lock.
*/
- if (heap_prepare_freeze_tuple(tuple.t_data,
+ // Avoid freezing HEAPTUPLE_DEAD, as required
+ if (satisfies!=HEAPTUPLE_DEAD &&
+ heap_prepare_freeze_tuple(tuple.t_data,
relfrozenxid, relminmxid,
FreezeLimit, MultiXactCutoff,
&frozen[nfrozen],
@@ -1192,6 +1194,14 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
} /* scan along page */
/*
+ * Prune all HOT-update chains in this page.
+ *
+ * We count tuples removed by the pruning step as removed by VACUUM.
+ */
+ tups_vacuumed += heap_page_prune(onerel, buf, OldestXmin, false,
+ &vacrelstats->latestRemovedXid);
+
+ /*
* If we froze any tuples, mark the buffer dirty, and write a WAL
* record recording the changes. We must log the changes to be
* crash-safe against future truncation of CLOG.
@@ -1496,6 +1506,10 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
"%u pages frozen.\n",
vacrelstats->pages_frozen),
vacrelstats->pages_frozen);
+ appendStringInfo(&sbuf, ngettext("%sWrote %.0f hint bit.\n",
+ "%sWrote %.0f hint bits.\n",
+ vacrelstats->hintbit_tuples),
+ msgprefix, vacrelstats->hintbit_tuples);
appendStringInfo(&sbuf, _("%s%s."), msgprefix, pg_rusage_show(&ru0)); // why translate this ??
ereport(elevel,
--
2.7.4
