On 12/01/2014 08:55 PM, Jim Nasby wrote:
On 12/1/14, 11:57 AM, Andres Freund wrote:
On 2014-11-30 20:46:51 -0600, Jim Nasby wrote:
On 11/10/14, 7:52 PM, Tom Lane wrote:
On the whole, I'm +1 for just logging the events and seeing what we learn
that way. That seems like an appropriate amount of effort for finding out
whether there is really an issue.
Attached is a patch that does this.
Unless somebody protests I plan to push this soon. I'll change two
things:
* Always use the same message, independent of scan_all. For one Jim's
version would be untranslatable, for another it's not actually
correct. In most cases we'll *not* wait, even if scan_all is
true as we'll often just balk after !lazy_check_needs_freeze().
Good point.
* Change the new bit in the errdetail. "could not acquire cleanup lock"
sounds too much like an error to me. "skipped %u pinned pages" maybe?
Seems reasonable.
Well, that's not always true either; when freezing, it doesn't skip the
pinned pages, it waits for them.
How about the attached (I also edited the comments a bit)? It looks like
this:
postgres=# vacuum verbose foo;
INFO: vacuuming "public.foo"
INFO: "foo": found 0 removable, 0 nonremovable row versions in 0 out of
7256 pages
DETAIL: 0 dead row versions cannot be removed yet.
There were 0 unused item pointers.
1 pages were pinned.
0 pages are entirely empty.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO: "foo": stopping truncate due to conflicting lock request
INFO: vacuuming "pg_toast.pg_toast_16384"
INFO: index "pg_toast_16384_index" now contains 0 row versions in 1 pages
DETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
and for autovacuum log:
LOG: automatic vacuum of table "postgres.public.foo": index scans: 0
pages: 0 removed, 7256 remain, 0 pinned
tuples: 79415 removed, 513156 remain, 0 are dead but not yet removable
buffer usage: 14532 hits, 6 misses, 6241 dirtied
avg read rate: 0.003 MB/s, avg write rate: 3.413 MB/s
system usage: CPU 0.00s/0.30u sec elapsed 14.28 sec
I.e. this just says how many pages were pinned, without saying what was
done about them. That's not very meaningful to an average DBA, but
that's true for many of the numbers printed in vacuum verbose.
- Heikki
diff --git a/doc/src/sgml/ref/vacuum.sgml b/doc/src/sgml/ref/vacuum.sgml
index 450c94f..5755753 100644
--- a/doc/src/sgml/ref/vacuum.sgml
+++ b/doc/src/sgml/ref/vacuum.sgml
@@ -252,6 +252,7 @@ DETAIL: CPU 0.01s/0.06u sec elapsed 0.07 sec.
INFO: "onek": found 3000 removable, 1000 nonremovable tuples in 143 pages
DETAIL: 0 dead tuples cannot be removed yet.
There were 0 unused item pointers.
+0 pages were pinned.
0 pages are entirely empty.
CPU 0.07s/0.39u sec elapsed 1.56 sec.
INFO: analyzing "public.onek"
diff --git a/src/backend/commands/vacuumlazy.c b/src/backend/commands/vacuumlazy.c
index 6db6c5c..af36486 100644
--- a/src/backend/commands/vacuumlazy.c
+++ b/src/backend/commands/vacuumlazy.c
@@ -105,6 +105,7 @@ typedef struct LVRelStats
BlockNumber old_rel_pages; /* previous value of pg_class.relpages */
BlockNumber rel_pages; /* total number of pages */
BlockNumber scanned_pages; /* number of pages we examined */
+ BlockNumber pinned_pages; /* # of pages we could not initially lock */
double scanned_tuples; /* counts only tuples on scanned pages */
double old_rel_tuples; /* previous value of pg_class.reltuples */
double new_rel_tuples; /* new estimated total # of tuples */
@@ -345,7 +346,7 @@ lazy_vacuum_rel(Relation onerel, VacuumStmt *vacstmt,
}
ereport(LOG,
(errmsg("automatic vacuum of table \"%s.%s.%s\": index scans: %d\n"
- "pages: %d removed, %d remain\n"
+ "pages: %d removed, %d remain, %d pinned\n"
"tuples: %.0f removed, %.0f remain, %.0f are dead but not yet removable\n"
"buffer usage: %d hits, %d misses, %d dirtied\n"
"avg read rate: %.3f MB/s, avg write rate: %.3f MB/s\n"
@@ -356,6 +357,7 @@ lazy_vacuum_rel(Relation onerel, VacuumStmt *vacstmt,
vacrelstats->num_index_scans,
vacrelstats->pages_removed,
vacrelstats->rel_pages,
+ vacrelstats->pinned_pages,
vacrelstats->tuples_deleted,
vacrelstats->new_rel_tuples,
vacrelstats->new_dead_tuples,
@@ -611,6 +613,8 @@ lazy_scan_heap(Relation onerel, LVRelStats *vacrelstats,
/* We need buffer cleanup lock so that we can prune HOT chains. */
if (!ConditionalLockBufferForCleanup(buf))
{
+ vacrelstats->pinned_pages++;
+
/*
* If we're not scanning the whole relation to guard against XID
* wraparound, it's OK to skip vacuuming a page. The next vacuum
@@ -1101,10 +1105,12 @@ lazy_scan_heap(Relation onerel, LVRelStats *vacrelstats,
vacrelstats->scanned_pages, nblocks),
errdetail("%.0f dead row versions cannot be removed yet.\n"
"There were %.0f unused item pointers.\n"
+ "%u pages were pinned.\n"
"%u pages are entirely empty.\n"
"%s.",
nkeep,
nunused,
+ vacrelstats->pinned_pages,
empty_pages,
pg_rusage_show(&ru0))));
}
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
