vacuuming strangeness

Hello all,

I am currently experiencing some strange behaviour when vacuuming an active
table.

This table is constantly being updated by one process which gets a new
connection every time it updates the table.

There is a second process which is selecting from this table, also aquiring
a new connection prior to each operation.

While this is ongoing I manually issued "VACUUM VERBOSE test_table;" what
happened there after was unexpected and somewhat unnerving.

The VACUUM process does not seem to be able to exit, instead it seems to be
stuck in some strange loop for some time.

Is this something to be expected?

Also, should I expect a performance improvement in selects and update
statements after this type of operation?

My current measurements are that the only thing which is making a difference
for update/select statements is the use of a "VACUUM FULL", though given the
aggressive nature of the statement it is not something I want to do on a
high transaction db unless I absolutely must.

Thanks in advance,

--
Joe Maldonado

OUPUT:

db=# vacuum verbose test_table;
INFO: vacuuming "public.test_table"
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.92s/1.64u sec elapsed 9.38 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.95s/1.67u sec elapsed 40.74 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.84s/1.83u sec elapsed 11.86 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.90s/1.47u sec elapsed 9.54 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.79s/1.60u sec elapsed 10.06 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.82s/1.63u sec elapsed 9.29 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.84s/1.73u sec elapsed 10.46 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.63s/1.69u sec elapsed 18.69 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.42s/1.64u sec elapsed 10.60 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.61s/1.45u sec elapsed 9.51 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.51s/1.64u sec elapsed 10.96 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.58s/1.75u sec elapsed 9.67 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.76s/1.47u sec elapsed 23.65 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.49s/1.60u sec elapsed 10.59 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.58s/1.63u sec elapsed 9.17 sec.
INFO: "test_table": removed 1397848 row versions in 13064 pages
DETAIL: CPU 0.60s/1.55u sec elapsed 11.20 sec.
INFO: "test_table": removed 991515 row versions in 9267 pages
DETAIL: CPU 0.05s/1.45u sec elapsed 8.42 sec.
INFO: "test_table": found 23357083 removable, 200037 nonremovable row
versions in 442991 pages
DETAIL: 200000 dead row versions cannot be removed yet.
There were 23842917 unused item pointers.
0 pages are entirely empty.
CPU 21.21s/32.60u sec elapsed 475.26 sec.
INFO: vacuuming "pg_toast.pg_toast_2391937"
INFO: index "pg_toast_2391937_index" now contains 0 row versions in 1 pages
DETAIL: 0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.07 sec.
INFO: "pg_toast_2391937": found 0 removable, 0 nonremovable row versions in
0 pages
DETAIL: 0 dead row versions cannot be removed yet.
There were 0 unused item pointers.
0 pages are entirely empty.
CPU 0.00s/0.00u sec elapsed 0.15 sec.
VACUUM