(Please keep the list CC'd so that others can help) Autovacuum_naptime is the minimum delay between autovacuum runs *on any given database*, so what you're seeing is normal.
A.J.Masterton wrote: > The relevant lines from the config file are below. In this exmple the > autovacuum_naptime is set to 1min which is the default. > > #------------------------------------------------------------------------------ > # AUTOVACUUM PARAMETERS > #------------------------------------------------------------------------------ > > autovacuum = on # Enable autovacuum subprocess? 'on' > # requires track_counts to also be on. > log_autovacuum_min_duration = 0 # -1 disables, 0 logs all actions and > # their durations, > 0 logs only > # actions running at least that time. > autovacuum_max_workers = 3 # max number of autovacuum > subprocesses > autovacuum_naptime = 1min # time between autovacuum runs > autovacuum_vacuum_threshold = 50 # min number of row updates before > # vacuum > autovacuum_analyze_threshold = 50 # min number of row updates before > # analyze > autovacuum_vacuum_scale_factor = 0.2 # fraction of table size before vacuum > autovacuum_analyze_scale_factor = 0.1 # fraction of table size before > analyze > autovacuum_freeze_max_age = 200000000 # maximum XID age before forced vacuum > # (change requires restart) > autovacuum_vacuum_cost_delay = 20 # default vacuum cost delay for > # autovacuum, -1 means use > # vacuum_cost_delay > autovacuum_vacuum_cost_limit = -1 # default vacuum cost limit for > # autovacuum, -1 means use > # vacuum_cost_limit > > Below is a set of postgres log lines with the setting above and > log_min_messages = debug2: > > 2009-11-20 22:11:23 GMT LOG: database system was shut down at 2009-11-20 > 22:11:21 GMT > 2009-11-20 22:11:23 GMT DEBUG: checkpoint record is at 5/EB18D080 > 2009-11-20 22:11:23 GMT DEBUG: redo record is at 5/EB18D080; shutdown > TRUE > 2009-11-20 22:11:23 GMT DEBUG: next transaction ID: 0/2909382; next OID: > 2761814 > 2009-11-20 22:11:23 GMT DEBUG: next MultiXactId: 1; next > MultiXactOffset: 0 > 2009-11-20 22:11:23 GMT DEBUG: transaction ID wrap limit is 2147484025, > limited by database "sdd-demo" > 2009-11-20 22:11:23 GMT LOG: autovacuum launcher started > 2009-11-20 22:11:23 GMT LOG: database system is ready to accept > connections > 2009-11-20 22:11:24 GMT DEBUG: autovacuum: processing database "abc1" > 2009-11-20 22:11:24 GMT DEBUG: server process (PID 22183) exited with > exit code 0 > 2009-11-20 22:11:25 GMT DEBUG: autovacuum: processing database "abc2" > 2009-11-20 22:11:25 GMT DEBUG: server process (PID 22187) exited with > exit code 0 > 2009-11-20 22:11:26 GMT DEBUG: autovacuum: processing database "abc3" > 2009-11-20 22:11:26 GMT DEBUG: server process (PID 22188) exited with > exit code 0 > 2009-11-20 22:11:27 GMT DEBUG: autovacuum: processing database "test_mso" > 2009-11-20 22:11:27 GMT DEBUG: server process (PID 22189) exited with > exit code 0 > 2009-11-20 22:11:28 GMT DEBUG: autovacuum: processing database > "template1" > 2009-11-20 22:11:28 GMT DEBUG: server process (PID 22190) exited with > exit code 0 > 2009-11-20 22:11:29 GMT DEBUG: autovacuum: processing database "abc4" > 2009-11-20 22:11:29 GMT DEBUG: server process (PID 22191) exited with > exit code 0 > 2009-11-20 22:11:29 GMT DEBUG: autovacuum: processing database "abc5" > 2009-11-20 22:11:29 GMT DEBUG: server process (PID 22192) exited with > exit code 0 > 2009-11-20 22:11:30 GMT DEBUG: autovacuum: processing database "abc6" > 2009-11-20 22:11:30 GMT DEBUG: server process (PID 22193) exited with > exit code 0 > 2009-11-20 22:11:31 GMT DEBUG: autovacuum: processing database "abc7" > 2009-11-20 22:11:31 GMT DEBUG: server process (PID 22194) exited with > exit code 0 > 2009-11-20 22:11:32 GMT DEBUG: autovacuum: processing database "sdd-live" > 2009-11-20 22:11:32 GMT DEBUG: server process (PID 22195) exited with > exit code 0 > 2009-11-20 22:11:33 GMT DEBUG: autovacuum: processing database "abc8" > 2009-11-20 22:11:33 GMT DEBUG: server process (PID 22196) exited with > exit code 0 > 2009-11-20 22:11:34 GMT DEBUG: autovacuum: processing database "abc9" > 2009-11-20 22:11:34 GMT DEBUG: server process (PID 22197) exited with > exit code 0 > > As you can see the autovacuum process appears to be running every second. > > If I set the autovacuum_naptime = 60min the log output is below: > > 2009-11-20 22:18:07 GMT LOG: database system was shut down at 2009-11-20 > 22:15:17 GMT > 2009-11-20 22:18:07 GMT DEBUG: checkpoint record is at 5/EB18D0C8 > 2009-11-20 22:18:07 GMT DEBUG: redo record is at 5/EB18D0C8; shutdown > TRUE > 2009-11-20 22:18:07 GMT DEBUG: next transaction ID: 0/2909382; next OID: > 2761814 > 2009-11-20 22:18:07 GMT DEBUG: next MultiXactId: 1; next > MultiXactOffset: 0 > 2009-11-20 22:18:07 GMT DEBUG: transaction ID wrap limit is 2147484025, > limited by database "sdd-demo" > 2009-11-20 22:18:07 GMT LOG: database system is ready to accept > connections > 2009-11-20 22:18:07 GMT LOG: autovacuum launcher started > 2009-11-20 22:18:58 GMT DEBUG: autovacuum: processing database "abc1" > 2009-11-20 22:18:58 GMT DEBUG: server process (PID 22776) exited with > exit code 0 > 2009-11-20 22:19:50 GMT DEBUG: autovacuum: processing database "abc2" > 2009-11-20 22:19:50 GMT DEBUG: server process (PID 22789) exited with > exit code 0 > 2009-11-20 22:20:41 GMT DEBUG: autovacuum: processing database "abc3" > 2009-11-20 22:20:41 GMT DEBUG: server process (PID 22804) exited with > exit code 0 > 2009-11-20 22:21:32 GMT DEBUG: autovacuum: processing database "test_mso" > 2009-11-20 22:21:32 GMT DEBUG: server process (PID 22839) exited with > exit code 0 > 2009-11-20 22:22:24 GMT DEBUG: autovacuum: processing database > "template1" > 2009-11-20 22:22:24 GMT DEBUG: server process (PID 22859) exited with > exit code 0 > > As you can see the autovacuum process is now running almost every minute > (appears to be every ~52 secs) > > The installed postgres RPMs are the PGDG ons from the yum repository and the > details are below: > > postgresql-libs-8.3.8-1PGDG.rhel5.x86_64.rpm > postgresql-8.3.8-1PGDG.rhel5.x86_64.rpm > postgresql-server-8.3.8-1PGDG.rhel5.x86_64.rpm > > Not sure what else info I maybe able to give, but if there is anything more I > can help with let me know. > > -Andrew > > ________________________________________ > From: Heikki Linnakangas [heikki.linnakan...@enterprisedb.com] > Sent: 20 November 2009 19:51 > To: Andrew Masterton > Cc: pgsql-bugs@postgresql.org > Subject: Re: [BUGS] BUG #5200: Use of min suffix in autovacuum_naptime ignored > > Andrew Masterton wrote: >> The following bug has been logged online: >> >> Bug reference: 5200 >> Logged by: Andrew Masterton >> Email address: a.j.master...@open.ac.uk >> PostgreSQL version: 8.3.8 >> Operating system: RedHat Enterprise 5.4 >> Description: Use of min suffix in autovacuum_naptime ignored >> Details: >> >> The default configuration of 8.3.8 has autovacuum_naptime = 1min. It would >> appear that the min is ignored as turning up debug show the autovacuum >> running every second. On my 8.3.8 installation with a large number of >> databases and tables this has the side effect of the stats collector process >> using up large amounts of CPU and I/O. >> >> Changing this setting to 60min causes the autovacuum process to have the >> correct 60 second naptime. >> >> I Haven't tried removing the min and setting it to s to see if any time >> suffix is ignored for this configuration option. > > I can't reproduce this. Can you send the relevant lines from your > postgresql.conf and the logs showing what's happening, and/or anything > else that might help to track that down? > > -- > Heikki Linnakangas > EnterpriseDB http://www.enterprisedb.com > > > The Open University is incorporated by Royal Charter (RC 000391), an exempt > charity in England & Wales and a charity registered in Scotland (SC 038302). -- Heikki Linnakangas EnterpriseDB http://www.enterprisedb.com -- Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-bugs
