Re: BUG #5200: Use of min suffix in autovacuum_naptime ignored

Sorry force of habit with the CC.

Sorry a bit of confusion here with the documentations meaing.

Does the autovacuum_naptime also then mean that the daemon will wil try to scan all databases within system in the autovacuum_naptime?
Therefore as the number of databases increases the amount of work the autovacuum daemon has to do in the autovacuum_naptime interval increases?
Is that why with the setting set to 1min it scans a new database every second yet with it set to 60min it spaces out the vacuums to make sure it gets through them all in 60min?

Finally do people think it could be better to have some sort of configuration option to allow spacing between autovacuum runs across the whole system? This would stop the heavy statistics gatherer load I see with the current way autovacuum works when there are a large number of databases? (sorry for all the questions)

Maybe something like a scale factor as there are for other autovacuum options...

(Sorry again if i've got the way it all works wrong...)

-Andrew
________________________________________
From: Heikki Linnakangas [heikki(dot)linnakangas(at)enterprisedb(dot)com]
Sent: 21 November 2009 15:08
To: A.J.Masterton
Cc: PostgreSQL Bugs
Subject: Re: [BUGS] BUG #5200: Use of min suffix in autovacuum_naptime ignored

(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(dot)linnakangas(at)enterprisedb(dot)com]
> Sent: 20 November 2009 19:51
> To: Andrew Masterton
> Cc: pgsql-bugs(at)postgresql(dot)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(dot)j(dot)masterton(at)open(dot)ac(dot)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

The Open University is incorporated by Royal Charter (RC 000391), an exempt charity in England & Wales and a charity registered in Scotland (SC 038302).