Question on vacuuming

From: Chris Hoover <revoohc(at)gmail(dot)com>
To: pgsql-admin(at)postgresql(dot)org
Subject: Question on vacuuming
Date: 2005-09-13 15:49:02
Message-ID: 1d219a6f050913084934b5abf@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-admin

I have a vacuuming question.

What does a vacuum have to do when it runs?

The reason I'm asking this question is that we are running a 5 minute vacuum
analyze on a key table in one of our databases to try and resolve some
performance problems. Due to i/o issues, we have only been running a vacuum
at night. However, this database customer has complained of slowness. When
we vacuum analyze this one table, their entire application speeds up.
However, the reactive vacuum tends to be fairly i/o expensive and slows the
entire server down for several minutes. Plus, being reactive is upsetting
the customer (and rightly so).

To try and be proactive, we are trying a vacuum analyze every 5 minutes on
this table. The thought being that every 5 minutes, the vacuum should have
very little work to do, and hopefully not cause extra strain on the db
server/io system. This seems to be working fine for the most part. However,
there is 1 exception. Everytime there is work to do, it seems to spike our
load from < 1 to a load of 3+ for a short time. This tends to cause
significant slowdowns for our customer if they happen to do anything that is
causing the database to access the drives. It does not seem to matter how
much work there is to do. Cleaning up 1 page/tuple or 15000 page/tuples
tends to cause this spike.

So, what is a vacuum doing when there is work to do? Does it have the same
work to do dispite the amount of pages/tuples that need to be cleaned up?

We are running 7.3.4 on Dell 2650 connected to a Dell powervault running
raid5.

Thanks for any help,

Chris

P.S. Here are some output from the vacuum process showing the load spike.

