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 autov=
acuum 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 seco=
nd 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 configurati=
on 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 optio=
ns...

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

-Andrew
________________________________________
From: Heikki Linnakangas [heikki.linnakangas@enterprisedb.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 igno=
red

(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 aut=
ovacuum_naptime is set to 1min which is the default.
>
> #------------------------------------------------------------------------=
------
> # AUTOVACUUM PARAMETERS
> #------------------------------------------------------------------------=
------
>
> autovacuum =3D on                         # Enable autovacuum subprocess?=
  'on'
>                                         # requires track_counts to also b=
e on.
> log_autovacuum_min_duration =3D 0         # -1 disables, 0 logs all actio=
ns and
>                                         # their durations, > 0 logs only
>                                         # actions running at least that t=
ime.
> autovacuum_max_workers =3D 3              # max number of autovacuum subp=
rocesses
> autovacuum_naptime =3D 1min               # time between autovacuum runs
> autovacuum_vacuum_threshold =3D 50        # min number of row updates bef=
ore
>                                         # vacuum
> autovacuum_analyze_threshold =3D 50       # min number of row updates bef=
ore
>                                         # analyze
> autovacuum_vacuum_scale_factor =3D 0.2    # fraction of table size before=
 vacuum
> autovacuum_analyze_scale_factor =3D 0.1   # fraction of table size before=
 analyze
> autovacuum_freeze_max_age =3D 200000000   # maximum XID age before forced=
 vacuum
>                                         # (change requires restart)
> autovacuum_vacuum_cost_delay =3D 20       # default vacuum cost delay for
>                                         # autovacuum, -1 means use
>                                         # vacuum_cost_delay
> autovacuum_vacuum_cost_limit =3D -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_m=
essages =3D debug2:
>
> 2009-11-20 22:11:23 GMT     LOG:  database system was shut down at 2009-1=
1-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; shutdow=
n 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 MultiXactOf=
fset: 0
> 2009-11-20 22:11:23 GMT     DEBUG:  transaction ID wrap limit is 21474840=
25, 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 conn=
ections
> 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 wit=
h 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 wit=
h 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 wit=
h 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 wit=
h exit code 0
> 2009-11-20 22:11:28 GMT     DEBUG:  autovacuum: processing database "temp=
late1"
> 2009-11-20 22:11:28 GMT     DEBUG:  server process (PID 22190) exited wit=
h 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 wit=
h 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 wit=
h 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 wit=
h 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 wit=
h 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 wit=
h 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 wit=
h 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 wit=
h exit code 0
>
> As you can see the autovacuum process appears to be running every second.
>
> If I set the autovacuum_naptime =3D 60min the log output is below:
>
> 2009-11-20 22:18:07 GMT     LOG:  database system was shut down at 2009-1=
1-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; shutdow=
n 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 MultiXactOf=
fset: 0
> 2009-11-20 22:18:07 GMT     DEBUG:  transaction ID wrap limit is 21474840=
25, limited by database "sdd-demo"
> 2009-11-20 22:18:07 GMT     LOG:  database system is ready to accept conn=
ections
> 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 wit=
h 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 wit=
h 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 wit=
h 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 wit=
h exit code 0
> 2009-11-20 22:22:24 GMT     DEBUG:  autovacuum: processing database "temp=
late1"
> 2009-11-20 22:22:24 GMT     DEBUG:  server process (PID 22859) exited wit=
h 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 mo=
re I can help with let me know.
>
> -Andrew
>
> ________________________________________
> From: Heikki Linnakangas [heikki.linnakangas@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 ig=
nored
>
> Andrew Masterton wrote:
>> The following bug has been logged online:
>>
>> Bug reference:      5200
>> Logged by:          Andrew Masterton
>> Email address:      a.j.masterton@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 =3D 1min. It w=
ould
>> 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 pro=
cess
>> 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 exem=
pt charity in England & Wales and a charity registered in Scotland (SC 0383=
02).


--
  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=
).