strange 'vacuum verbose analyze' behaviour

From: Oleg Bartunov <oleg(at)sai(dot)msu(dot)su>
To: Pgsql Hackers <pgsql-hackers(at)postgresql(dot)org>
Subject: strange 'vacuum verbose analyze' behaviour
Date: 2005-01-27 14:35:51
Message-ID: Pine.GSO.4.62.0501271724240.6701@ra.sai.msu.su
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

Hi there,

we have a table with 500mln rows:

wsdb=# \d usno
Table "public.usno"
Column | Type | Modifiers
--------+--------+-----------
ra | real |
dec | real |
bmag | real |
rmag | real |
ipix | bigint |
Indexes:
"ipix_ind" btree (ipix)
"radec_idx1" btree (ra, "dec")

postgresql is a v8.0 release running on Linux 2.6.7

Day ago we run 'vacuum verbose analyze;' and now we're observing
strange output (see below). We see many repeated passes through the
table 'usno' and all indices (2). The only change is a string like:
INFO: index "radec_idx1" now contains 1024770075 row versions in 2946824 pages
^^^^^^^^^^
The loop is:
usno table ~ 20sec
index "radec_idx1" ~ 5100sec
index "ipix_ind" ~ 1000sec

and it repeated about 13 times ( 26hours/2hours )

Is this an expected behaviour or I miss something ?

===============================================

CPU 120.71s/459.94u sec elapsed 5135.44 sec.
INFO: index "ipix_ind" now contains 526280881 row versions in 1443010 pages
DETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 66.65s/229.44u sec elapsed 1003.02 sec.
INFO: "usno": removed 2796013 row versions in 17809 pages
DETAIL: CPU 1.45s/1.79u sec elapsed 17.77 sec.
INFO: index "radec_idx1" now contains 1024770075 row versions in 2946824 pages
DETAIL: 2796013 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 147.80s/500.09u sec elapsed 5343.77 sec.
INFO: index "ipix_ind" now contains 526280881 row versions in 1443010 pages
DETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 66.99s/228.63u sec elapsed 1005.83 sec.
INFO: "usno": removed 2796013 row versions in 17809 pages
DETAIL: CPU 1.41s/1.89u sec elapsed 19.37 sec.
INFO: index "radec_idx1" now contains 1021974062 row versions in 2946824 pages
DETAIL: 2796013 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 152.17s/507.50u sec elapsed 5307.60 sec.
INFO: index "ipix_ind" now contains 526280881 row versions in 1443010 pages
DETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 67.38s/228.16u sec elapsed 1004.35 sec.
INFO: "usno": removed 2796013 row versions in 17809 pages
DETAIL: CPU 1.53s/1.75u sec elapsed 18.18 sec.
INFO: index "radec_idx1" now contains 1019178049 row versions in 2946824 pages
DETAIL: 2796013 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 131.59s/473.23u sec elapsed 5198.25 sec.
INFO: index "ipix_ind" now contains 526280881 row versions in 1443010 pages
DETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 69.60s/231.15u sec elapsed 1004.39 sec.
INFO: "usno": removed 2796013 row versions in 17809 pages
DETAIL: CPU 1.50s/1.83u sec elapsed 19.18 sec.
INFO: index "radec_idx1" now contains 1016382036 row versions in 2946824 pages
DETAIL: 2796013 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 120.82s/457.42u sec elapsed 5137.68 sec.
INFO: index "ipix_ind" now contains 526280881 row versions in 1443010 pages
DETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 67.00s/228.01u sec elapsed 1000.84 sec.
INFO: "usno": removed 2796013 row versions in 17809 pages
DETAIL: CPU 1.55s/1.73u sec elapsed 19.84 sec.
INFO: index "radec_idx1" now contains 1013586023 row versions in 2946824 pages
DETAIL: 2796013 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 114.79s/444.80u sec elapsed 5113.45 sec.
INFO: index "ipix_ind" now contains 526280881 row versions in 1443010 pages
DETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 66.73s/228.66u sec elapsed 1006.17 sec.
INFO: "usno": removed 2796013 row versions in 17809 pages
DETAIL: CPU 1.49s/1.69u sec elapsed 20.00 sec.
INFO: index "radec_idx1" now contains 1010790010 row versions in 2946824 pages
DETAIL: 2796013 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 114.04s/442.33u sec elapsed 5080.93 sec.
INFO: index "ipix_ind" now contains 526280881 row versions in 1443010 pages
DETAIL: 0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 67.12s/228.84u sec elapsed 1010.20 sec.
INFO: "usno": removed 2796013 row versions in 17809 pages
DETAIL: CPU 1.50s/1.82u sec elapsed 19.98 sec.

Regards,
Oleg
_____________________________________________________________
Oleg Bartunov, sci.researcher, hostmaster of AstroNet,
Sternberg Astronomical Institute, Moscow University (Russia)
Internet: oleg(at)sai(dot)msu(dot)su, http://www.sai.msu.su/~megera/
phone: +007(095)939-16-83, +007(095)939-23-83

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Tom Lane 2005-01-27 14:39:05 Re: Deferrable Unique Constraints
Previous Message Tom Lane 2005-01-27 14:24:11 Re: Deferrable Unique Constraints