Repeated VACUUM reports same number of deleted rows

[Russell Smith]

Postgresql 7.4.5

The following VACUUMs were run within a couple of minutes of each other completing.
This table concerned is a table that has not been changed in a long time. (a month)

There were open transactions at the time the vacuum was run. These were created by having PHP running with
postgresql. At least that is what I have managed to find so far. and disabling PHP in apache removes them.

postgres 7588 0.0 0.4 50324 3168 ? S Sep28 0:00 postgres: postgres sqlfilter 10.0.0.5 idle in transaction
postgres 7589 0.0 0.4 50324 3172 ? S Sep28 0:00 postgres: postgres sqlfilter 10.0.0.5 idle in transaction

Should VACUUM report the rows as deleted or say they could not be deleted?
Why does it report the same information for three runs in a row?

Or is something else going on that I don't understand.

Regards

Russell Smith
sqlfilter=# vacuum verbose filter.access_log_big
sqlfilter-# ;
INFO: vacuuming "filter.access_log_big"
INFO: index "access_log_url" now contains 5159204 row versions in 74984 pages
DETAIL: 21455 index pages have been deleted, 20000 are currently reusable.
CPU 5.16s/0.69u sec elapsed 650.85 sec.
INFO: index "access_log_whenwho" now contains 5159204 row versions in 58292 pages
DETAIL: 0 index pages have been deleted, 0 are currently reusable.
CPU 5.39s/0.68u sec elapsed 615.43 sec.
INFO: index "access_log_time" now contains 5159204 row versions in 38063 pages
DETAIL: 0 index pages have been deleted, 0 are currently reusable.
CPU 3.34s/0.46u sec elapsed 259.59 sec.
INFO: index "accesslogbig_domain" now contains 5159204 row versions in 25501 pages
DETAIL: 0 index pages have been deleted, 0 are currently reusable.
CPU 2.17s/0.24u sec elapsed 56.53 sec.
INFO: "access_log_big": found 0 removable, 5159204 nonremovable row versions in 175418 pages
DETAIL: 0 dead row versions cannot be removed yet.
There were 19262 unused item pointers.
0 pages are entirely empty.
CPU 21.06s/2.60u sec elapsed 1662.62 sec.
VACUUM
Time: 1662627.077 ms
sqlfilter=# vacuum verbose filter.access_log_big;
INFO: vacuuming "filter.access_log_big"
INFO: index "access_log_url" now contains 5159204 row versions in 74984 pages
DETAIL: 21455 index pages have been deleted, 20000 are currently reusable.
CPU 5.57s/0.64u sec elapsed 655.85 sec.
INFO: index "access_log_whenwho" now contains 5159204 row versions in 58292 pages
DETAIL: 0 index pages have been deleted, 0 are currently reusable.
CPU 5.54s/0.52u sec elapsed 589.95 sec.
INFO: index "access_log_time" now contains 5159204 row versions in 38063 pages
DETAIL: 0 index pages have been deleted, 0 are currently reusable.
CPU 3.30s/0.38u sec elapsed 262.43 sec.
INFO: index "accesslogbig_domain" now contains 5159204 row versions in 25501 pages
DETAIL: 0 index pages have been deleted, 0 are currently reusable.
CPU 2.37s/0.20u sec elapsed 54.98 sec.
INFO: "access_log_big": found 0 removable, 5159204 nonremovable row versions in 175418 pages
DETAIL: 0 dead row versions cannot be removed yet.
There were 19262 unused item pointers.
0 pages are entirely empty.
CPU 21.20s/2.36u sec elapsed 1647.25 sec.
VACUUM
Time: 1647292.681 ms
sqlfilter=# commit;
WARNING: there is no transaction in progress
COMMIT
Time: 47.537 ms
sqlfilter=# vacuum verbose filter.access_log_big;
INFO: vacuuming "filter.access_log_big"
INFO: index "access_log_url" now contains 5159204 row versions in 74984 pages
DETAIL: 21455 index pages have been deleted, 20000 are currently reusable.
CPU 4.95s/0.68u sec elapsed 648.90 sec.
INFO: index "access_log_whenwho" now contains 5159204 row versions in 58292 pages
DETAIL: 0 index pages have been deleted, 0 are currently reusable.
CPU 5.29s/0.68u sec elapsed 605.39 sec.
INFO: index "access_log_time" now contains 5159204 row versions in 38063 pages
DETAIL: 0 index pages have been deleted, 0 are currently reusable.
CPU 3.58s/0.42u sec elapsed 250.08 sec.
INFO: index "accesslogbig_domain" now contains 5159204 row versions in 25501 pages
DETAIL: 0 index pages have been deleted, 0 are currently reusable.
CPU 2.13s/0.29u sec elapsed 55.05 sec.
INFO: "access_log_big": found 0 removable, 5159204 nonremovable row versions in 175418 pages
DETAIL: 0 dead row versions cannot be removed yet.
There were 19262 unused item pointers.
0 pages are entirely empty.
CPU 20.89s/2.58u sec elapsed 1658.31 sec.
VACUUM
Time: 1658431.580 ms

---------------------------(end of broadcast)---------------------------
TIP 4: Don't 'kill -9' the postmaster

[Tom Lane]

Russell Smith <mr*****@pws.com.au> writes:

Should VACUUM report the rows as deleted or say they could not be deleted?
Why does it report the same information for three runs in a row?
I see no pending deletions in that vacuum output:
DETAIL: 0 dead row versions cannot be removed yet.

so I'm not sure why you would expect the output to change.

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 6: Have you searched our list archives?

http://archives.postgresql.org

[Russell Smith]

On Sat, 2 Oct 2004 12:42 am, Tom Lane wrote:

Russell Smith <mr*****@pws.com.au> writes:

Should VACUUM report the rows as deleted or say they could not be deleted?
Why does it report the same information for three runs in a row?
I see no pending deletions in that vacuum output:

DETAIL: 0 dead row versions cannot be removed yet.

INFO: *vacuuming "filter.access_log_big"
INFO: *index "access_log_url" now contains 5159204 row versions in 74984 pages
DETAIL: *21455 index pages have been deleted, 20000 are currently reusable.

I expect that index info not to be the same each vacuum run. Why are 21455index pages deleted
on runs 1, 2 and 3.
so I'm not sure why you would expect the output to change.

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 6: Have you searched our list archives?

http://archives.postgresql.org

---------------------------(end of broadcast)---------------------------
TIP 6: Have you searched our list archives?

http://archives.postgresql.org