Monday, May 21, 2012

Testing 9.2: Autovacuum Logging

Since PostgreSQL 9.2 is in beta now, I've been using some generously donated cloud server time on GoGrid to test various features in the new release.  One of the ones which is working brilliantly is the new, more verbose logging for Autovacuum. 

Greg Smith and Noah Misch added additional information to the logging you get when you set log_autovacuum_min_duration.  This includes information on the work done by autovacuum (buffers, pages and tuples read and written), as well as information on when autovacuum "skips" because it can't get a lock.  Here's a sample:

LOG:  automatic analyze of table "bench2.public.pgbench_tellers" system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec
LOG:  automatic vacuum of table "bench2.public.pgbench_branches": index scans: 0
        pages: 0 removed, 2 remain
        tuples: 114 removed, 200 remain
        buffer usage: 44 hits, 0 misses, 3 dirtied
        avg read rate: 0.000 MiB/s, avg write rate: 45.334 MiB/s
        system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec
LOG:  automatic analyze of table "bench2.public.pgbench_branches" system usage: CPU 0.00s/0.00u sec elapsed 0.02 sec
LOG:  automatic analyze of table "bench2.public.pgbench_tellers" system usage: CPU 0.00s/0.00u sec elapsed 0.00 sec

This will go a long way towards helping users troubleshoot autovacuum in the future.  Great work, Greg and Noah!

2 comments:

  1. This comment has been removed by the author.

    ReplyDelete
  2. What does index scans:0 mean. Autovacuum seems to do bad things to the statistics associated with my very hot key table when that message is displayed and only recovers when index scans: 1 logged during a later autovacuum.

    ReplyDelete