Search Postgresql Archives

Re: Why does autovacuum run in so small blocks?

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



In response to hubert depesz lubaczewski <depesz@xxxxxxxxxx>:

> hi,
> I have strange situation with one table.
> 
> base info: pg 8.4.8
> 
> here is info from pg_stat_all_tables about i:
>               now              | relid | n_tup_ins | n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup |       last_autovacuum
> -------------------------------+-------+-----------+-----------+-----------+---------------+------------+------------+------------------------------
>  2011-11-09 21:07:02.250232+00 | xxx   |      4184 |   1069977 |         0 |        621580 |       4184 |          0 | 2011-11-09 21:06:35.23673+00
>  2011-11-09 21:07:22.312616+00 | xxx   |      4184 |   1069977 |         0 |        621580 |       4184 |          0 | 2011-11-09 21:06:35.23673+00
>  2011-11-09 21:07:42.377629+00 | xxx   |      4184 |   1069977 |         0 |        621580 |       4184 |          0 | 2011-11-09 21:06:35.23673+00
>  2011-11-09 21:08:02.491853+00 | xxx   |      4184 |   1069977 |         0 |        621580 |       4184 |          0 | 2011-11-09 21:06:35.23673+00
>  2011-11-09 21:08:22.575746+00 | xxx   |      4184 |   1069977 |         0 |        621580 |       4184 |          0 | 2011-11-09 21:06:35.23673+00
>  2011-11-09 21:08:42.641988+00 | xxx   |      4184 |   1069977 |         0 |        621580 |       4184 |          0 | 2011-11-09 21:06:35.23673+00
>  2011-11-09 21:09:02.705319+00 | xxx   |      4184 |   1069977 |         0 |        621580 |       4184 |          0 | 2011-11-09 21:06:35.23673+00
>  2011-11-09 21:09:22.769856+00 | xxx   |      4184 |   1069977 |         0 |        621580 |       4184 |          0 | 2011-11-09 21:06:35.23673+00
>  2011-11-09 21:09:42.837779+00 | xxx   |      4184 |   1069977 |         0 |        621580 |       4184 |          0 | 2011-11-09 21:06:35.23673+00
>  2011-11-09 21:10:02.903242+00 | xxx   |      4184 |   1069977 |         0 |        621580 |       4184 |          0 | 2011-11-09 21:06:35.23673+00
>  2011-11-09 21:10:23.315874+00 | xxx   |      4184 |   1070484 |         0 |        621949 |       4184 |        507 | 2011-11-09 21:06:35.23673+00
>  2011-11-09 21:10:43.38273+00  | xxx   |      4184 |   1070484 |         0 |        621949 |       4184 |        507 | 2011-11-09 21:10:24.161642+00
>  2011-11-09 21:11:03.44763+00  | xxx   |      4184 |   1070484 |         0 |        621949 |       4184 |        507 | 2011-11-09 21:10:24.161642+00
>  2011-11-09 21:11:23.51432+00  | xxx   |      4184 |   1070484 |         0 |        621949 |       4184 |          0 | 2011-11-09 21:11:20.879516+00
>  2011-11-09 21:11:43.576631+00 | xxx   |      4184 |   1070484 |         0 |        621949 |       4184 |          0 | 2011-11-09 21:11:20.879516+00
>  2011-11-09 21:12:03.643183+00 | xxx   |      4184 |   1070484 |         0 |        621949 |       4184 |          0 | 2011-11-09 21:11:20.879516+00
>  2011-11-09 21:12:23.699986+00 | xxx   |      4184 |   1070484 |         0 |        621949 |       4184 |          0 | 2011-11-09 21:11:20.879516+00
>  2011-11-09 21:12:43.762559+00 | xxx   |      4184 |   1070484 |         0 |        621949 |       4184 |          0 | 2011-11-09 21:11:20.879516+00
>  2011-11-09 21:13:03.8274+00   | xxx   |      4184 |   1070484 |         0 |        621949 |       4184 |          0 | 2011-11-09 21:11:20.879516+00
> 
> as you can see within ~ 5 minutes, there were no inserts, just some updates.
> Which explains (kind of) the autovacuum at 21:10:24.161642+00
> but why was there another one at 21:11:20.879516+00?
> 
> In logs I see:
> 
> 2011-11-09 21:06:35.236 GMT::@:[6957]:LOG:  automatic vacuum of table "public.xxx": index scans: 1
>         pages: 0 removed, 1094 remain
>         tuples: 704 removed, 2990 remain
>         system usage: CPU 0.00s/0.01u sec elapsed 0.10 sec
> --
> 2011-11-09 21:10:24.161 GMT::@:[8161]:LOG:  automatic vacuum of table "public.xxx": index scans: 0
>         pages: 0 removed, 1094 remain
>         tuples: 0 removed, 3516 remain
>         system usage: CPU 0.00s/0.00u sec elapsed 0.05 sec
> --
> 2011-11-09 21:11:20.879 GMT::@:[8467]:LOG:  automatic vacuum of table "public.xxx": index scans: 1
>         pages: 0 removed, 1094 remain
>         tuples: 507 removed, 2938 remain
>         system usage: CPU 0.00s/0.01u sec elapsed 0.01 sec
> 
> the question basically is - why do we have so many vacuums?
> especially the ones that don't do anything?

My guess would be that the vacuum was triggered by updates, but there were
active transactions that prevented vacuum from cleaning up the dead tuples,
so it came back later and was able to clean them up at that time.

Would need to do a little more in-depth research/monitoring to determine
if that guess is correct or not.

-- 
Bill Moran
http://www.potentialtech.com
http://people.collaborativefusion.com/~wmoran/

-- 
Sent via pgsql-general mailing list (pgsql-general@xxxxxxxxxxxxxx)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general


[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
[Index of Archives]     [Postgresql Jobs]     [Postgresql Admin]     [Postgresql Performance]     [Linux Clusters]     [PHP Home]     [PHP on Windows]     [Kernel Newbies]     [PHP Classes]     [PHP Books]     [PHP Databases]     [Postgresql & PHP]     [Yosemite]
  Powered by Linux