What is VACUUM waiting for?

Dear list, this is postgres 8.1, and I run a dbmail mailserver where we deleted most e-mails.
I then did a VACUUM (see below), and just before the "dbmail_messages" truncated rows
there was a very long time where obviously nothing happened. No CPU usage (<8%) and
no disk I/O (usage <5%). You can see this from the details:
DETAIL: CPU 0.11s/0.23u sec elapsed 294.24 sec.
I would have expected I/Os at least. How does VACUUM work at all?

dbmail=> VACUUM FULL VERBOSE dbmail_messages;
INFO: vacuuming "public.dbmail_messages"
INFO: "dbmail_messages": found 537 removable, 29257 nonremovable row versions in 10406 pages
DETAIL: 0 dead row versions cannot be removed yet.
Nonremovable row versions range from 106 to 106 bytes long.
There were 698152 unused item pointers.
Total free space (including removable row versions) is 78849264 bytes.
7770 pages are or will become empty, including 0 at the end of the table.
10385 pages containing 78848172 free bytes are potential move destinations.
CPU 0.00s/0.02u sec elapsed 2.51 sec.
INFO: index "dbmail_messages_pkey" now contains 29257 row versions in 6842 pages
DETAIL: 537 index row versions were removed.
2801 index pages have been deleted, 2801 are currently reusable.
CPU 0.04s/0.04u sec elapsed 3.56 sec.
INFO: index "dbmail_messages_1" now contains 29257 row versions in 2870 pages
DETAIL: 537 index row versions were removed.
2504 index pages have been deleted, 2504 are currently reusable.
CPU 0.10s/0.02u sec elapsed 7.26 sec.
INFO: index "dbmail_messages_2" now contains 29257 row versions in 6896 pages
DETAIL: 537 index row versions were removed.
2409 index pages have been deleted, 2409 are currently reusable.
CPU 0.23s/0.00u sec elapsed 29.09 sec.
INFO: index "dbmail_messages_3" now contains 29257 row versions in 4270 pages
DETAIL: 537 index row versions were removed.
2695 index pages have been deleted, 2695 are currently reusable.
CPU 0.29s/0.02u sec elapsed 14.26 sec.
INFO: index "dbmail_messages_4" now contains 29257 row versions in 7345 pages
DETAIL: 537 index row versions were removed.
159 index pages have been deleted, 159 are currently reusable.
CPU 0.78s/0.02u sec elapsed 36.18 sec.
INFO: index "dbmail_messages_5" now contains 29257 row versions in 4026 pages
DETAIL: 537 index row versions were removed.
2804 index pages have been deleted, 2804 are currently reusable.
CPU 0.16s/0.01u sec elapsed 12.57 sec.
INFO: index "dbmail_messages_6" now contains 26863 row versions in 2413 pages
DETAIL: 328 index row versions were removed.
1208 index pages have been deleted, 1208 are currently reusable.
CPU 0.12s/0.00u sec elapsed 8.42 sec.
INFO: index "dbmail_messages_7" now contains 29257 row versions in 4856 pages
DETAIL: 537 index row versions were removed.
4422 index pages have been deleted, 4422 are currently reusable.
CPU 0.13s/0.01u sec elapsed 12.45 sec.
INFO: index "dbmail_messages_8" now contains 29257 row versions in 4900 pages
DETAIL: 537 index row versions were removed.
4468 index pages have been deleted, 4468 are currently reusable.
CPU 0.09s/0.01u sec elapsed 12.73 sec.

INFO: "dbmail_messages": moved 23366 row versions, truncated 10406 to 418 pages
DETAIL: CPU 0.11s/0.23u sec elapsed 294.24 sec.
INFO: index "dbmail_messages_pkey" now contains 29257 row versions in 6842 pages
DETAIL: 23366 index row versions were removed.
2804 index pages have been deleted, 2804 are currently reusable.
CPU 0.00s/0.00u sec elapsed 3.46 sec.
INFO: index "dbmail_messages_1" now contains 29257 row versions in 2869 pages
DETAIL: 23366 index row versions were removed.
2542 index pages have been deleted, 2542 are currently reusable.
CPU 0.05s/0.02u sec elapsed 7.36 sec.
INFO: index "dbmail_messages_2" now contains 29257 row versions in 6896 pages
DETAIL: 23366 index row versions were removed.
2410 index pages have been deleted, 2410 are currently reusable.
CPU 0.02s/0.02u sec elapsed 28.41 sec.
INFO: index "dbmail_messages_3" now contains 29257 row versions in 4270 pages
DETAIL: 23366 index row versions were removed.
3838 index pages have been deleted, 3838 are currently reusable.
CPU 0.01s/0.00u sec elapsed 17.15 sec.
INFO: index "dbmail_messages_4" now contains 29257 row versions in 7345 pages
DETAIL: 23366 index row versions were removed.
162 index pages have been deleted, 162 are currently reusable.
CPU 0.01s/0.01u sec elapsed 34.18 sec.
INFO: index "dbmail_messages_5" now contains 29257 row versions in 4025 pages
DETAIL: 23366 index row versions were removed.
3628 index pages have been deleted, 3628 are currently reusable.
CPU 0.00s/0.01u sec elapsed 14.64 sec.
INFO: index "dbmail_messages_6" now contains 26863 row versions in 2400 pages
DETAIL: 22303 index row versions were removed.
2022 index pages have been deleted, 2022 are currently reusable.
CPU 0.00s/0.01u sec elapsed 10.43 sec.
INFO: index "dbmail_messages_7" now contains 29257 row versions in 4856 pages
DETAIL: 23366 index row versions were removed.
4412 index pages have been deleted, 4412 are currently reusable.
CPU 0.00s/0.01u sec elapsed 12.14 sec.
INFO: index "dbmail_messages_8" now contains 29257 row versions in 4900 pages
DETAIL: 23366 index row versions were removed.
4465 index pages have been deleted, 4465 are currently reusable.
CPU 0.00s/0.00u sec elapsed 12.35 sec.

mfg zmi
--
// Michael Monnerie, Ing.BSc ----- http://it-management.at
// Tel: 0660 / 415 65 31 .network.your.ideas.
// PGP Key: "curl -s http://zmi.at/zmi.asc | gpg --import"
// Fingerprint: AC19 F9D5 36ED CD8A EF38 500E CE14 91F7 1C12 09B4
// Keyserver: www.keyserver.net Key-ID: 1C1209B4