Thread: Need help understanding vacuum verbose output

Need help understanding vacuum verbose output

From
Gordon Shannon
Date:
Hi,  Running 8.4.4 on Centos.  A couple of these numbers don't make sense to
me.
(I added line numbers for reference)

1  vacuum verbose authors_archive;
2  INFO:  vacuuming "public.authors_archive"
3  INFO:  scanned index "authors_archive_pkey" to remove 45878 row versions
4  DETAIL:  CPU 0.05s/0.34u sec elapsed 0.41 sec.
5  INFO:  "authors_archive": removed 45878 row versions in 396 pages
6  DETAIL:  CPU 0.00s/0.00u sec elapsed 0.00 sec.
7  INFO:  index "authors_archive_pkey" now contains 5012898 row versions in
13886 pages
8  DETAIL:  45878 index row versions were removed.
9  138 index pages have been deleted, 12 are currently reusable.
10 CPU 0.00s/0.00u sec elapsed 0.00 sec.
11 INFO:  "authors_archive": found 16558 removable, 7300 nonremovable row
versions in 492 out of 51958 pages
12 DETAIL:  0 dead row versions cannot be removed yet.
13 There were 4687 unused item pointers.
14 0 pages are entirely empty.

I was the only one touching this table. Since the previous vacuum, I deleted
45,878 rows.
Line 5 says it removed all 45,878 tuples, that's fine.
Line 11 now says it found only 16,558 removable tuples. What does this mean?
Line 11 also says there are 7,300 non-removable tuples.  I expected 0. What
does this mean?
Line 12 says that 0 dead tuples cannot be removed, which seems correct to
me, but seems to contradict Line 11.

Thanks.


--
View this message in context:
http://postgresql.1045698.n5.nabble.com/Need-help-understanding-vacuum-verbose-output-tp2265895p2265895.html
Sent from the PostgreSQL - general mailing list archive at Nabble.com.

Re: Need help understanding vacuum verbose output

From
Tom Lane
Date:
Gordon Shannon <gordo169@gmail.com> writes:
> Hi,  Running 8.4.4 on Centos.  A couple of these numbers don't make sense to
> me.
> (I added line numbers for reference)

> 11 INFO:  "authors_archive": found 16558 removable, 7300 nonremovable row
> versions in 492 out of 51958 pages

