Re: Unusually high IO for autovacuum worker

[Vlad Bailescu <vlad@xxxxxxxxxxxxxxxxxx>]

On Fri, Feb 1, 2013 at 1:08 PM, Pavan Deolasee <pavan.deolasee@xxxxxxxxx> wrote:

On Fri, Feb 1, 2013 at 3:24 PM, Vlad Bailescu <vlad@xxxxxxxxxxxxxxxxxx> wrote:

Stats show only 3 tables get frequently autovacuumed

Table Name	Tuples inserted	Tuples updated	Tuples deleted	Tuples HOT updated	Live Tuples	Dead Tuples	Last vacuum	Last autovacuum	Last analyze	Last autoanalyze	Vacuum counter	Autovacuum counter	Analyze counter	Autoanalyze counter	Size
vehicle_position	4689127	0	4689127	0	0	1985		2013-02-01 11:46:46.441227+02	2013-01-31 14:48:00.775864+02	2013-02-01 11:46:46.494234+02	0	3761	1	3754	4016 kB
vehicle	2124	934640	0	924003	2124	390		2013-02-01 11:47:46.067695+02		2013-02-01 11:47:46.325444+02	0	1293	0	2038	2448 kB
input_current	10032	1649206	0	1635902	10032	1728		2013-02-01 11:45:46.0681+02		2013-02-01 11:45:46.215048+02	0	442	0	1294	2336 kB

So sure there are more than just one table involved here. Also, the last column in the

output above shows that these are fairly large tables. In fact, if the last column is to be

trusted, they are as large 37GB, 20GB and 12GB respectively. Note the kB at the end of

those values. Also given the large number of inserts/deletes, I would doubt if the table can

really remain that small. May be auto-vacuum is truncating most of it and thats why you

see only a few MBs before it swells again by the time next vacuum cycles runs.

Whats your rate of insertion/deletion in the first table ? You also seem to be updating the

last two tables quite heavily, but most of them are HOT updates, so your tables should not

bloat too much.

Thanks,

Pavan

--
Pavan Deolasee
http://www.linkedin.com/in/pavandeolasee

Pavan, it seems there's a small issue with copy-paste and column text-align. Table sizes are:

4136 kB

2448 kB

2336 kB

The actual partition tables are very large (ie:  vehicle_position_y2013_m01 is 6448 MB), but they don't seem to receive so much attention.

The vehicle table gets updated very often because it has a foreign key to vehicle_position and that changes with every batch of data.

We were able to reproduce this on a test VM with minimum workload to trigger autovacuum. Here's the relevant log portion:


2012-12-05 00:32:57 EET LOG:  database system is ready to accept connections

2012-12-05 00:32:57 EET LOG:  autovacuum launcher started
2012-12-05 00:36:38 EET LOG:  automatic analyze of table "fleet.fleet.vehicle_position" system usage: CPU 0.00s/0.00u sec elapsed 0.03 sec
2012-12-05 00:37:39 EET LOG:  automatic analyze of table "fleet.fleet.vehicle_position_default" system usage: CPU 0.00s/0.15u sec elapsed 0.99 sec

2012-12-05 00:44:23 EET LOG:  automatic analyze of table "fleet.fleet.vehicle_position" system usage: CPU 4.46s/0.61u sec elapsed 465.09 sec
2012-12-05 00:44:38 EET LOG:  automatic vacuum of table "fleet.fleet.vehicle_position": index scans: 1

        pages: 8 removed, 0 remain
        tuples: 64 removed, 0 remain
        system usage: CPU 0.00s/0.00u sec elapsed 0.02 sec
2012-12-05 00:44:38 EET LOG:  automatic analyze of table "fleet.fleet.vehicle_position" system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec

2012-12-05 00:51:40 EET LOG:  automatic analyze of table "fleet.fleet.vehicle_position" system usage: CPU 4.34s/0.53u sec elapsed 422.20 sec
2012-12-05 00:52:38 EET LOG:  automatic vacuum of table "fleet.fleet.vehicle_position": index scans: 1

        pages: 10 removed, 0 remain
        tuples: 30 removed, 0 remain
        system usage: CPU 0.00s/0.00u sec elapsed 0.02 sec
2012-12-05 00:52:38 EET LOG:  automatic analyze of table "fleet.fleet.vehicle_position" system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec

During the analyze the IO was ~800-1000 K/s

Vlad