Re: DB is slow until DB is reloaded

On 04/01/2010 7:10 PM, Madison Kelly wrote:
> Hi all,
>
>   I've got a fairly small DB (~850MB when pg_dump'ed) running on PgSQL
> v8.1.11 a CentOS 5.3 x86_64 Xen-based virtual machine. The filesystem is
> ext3 on LVM with 32MB extents. It's about the only real resource-hungry
> VM on the server.
>
>   It slows down over time and I can't seem to find a way to get the
> performance to return without doing a dump and reload of the database.
> I've tried manually running 'VACUUM FULL' and restarting the postgresql
> daemon without success.
>
> For example, here is an actual query before the dump and again after the
> dump (sorry for the large query):
>
> -=] Before the dump/reload [=-
> server@iwt=> EXPLAIN ANALYZE SELECT lor_order_type, lor_order_date,
> lor_order_time, lor_isp_agent_id, lor_last_modified_date,
> lor_isp_order_number, lor_instr_for_bell_rep, lor_type_of_service,
> lor_local_voice_provider, lor_dry_loop_instr, lor_termination_location,
> lor_req_line_speed, lor_server_from, lor_rate_band,
> lor_related_order_nums, lor_related_order_types, lor_activation_date,
> lor_cust_first_name, lor_cust_last_name, lor_req_activation_date,
> lor_street_number, lor_street_number_suffix, lor_street_name,
> lor_street_type, lor_street_direction, lor_location_type_1,
> lor_location_number_1, lor_location_type_2, lor_location_number_2,
> lor_postal_code, lor_municipality, lor_province, lor_customer_group,
> lor_daytime_phone, lor_daytime_phone_ext, lod_value AS circuit_number
> FROM line_owner_report LEFT JOIN line_owner_data ON (lor_id=lod_lo_id
> AND lod_variable='ISPCircuitNumber1') WHERE lor_lo_id=514;
>                                                                 QUERY
> PLAN
>
------------------------------------------------------------------------------------------------------------------------------------------

>
>  Hash Left Join  (cost=2115.43..112756.81 rows=8198 width=1152) (actual
> time=1463.311..1463.380 rows=1 loops=1)
>    Hash Cond: ("outer".lor_id = "inner".lod_lo_id)
>    ->  Seq Scan on line_owner_report  (cost=0.00..108509.85 rows=8198
> width=1124) (actual time=1462.810..1462.872 rows=1 loops=1)
>          Filter: (lor_lo_id = 514)
>    ->  Hash  (cost=2112.85..2112.85 rows=1033 width=36) (actual
> time=0.421..0.421 rows=5 loops=1)
>          ->  Bitmap Heap Scan on line_owner_data  (cost=9.61..2112.85
> rows=1033 width=36) (actual time=0.274..0.378 rows=5 loops=1)
>                Recheck Cond: (lod_variable = 'ISPCircuitNumber1'::text)
>                ->  Bitmap Index Scan on lod_variable_index
> (cost=0.00..9.61 rows=1033 width=0) (actual time=0.218..0.218 rows=5
> loops=1)
>                      Index Cond: (lod_variable =
> 'ISPCircuitNumber1'::text)
>  Total runtime: 1463.679 ms
> (10 rows)
>
> -=] After the dump/reload [=-
> server@iwt=> EXPLAIN ANALYZE SELECT lor_order_type, lor_order_date,
> lor_order_time, lor_isp_agent_id, lor_last_modified_date,
> lor_isp_order_number, lor_instr_for_bell_rep, lor_type_of_service,
> lor_local_voice_provider, lor_dry_loop_instr, lor_termination_location,
> lor_req_line_speed, lor_server_from, lor_rate_band,
> lor_related_order_nums, lor_related_order_types, lor_activation_date,
> lor_cust_first_name, lor_cust_last_name, lor_req_activation_date,
> lor_street_number, lor_street_number_suffix, lor_street_name,
> lor_street_type, lor_street_direction, lor_location_type_1,
> lor_location_number_1, lor_location_type_2, lor_location_number_2,
> lor_postal_code, lor_municipality, lor_province, lor_customer_group,
> lor_daytime_phone, lor_daytime_phone_ext, lod_value AS circuit_number
> FROM line_owner_report LEFT JOIN line_owner_data ON (lor_id=lod_lo_id
> AND lod_variable='ISPCircuitNumber1') WHERE lor_lo_id=514;
>                                                                QUERY
> PLAN
>
-----------------------------------------------------------------------------------------------------------------------------------------

>
>  Nested Loop Left Join  (cost=10.84..182.57 rows=5 width=1152) (actual
> time=1.980..2.083 rows=1 loops=1)
>    ->  Seq Scan on line_owner_report  (cost=0.00..70.05 rows=5
> width=1124) (actual time=1.388..1.485 rows=1 loops=1)
>          Filter: (lor_lo_id = 514)
>    ->  Bitmap Heap Scan on line_owner_data  (cost=10.84..22.47 rows=3
> width=36) (actual time=0.562..0.562 rows=0 loops=1)
>          Recheck Cond: (("outer".lor_id = line_owner_data.lod_lo_id)
> AND (line_owner_data.lod_variable = 'ISPCircuitNumber1'::text))
>          ->  BitmapAnd  (cost=10.84..10.84 rows=3 width=0) (actual
> time=0.552..0.552 rows=0 loops=1)
>                ->  Bitmap Index Scan on lod_id_index  (cost=0.00..4.80
> rows=514 width=0) (actual time=0.250..0.250 rows=126 loops=1)
>                      Index Cond: ("outer".lor_id =
> line_owner_data.lod_lo_id)
>                ->  Bitmap Index Scan on lod_variable_index
> (cost=0.00..5.80 rows=514 width=0) (actual time=0.262..0.262 rows=5
> loops=1)
>                      Index Cond: (lod_variable =
> 'ISPCircuitNumber1'::text)
>  Total runtime: 2.576 ms
> (11 rows)
>
>   Any idea on what might be causing the slowdown? Is it likely
> filesystem related or am I missing for maintenance step?

You'll notice that in the first query your row estimates are off by
several orders of magnitude, where in the second query they are much
more accurate.

I'm guessing that the data is changing a fair bit over time
(inserts/updates/deletes) and you are not ANALYZEing regularly (and
probably not VACUUMing regularly either).

Try regular VACUUM ANALYZE DATABASE rather than VACUUM FULL or a
dump/reload.

Cheers,
Gary.