The key point here is that vacuum only looked at 492 out of the 51958
pages in the table; those rowcounts are relevant to just that subset of
the table.  This is a new thing in 8.4 --- before, vacuum always had to
scan the entire table.  There's now bookkeeping that lets it figure out
which pages might contain vacuumable tuples, so it doesn't have to visit
every one.  The only real downside is that this message doesn't tell the
whole truth :-(

(IIRC there isn't yet any comparable optimization on indexes, so the
reports about the indexes still reflect everything in the table.)

            regards, tom lane

Re: Need help understanding vacuum verbose output

From
Gordon Shannon
Date:
OK, so if it knew that all vacuumable tuples could be found in 492 pages, and
it scanned only those pages, then how could it be that it reports 16558
removable tuples from those 492 pages, when it has already reported earlier
that it removed 45878 tuples -- a number we know in fact to be correct?  How
could both statements be correct?
--
View this message in context:
http://postgresql.1045698.n5.nabble.com/Need-help-understanding-vacuum-verbose-output-tp2265895p2266792.html
Sent from the PostgreSQL - general mailing list archive at Nabble.com.

Re: Need help understanding vacuum verbose output

From
Brad Nicholson
Date:
  On 10-08-06 11:45 AM, Gordon Shannon wrote:
> OK, so if it knew that all vacuumable tuples could be found in 492 pages, and
> it scanned only those pages, then how could it be that it reports 16558
> removable tuples from those 492 pages, when it has already reported earlier
> that it removed 45878 tuples -- a number we know in fact to be correct?  How
> could both statements be correct?

It found 45878 dead tuples in 396 pages for the index authors_archive_pkey.

It found 16558 dead tuples in 492 pages for the table authors_archive.

--
Brad Nicholson  416-673-4106
Database Administrator, Afilias Canada Corp.



Re: Need help understanding vacuum verbose output

From
Alvaro Herrera
Date:
Excerpts from Brad Nicholson's message of vie ago 06 12:01:27 -0400 2010:
>   On 10-08-06 11:45 AM, Gordon Shannon wrote:
> > OK, so if it knew that all vacuumable tuples could be found in 492 pages, and
> > it scanned only those pages, then how could it be that it reports 16558
> > removable tuples from those 492 pages, when it has already reported earlier
> > that it removed 45878 tuples -- a number we know in fact to be correct?  How
> > could both statements be correct?
>
> It found 45878 dead tuples in 396 pages for the index authors_archive_pkey.
>
> It found 16558 dead tuples in 492 pages for the table authors_archive.

But why did it choose to skip the rest of the pages in authors_archive,
if there certainly are a lot of vacuumable tuples in (some of) them?

--
Álvaro Herrera <alvherre@commandprompt.com>
The PostgreSQL Company - Command Prompt, Inc.
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

Re: Need help understanding vacuum verbose output

From
Gordon Shannon
Date:
Yes, and also from the original post:

> 3  INFO:  scanned index "authors_archive_pkey" to remove 45878 row
> versions
> 4  DETAIL:  CPU 0.05s/0.34u sec elapsed 0.41 sec.
> 5  INFO:  "authors_archive": removed 45878 row versions in 396 pages
> 6  DETAIL:  CPU 0.00s/0.00u sec elapsed 0.00 sec.

Line 5 is talking about the relation, not the index, right?  Anyway, I know
it did remove 45878 row versions, cuz that's how many I deleted, and the
stats now say 0 dead tuples.
--
View this message in context:
http://postgresql.1045698.n5.nabble.com/Need-help-understanding-vacuum-verbose-output-tp2265895p2266825.html
Sent from the PostgreSQL - general mailing list archive at Nabble.com.

Re: Need help understanding vacuum verbose output

From
Tom Lane
Date:
Alvaro Herrera <alvherre@commandprompt.com> writes:
> Excerpts from Brad Nicholson's message of vie ago 06 12:01:27 -0400 2010:
>> It found 45878 dead tuples in 396 pages for the index authors_archive_pkey.
>> It found 16558 dead tuples in 492 pages for the table authors_archive.

> But why did it choose to skip the rest of the pages in authors_archive,
> if there certainly are a lot of vacuumable tuples in (some of) them?

I think the discrepancy is probably explained here:

            /*
             * DEAD item pointers are to be vacuumed normally; but we don't
             * count them in tups_vacuumed, else we'd be double-counting (at
             * least in the common case where heap_page_prune() just freed up
             * a non-HOT tuple).
             */

That last message prints tups_vacuumed, but those other ones are counting
all the removed item pointers.  So apparently Gordon had a whole lot of
pre-existing DEAD item pointers.  I wonder why ...

            regards, tom lane

Re: Need help understanding vacuum verbose output

From
Gordon Shannon
Date:
> That last message prints tups_vacuumed, but those other ones are counting
> all the removed item pointers.  So apparently Gordon had a whole lot of
> pre-existing DEAD item pointers.  I wonder why ...

Perhaps this will help.  Here's the entire test.

Start with a newly loaded table with 5,063,463 rows.
1. delete 467 rows
2. delete 4,220 rows
3. vacuum
4. delete 5,091 rows
5. delete 3,832 rows
6. delete 10,168 rows
7. delete 10,469 rows
8. delete 16,318 rows
9. vacuum (output shown in original post)

> 13 There were 4687 unused item pointers.

This corresponds to the 1st 2 steps, I presume, where the 4687 unused
pointer were created by the 1st vacuum.




--
View this message in context:
http://postgresql.1045698.n5.nabble.com/Need-help-understanding-vacuum-verbose-output-tp2265895p2266912.html
Sent from the PostgreSQL - general mailing list archive at Nabble.com.