Tue Sep 13 10:00:59 EDT 2005
10:00am up 75 days, 26 min, 1 user, load average: 0.10, 0.16, 0.10
INFO: --Relation public.clmhdr--
INFO: Pages 115285: Changed 2, Empty 0; Tup 1366272: Vac 0, Keep 17123,
UnUsed 32710.
Total CPU 2.42s/0.52u sec elapsed 2.97 sec.
INFO: Analyzing public.clmhdr
VACUUM
10:01am up 75 days, 26 min, 1 user, load average: 0.10, 0.16, 0.10
sleeping 5 minutes
Tue Sep 13 10:06:04 EDT 2005
10:06am up 75 days, 31 min, 1 user, load average: 0.14, 0.14, 0.09
INFO: --Relation public.clmhdr--
INFO: Index clmhdr_bill_type: Pages 3925; Tuples 1366360: Deleted 2.
CPU 0.09s/0.10u sec elapsed 0.96 sec.
INFO: Index clmhdr_f_name: Pages 4575; Tuples 1366360: Deleted 2.
CPU 0.11s/0.16u sec elapsed 1.17 sec.
INFO: Index clmhdr_hdr_clm_status_idx: Pages 3924; Tuples 1366363: Deleted
2.
CPU 0.09s/0.14u sec elapsed 1.29 sec.
INFO: Index clmhdr_hdr_create_dt_idx: Pages 4711; Tuples 1366363: Deleted 2.
CPU 0.16s/0.10u sec elapsed 0.82 sec.
INFO: Index clmhdr_hdr_inv_nbr_idx: Pages 3114; Tuples 1366363: Deleted 2.
CPU 0.10s/0.09u sec elapsed 0.49 sec.
INFO: Index clmhdr_hdr_submit_mode_idx: Pages 5553; Tuples 1366363: Deleted
2.
CPU 0.11s/0.11u sec elapsed 0.58 sec.
INFO: Index clmhdr_hdr_user_id_idx: Pages 5466; Tuples 1366363: Deleted 2.
CPU 0.08s/0.13u sec elapsed 0.73 sec.
INFO: Index clmhdr_l_name_idx: Pages 4620; Tuples 1366363: Deleted 2.
CPU 0.23s/0.14u sec elapsed 2.78 sec.
INFO: Index clmhdr_pat_cntl_nbr_idx: Pages 5453; Tuples 1366363: Deleted 2.
CPU 0.16s/0.17u sec elapsed 0.56 sec.
INFO: Index clmhdr_stmt_from_dt_idx: Pages 4657; Tuples 1366363: Deleted 2.
CPU 0.17s/0.14u sec elapsed 0.40 sec.
INFO: Index clmhdr_stmt_thru_dt_idx: Pages 4651; Tuples 1366363: Deleted 2.
CPU 0.23s/0.13u sec elapsed 0.50 sec.
INFO: Index clmhdr_userid_status_idx: Pages 7013; Tuples 1366367: Deleted 2.
CPU 0.28s/0.23u sec elapsed 76.19 sec.
INFO: Index clmhdr_hdr_clm_status_2: Pages 3924; Tuples 1366367: Deleted 2.
CPU 0.09s/0.06u sec elapsed 0.48 sec.
INFO: Index clmhdr_pkey: Pages 4691; Tuples 1366367: Deleted 2.
CPU 0.08s/0.12u sec elapsed 0.47 sec.
INFO: Index clmhdr_inv_idx: Pages 4691; Tuples 1366367: Deleted 2.
CPU 0.08s/0.11u sec elapsed 0.52 sec.
INFO: Index clmhdr_l_name: Pages 4631; Tuples 1366367: Deleted 2.
CPU 0.13s/0.08u sec elapsed 0.64 sec.
INFO: Index clmhdr_pat_cntl_nbr: Pages 5453; Tuples 1366367: Deleted 2.
CPU 0.13s/0.10u sec elapsed 0.69 sec.
INFO: Index clmhdr_stmt_from_dt: Pages 4651; Tuples 1366368: Deleted 2.
CPU 0.14s/0.18u sec elapsed 0.81 sec.
INFO: Index clmhdr_stmt_thru_dt: Pages 4656; Tuples 1366369: Deleted 2.
CPU 0.23s/0.16u sec elapsed 1.13 sec.
INFO: Index hdr_status_with_user_idx: Pages 7026; Tuples 1366372: Deleted 2.
CPU 0.51s/0.14u sec elapsed 4.80 sec.
INFO: Index clmhdr_hdr_submit_mode_hdr_clm_type_idx: Pages 7137; Tuples
1366372: Deleted 2.
CPU 0.60s/0.18u sec elapsed 7.04 sec.
INFO: Index clmhdr_hdr_clm_type_idx: Pages 3926; Tuples 1366373: Deleted 2.
CPU 0.18s/0.14u sec elapsed 1.15 sec.
INFO: Removed 2 tuples in 2 pages.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO: Pages 115285: Changed 7, Empty 0; Tup 1366360: Vac 2, Keep 17210,
UnUsed 32620.
Total CPU 6.41s/3.50u sec elapsed 107.45 sec.
INFO: Analyzing public.clmhdr
VACUUM
10:07am up 75 days, 33 min, 1 user, load average: 3.99, 1.53, 0.60
sleeping 5 minutes
Tue Sep 13 10:12:54 EDT 2005
10:12am up 75 days, 38 min, 1 user, load average: 0.18, 0.82, 0.56
INFO: --Relation public.clmhdr--
INFO: Pages 115285: Changed 3, Empty 0; Tup 1366490: Vac 0, Keep 17341,
UnUsed 32493.
Total CPU 2.48s/0.33u sec elapsed 2.84 sec.
INFO: Analyzing public.clmhdr
VACUUM
10:12am up 75 days, 38 min, 1 user, load average: 0.25, 0.83, 0.57
sleeping 5 minutes

Responses

Browse pgsql-admin by date

  From Date Subject
Next Message Tom Lane 2005-09-13 16:31:03 Re: ERROR: canceling query due to user request
Previous Message Tom Lane 2005-09-13 15:24:17 Re: plperl again but different problem