Thread: log_autovacuum

log_autovacuum

From
"Simon Riggs"
Date:
log_autovacuum = on produces a single line of output from autovacuum,
with additional useful stats. Patch is proving useful in performance
testing. Not sure what is intended on logging for 8.3....

LOG:  autovac "public.w" scans:1 pages:197(-0) tuples:2338(-7199) CPU
0.00s/0.00u sec elapsed 0.39 sec
LOG:  autovac "public.s" scans:1 pages:1926746(-0)
tuples:37000611(-3461867) CPU 99.74s/53.37u sec elapsed 7977.20 sec

No docs yet, but will do this if accepted.

scans: N     number of times indexes have been scanned
pages: remaining(-removed)
tuples: remaining(-removed)
CPU
elapsed

--
  Simon Riggs
  EnterpriseDB   http://www.enterprisedb.com


Attachment

Re: log_autovacuum

From
Neil Conway
Date:
On Thu, 2007-03-08 at 16:05 +0000, Simon Riggs wrote:
> LOG:  autovac "public.w" scans:1 pages:197(-0) tuples:2338(-7199) CPU
> 0.00s/0.00u sec elapsed 0.39 sec

Seems like a pretty cryptic log format to me.

-Neil



Re: log_autovacuum

From
Alvaro Herrera
Date:
Simon Riggs wrote:
> log_autovacuum = on produces a single line of output from autovacuum,
> with additional useful stats. Patch is proving useful in performance
> testing. Not sure what is intended on logging for 8.3....
>
> LOG:  autovac "public.w" scans:1 pages:197(-0) tuples:2338(-7199) CPU
> 0.00s/0.00u sec elapsed 0.39 sec
> LOG:  autovac "public.s" scans:1 pages:1926746(-0)
> tuples:37000611(-3461867) CPU 99.74s/53.37u sec elapsed 7977.20 sec

I agree something like this is useful, but I'd try to get rid of cryptic
notation, and maybe split in several message categories if reasonable.

Your proposal is

LOG:  autovac "public.w" scans:1 pages:197(-0) tuples:2338(-7199) CPU 0.00s/0.00u sec elapsed 0.39 sec

This looks too much like the old VACUUM VERBOSE reporting, which was
awful.  Maybe something like this is better:

LOG: index passes: 1  pages: removed 0, 197 remain  tuples: removed 7199, 2338 remain  CPU usage: whatever
CONTEXT: Automatic vacuuming of table "database.public.w"

This looks like the sort of thing comparable to picking a bikeshed color
though :-(

Keep in mind that it's going to be translated, so it's not useful for
machine parsing anyway.

--
Alvaro Herrera                                http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

Re: log_autovacuum

From
Darcy Buskermolen
Date:
On March 8, 2007 09:53 am, Alvaro Herrera wrote:
> Simon Riggs wrote:
> > log_autovacuum = on produces a single line of output from autovacuum,
> > with additional useful stats. Patch is proving useful in performance
> > testing. Not sure what is intended on logging for 8.3....
> >
> > LOG:  autovac "public.w" scans:1 pages:197(-0) tuples:2338(-7199) CPU
> > 0.00s/0.00u sec elapsed 0.39 sec
> > LOG:  autovac "public.s" scans:1 pages:1926746(-0)
> > tuples:37000611(-3461867) CPU 99.74s/53.37u sec elapsed 7977.20 sec
>
> I agree something like this is useful, but I'd try to get rid of cryptic
> notation, and maybe split in several message categories if reasonable.
>
> Your proposal is
>
> LOG:  autovac "public.w" scans:1 pages:197(-0) tuples:2338(-7199) CPU
> 0.00s/0.00u sec elapsed 0.39 sec
>
> This looks too much like the old VACUUM VERBOSE reporting, which was
> awful.  Maybe something like this is better:
>
> LOG: index passes: 1  pages: removed 0, 197 remain  tuples: removed 7199,
> 2338 remain  CPU usage: whatever CONTEXT: Automatic vacuuming of table
> "database.public.w"
>
> This looks like the sort of thing comparable to picking a bikeshed color
> though :-(
>
> Keep in mind that it's going to be translated, so it's not useful for
> machine parsing anyway.

This goes back to the request for vacuum loging to a table..

--
Darcy Buskermolen
Command Prompt, Inc.
Sales/Support: +1.503.667.4564 || 24x7/Emergency: +1.800.492.2240
PostgreSQL solutions since 1997
http://www.commandprompt.com/

Re: log_autovacuum

From
Alvaro Herrera
Date:
Darcy Buskermolen wrote:
> On March 8, 2007 09:53 am, Alvaro Herrera wrote:

> > Keep in mind that it's going to be translated, so it's not useful for
> > machine parsing anyway.
>
> This goes back to the request for vacuum loging to a table..

That's right, but please let's have at least *something*.

--
Alvaro Herrera                                http://www.CommandPrompt.com/
The PostgreSQL Company - Command Prompt, Inc.

Re: log_autovacuum

From
"Simon Riggs"
Date:
On Thu, 2007-03-08 at 14:53 -0300, Alvaro Herrera wrote:
>  Maybe something like this is better:
>
> LOG: index passes: 1  pages: removed 0, 197 remain  tuples: removed 7199, 2338 remain  CPU usage: whatever
> CONTEXT: Automatic vacuuming of table "database.public.w"

Yours is better.

I've implemented this:

LOG: autovac "public.w" index passes: 1  pages: removed 0, 197 remain
tuples: removed 7199, 2338 remain  CPU usage: whatever

I'm happy if this gets removed later, but I think it will help everybody
understand how multi-vacuums are working and what the best way to
specify the controls should be.

Not sure about the CONTEXT bit. I think its verbose, plus I thought that
was for ERRORs only. I will defer on this point, since I know y'all
understand that better than I.

--
  Simon Riggs
  EnterpriseDB   http://www.enterprisedb.com


Attachment

Re: log_autovacuum

From
NikhilS
Date:
Hi,

On 3/9/07, Simon Riggs <simon@2ndquadrant.com> wrote:
On Thu, 2007-03-08 at 14:53 -0300, Alvaro Herrera wrote:
>  Maybe something like this is better:
>
> LOG: index passes: 1  pages: removed 0, 197 remain  tuples: removed 7199, 2338 remain  CPU usage: whatever
> CONTEXT: Automatic vacuuming of table "database.public.w"

Yours is better.

I've implemented this:

LOG: autovac "public.w" index passes: 1  pages: removed 0, 197 remain
tuples: removed 7199, 2338 remain  CPU usage: whatever

I'm happy if this gets removed later, but I think it will help everybody
understand how multi-vacuums are working and what the best way to
specify the controls should be.

Not sure about the CONTEXT bit. I think its verbose, plus I thought that
was for ERRORs only. I will defer on this point, since I know y'all
understand that better than I.

IMHO, it would be good to have both the messages spit out. The earlier message is much better for parsing and the later makes READABLE sense.

Regards,
Nikhils
 
--
EnterpriseDB               http://www.enterprisedb.com

Re: log_autovacuum

From
Bruce Momjian
Date:
Your patch has been added to the PostgreSQL unapplied patches list at:

    http://momjian.postgresql.org/cgi-bin/pgpatches

It will be applied as soon as one of the PostgreSQL committers reviews
and approves it.

---------------------------------------------------------------------------


Simon Riggs wrote:
> On Thu, 2007-03-08 at 14:53 -0300, Alvaro Herrera wrote:
> >  Maybe something like this is better:
> >
> > LOG: index passes: 1  pages: removed 0, 197 remain  tuples: removed 7199, 2338 remain  CPU usage: whatever
> > CONTEXT: Automatic vacuuming of table "database.public.w"
>
> Yours is better.
>
> I've implemented this:
>
> LOG: autovac "public.w" index passes: 1  pages: removed 0, 197 remain
> tuples: removed 7199, 2338 remain  CPU usage: whatever
>
> I'm happy if this gets removed later, but I think it will help everybody
> understand how multi-vacuums are working and what the best way to
> specify the controls should be.
>
> Not sure about the CONTEXT bit. I think its verbose, plus I thought that
> was for ERRORs only. I will defer on this point, since I know y'all
> understand that better than I.
>
> --
>   Simon Riggs
>   EnterpriseDB   http://www.enterprisedb.com
>

[ Attachment, skipping... ]

>
> ---------------------------(end of broadcast)---------------------------
> TIP 1: if posting/reading through Usenet, please send an appropriate
>        subscribe-nomail command to majordomo@postgresql.org so that your
>        message can get through to the mailing list cleanly

--
  Bruce Momjian  <bruce@momjian.us>          http://momjian.us
  EnterpriseDB                               http://www.enterprisedb.com

  + If your life is a hard drive, Christ can be your backup. +

Re: log_autovacuum

From
Alvaro Herrera
Date:
Simon Riggs wrote:
> On Thu, 2007-03-08 at 14:53 -0300, Alvaro Herrera wrote:
> >  Maybe something like this is better:
> >
> > LOG: index passes: 1  pages: removed 0, 197 remain  tuples: removed 7199, 2338 remain  CPU usage: whatever
> > CONTEXT: Automatic vacuuming of table "database.public.w"
>
> Yours is better.
>
> I've implemented this:
>
> LOG: autovac "public.w" index passes: 1  pages: removed 0, 197 remain
> tuples: removed 7199, 2338 remain  CPU usage: whatever
>
> I'm happy if this gets removed later, but I think it will help everybody
> understand how multi-vacuums are working and what the best way to
> specify the controls should be.
>
> Not sure about the CONTEXT bit. I think its verbose, plus I thought that
> was for ERRORs only. I will defer on this point, since I know y'all
> understand that better than I.

I've tinkered with this patch a bit.  Sample output:

LOG:  automatic vacuum of table "alvherre.public.foo": index scans: 0
        pages: removed 0, 11226 remain
        tuples: 1300683 removed, 1096236 remain
        system usage: CPU 0.29s/0.38u sec elapsed 2.56 sec

Please comment.

--
Alvaro Herrera                                http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

Re: log_autovacuum

From
"Simon Riggs"
Date:
On Tue, 2007-04-17 at 14:06 -0400, Alvaro Herrera wrote:
> Simon Riggs wrote:
> > On Thu, 2007-03-08 at 14:53 -0300, Alvaro Herrera wrote:
> > >  Maybe something like this is better:
> > >
> > > LOG: index passes: 1  pages: removed 0, 197 remain  tuples: removed 7199, 2338 remain  CPU usage: whatever
> > > CONTEXT: Automatic vacuuming of table "database.public.w"
> >
> > Yours is better.
> >
> > I've implemented this:
> >
> > LOG: autovac "public.w" index passes: 1  pages: removed 0, 197 remain
> > tuples: removed 7199, 2338 remain  CPU usage: whatever
> >
> > I'm happy if this gets removed later, but I think it will help everybody
> > understand how multi-vacuums are working and what the best way to
> > specify the controls should be.
> >
> > Not sure about the CONTEXT bit. I think its verbose, plus I thought that
> > was for ERRORs only. I will defer on this point, since I know y'all
> > understand that better than I.
>
> I've tinkered with this patch a bit.  Sample output:
>
> LOG:  automatic vacuum of table "alvherre.public.foo": index scans: 0
>         pages: removed 0, 11226 remain
>         tuples: 1300683 removed, 1096236 remain
>         system usage: CPU 0.29s/0.38u sec elapsed 2.56 sec
>
> Please comment.

Well, 'tis great except when you have very very frequent autovacuums.
That was why I wanted it in 1 log line.

Perhaps we need this as an integer, so we can log all vacuums that last
for longer in seconds than the setting, 0 logs all. That would
significantly reduce the volume if we set it to 5, say. That way you
would get your readability and I would get my reasonable size logs.

I guess we need to see how this interacts with HOT, as well.

Presumably you mean to have both removeds in the same order?
>         pages: 0 removed, 11226 remain
>         tuples: 1300683 removed, 1096236 remain


--
  Simon Riggs
  EnterpriseDB   http://www.enterprisedb.com



Re: log_autovacuum

From
Tom Lane
Date:
Alvaro Herrera <alvherre@commandprompt.com> writes:
> I've tinkered with this patch a bit.  Sample output:

> LOG:  automatic vacuum of table "alvherre.public.foo": index scans: 0
>         pages: removed 0, 11226 remain
>         tuples: 1300683 removed, 1096236 remain
>         system usage: CPU 0.29s/0.38u sec elapsed 2.56 sec

Please be a bit more consistent about whether numbers precede or follow
their descriptions.  "x removed, y remain" might work.

            regards, tom lane

Re: log_autovacuum

From
Alvaro Herrera
Date:
Tom Lane wrote:
> Alvaro Herrera <alvherre@commandprompt.com> writes:
> > I've tinkered with this patch a bit.  Sample output:
>
> > LOG:  automatic vacuum of table "alvherre.public.foo": index scans: 0
> >         pages: removed 0, 11226 remain
> >         tuples: 1300683 removed, 1096236 remain
> >         system usage: CPU 0.29s/0.38u sec elapsed 2.56 sec
>
> Please be a bit more consistent about whether numbers precede or follow
> their descriptions.  "x removed, y remain" might work.

Fixed.

--
Alvaro Herrera                                http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

Re: log_autovacuum

From
Alvaro Herrera
Date:
Simon Riggs wrote:
> On Tue, 2007-04-17 at 14:06 -0400, Alvaro Herrera wrote:

> > I've tinkered with this patch a bit.  Sample output:
> >
> > LOG:  automatic vacuum of table "alvherre.public.foo": index scans: 0
> >         pages: removed 0, 11226 remain
> >         tuples: 1300683 removed, 1096236 remain
> >         system usage: CPU 0.29s/0.38u sec elapsed 2.56 sec
> >
> > Please comment.
>
> Well, 'tis great except when you have very very frequent autovacuums.
> That was why I wanted it in 1 log line.
>
> Perhaps we need this as an integer, so we can log all vacuums that last
> for longer in seconds than the setting, 0 logs all. That would
> significantly reduce the volume if we set it to 5, say. That way you
> would get your readability and I would get my reasonable size logs.

It kinda smells funny to have a setting like that.  Do we have a
precedent?  If other people is OK with it, I'll do that.

Would it work to add a separate GUC var to control the minimum autovac
time?  Also, why do it by time and not by amount of tuples/pages
removed?

> Presumably you mean to have both removeds in the same order?
> >         pages: 0 removed, 11226 remain
> >         tuples: 1300683 removed, 1096236 remain

Right, fixed.

Also, here is the patch.

--
Alvaro Herrera                                http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

Attachment

Re: log_autovacuum

From
Tom Lane
Date:
Alvaro Herrera <alvherre@commandprompt.com> writes:
> Simon Riggs wrote:
>> Perhaps we need this as an integer, so we can log all vacuums that last
>> for longer in seconds than the setting, 0 logs all. That would
>> significantly reduce the volume if we set it to 5, say. That way you
>> would get your readability and I would get my reasonable size logs.

> It kinda smells funny to have a setting like that.  Do we have a
> precedent?  If other people is OK with it, I'll do that.

Sure, log_min_duration_statement.  Applying the same concept to autovac
logging makes sense to me.  In fact, what you've got now is equivalent
to an unconditional log_statement boolean, which is about where we were
three or four releases ago on statement logging.  History suggests that
we'd soon want it to be more flexible than that.  It seems sane to me
to skip the boolean stage and go straight to a threshold parameter.

> Also, why do it by time and not by amount of tuples/pages removed?

One, it's consistent with the way we do thresholded statement logging.
Two, time is a better indicator of effort expended --- consider
vacuuming a very large table that has only a few dead tuples.

We might want to add logging thresholds for pages/tuples later, but
for now I'd vote for just one parameter: a time threshold.

            regards, tom lane

Re: log_autovacuum

From
"Simon Riggs"
Date:
On Tue, 2007-04-17 at 14:45 -0400, Alvaro Herrera wrote:
> Simon Riggs wrote:
> > On Tue, 2007-04-17 at 14:06 -0400, Alvaro Herrera wrote:
>
> > > I've tinkered with this patch a bit.  Sample output:
> > >
> > > LOG:  automatic vacuum of table "alvherre.public.foo": index scans: 0
> > >         pages: removed 0, 11226 remain
> > >         tuples: 1300683 removed, 1096236 remain
> > >         system usage: CPU 0.29s/0.38u sec elapsed 2.56 sec
> > >
> > > Please comment.
> >
> > Well, 'tis great except when you have very very frequent autovacuums.
> > That was why I wanted it in 1 log line.
> >
> > Perhaps we need this as an integer, so we can log all vacuums that last
> > for longer in seconds than the setting, 0 logs all. That would
> > significantly reduce the volume if we set it to 5, say. That way you
> > would get your readability and I would get my reasonable size logs.
>
> It kinda smells funny to have a setting like that.  Do we have a
> precedent?  If other people is OK with it, I'll do that.

log_temp_files works a bit like that, as does log_min_duration_statement

perhaps log_min_duration_vacuum?
that would be easier to understand

> Would it work to add a separate GUC var to control the minimum autovac
> time?  Also, why do it by time and not by amount of tuples/pages
> removed?

...because you only want to know about slow vacuums.

Time is a more natural unit than tuples removed.

--
  Simon Riggs
  EnterpriseDB   http://www.enterprisedb.com



Re: log_autovacuum

From
Bill Moran
Date:
In response to Alvaro Herrera <alvherre@commandprompt.com>:

> Simon Riggs wrote:
> > On Tue, 2007-04-17 at 14:06 -0400, Alvaro Herrera wrote:
>
> > > I've tinkered with this patch a bit.  Sample output:
> > >
> > > LOG:  automatic vacuum of table "alvherre.public.foo": index scans: 0
> > >         pages: removed 0, 11226 remain
> > >         tuples: 1300683 removed, 1096236 remain
> > >         system usage: CPU 0.29s/0.38u sec elapsed 2.56 sec
> > >
> > > Please comment.
> >
> > Well, 'tis great except when you have very very frequent autovacuums.
> > That was why I wanted it in 1 log line.
> >
> > Perhaps we need this as an integer, so we can log all vacuums that last
> > for longer in seconds than the setting, 0 logs all. That would
> > significantly reduce the volume if we set it to 5, say. That way you
> > would get your readability and I would get my reasonable size logs.
>
> It kinda smells funny to have a setting like that.  Do we have a
> precedent?  If other people is OK with it, I'll do that.
>
> Would it work to add a separate GUC var to control the minimum autovac
> time?  Also, why do it by time and not by amount of tuples/pages
> removed?

When I submitted the log_temp_files stuff, there was considerable
discussion on the topic of how the GUC vars should be done.  IIRC, the
eventual decision was to have a single GUC var, where -1 equated to
off, 0 equated to log all, and numbers higher than 0 were a size limit
on when things get logged.

--
Bill Moran
Collaborative Fusion Inc.
http://people.collaborativefusion.com/~wmoran/

wmoran@collaborativefusion.com
Phone: 412-422-3463x4023

****************************************************************
IMPORTANT: This message contains confidential information and is
intended only for the individual named. If the reader of this
message is not an intended recipient (or the individual
responsible for the delivery of this message to an intended
recipient), please be advised that any re-use, dissemination,
distribution or copying of this message is prohibited. Please
notify the sender immediately by e-mail if you have received
this e-mail by mistake and delete this e-mail from your system.
E-mail transmission cannot be guaranteed to be secure or
error-free as information could be intercepted, corrupted, lost,
destroyed, arrive late or incomplete, or contain viruses. The
sender therefore does not accept liability for any errors or
omissions in the contents of this message, which arise as a
result of e-mail transmission.
****************************************************************

Re: log_autovacuum

From
Tom Lane
Date:
BTW, shouldn't the log entry distinguish whether this was VACUUM,
ANALYZE, or both?

            regards, tom lane

Re: log_autovacuum

From
Alvaro Herrera
Date:
Tom Lane wrote:
> BTW, shouldn't the log entry distinguish whether this was VACUUM,
> ANALYZE, or both?

We don't actually log anything for ANALYZE (the logging code is in
lazy_vacuum_rel).

Maybe it should be in autovacuum.c.

--
Alvaro Herrera                                http://www.CommandPrompt.com/
The PostgreSQL Company - Command Prompt, Inc.

Re: log_autovacuum

From
"Simon Riggs"
Date:
On Tue, 2007-04-17 at 16:41 -0400, Alvaro Herrera wrote:
> Tom Lane wrote:
> > BTW, shouldn't the log entry distinguish whether this was VACUUM,
> > ANALYZE, or both?
>
> We don't actually log anything for ANALYZE (the logging code is in
> lazy_vacuum_rel).

When ANALYZE starts taking some time, we can log it.

> Maybe it should be in autovacuum.c.

Well, I figured if it was the right place for VACUUM it was good enough
for autovacuum too.


--
  Simon Riggs
  EnterpriseDB   http://www.enterprisedb.com



Re: log_autovacuum

From
Alvaro Herrera
Date:
Alvaro Herrera wrote:
> Tom Lane wrote:
> > BTW, shouldn't the log entry distinguish whether this was VACUUM,
> > ANALYZE, or both?
>
> We don't actually log anything for ANALYZE (the logging code is in
> lazy_vacuum_rel).
>
> Maybe it should be in autovacuum.c.

The only problem with this is that we would have to export struct
LVRelStats definition from vacuumlazy.c and pass the struct back ...
which wouldn't directly work on ANALYZE.  What we could do is pass back
a "void *" pointer, which lazyvacuum.c or the analyze code knows how to
turn into a string.

I have no problem both ways.  Here is the current patch (logging code
still in lazy_vacuum_rel, log_autovacuum morphed into an integer
variable).

Opinions?

--
Alvaro Herrera                                http://www.CommandPrompt.com/
The PostgreSQL Company - Command Prompt, Inc.

Attachment

Re: log_autovacuum

From
Tom Lane
Date:
Alvaro Herrera <alvherre@commandprompt.com> writes:
> Alvaro Herrera wrote:
>> Tom Lane wrote:
>>> BTW, shouldn't the log entry distinguish whether this was VACUUM,
>>> ANALYZE, or both?
>>
>> We don't actually log anything for ANALYZE (the logging code is in
>> lazy_vacuum_rel).
>>
>> Maybe it should be in autovacuum.c.

Actually, I had misunderstood where you were proposing to put this.
I believe that where you have it, the elapsed-time indication will
only cover the VACUUM step; so it's not relevant to this code whether
an ANALYZE would happen too.

My suggestion is that you add similar but independent logging to
analyze.c, controlled by the same min-duration variable.  So the
log output would treat autovac and autoanalyze as two independently
loggable operations.  I don't think there's much to print about
an autoanalyze except its runtime ... well, maybe you could print
the numbers of rows sampled and estimated, but I dunno if it matters.
The point of doing it is just to be able to track what the heck
autovacuum is doing ...

            regards, tom lane

Re: log_autovacuum

From
Alvaro Herrera
Date:
Tom Lane wrote:
> Alvaro Herrera <alvherre@commandprompt.com> writes:
> > Alvaro Herrera wrote:
> >> Tom Lane wrote:
> >>> BTW, shouldn't the log entry distinguish whether this was VACUUM,
> >>> ANALYZE, or both?
> >>
> >> We don't actually log anything for ANALYZE (the logging code is in
> >> lazy_vacuum_rel).
> >>
> >> Maybe it should be in autovacuum.c.
>
> Actually, I had misunderstood where you were proposing to put this.
> I believe that where you have it, the elapsed-time indication will
> only cover the VACUUM step; so it's not relevant to this code whether
> an ANALYZE would happen too.

Correct.

> My suggestion is that you add similar but independent logging to
> analyze.c, controlled by the same min-duration variable.  So the
> log output would treat autovac and autoanalyze as two independently
> loggable operations.  I don't think there's much to print about
> an autoanalyze except its runtime ... well, maybe you could print
> the numbers of rows sampled and estimated, but I dunno if it matters.
> The point of doing it is just to be able to track what the heck
> autovacuum is doing ...

Seems fair.  Updated patch attached.

If there are no further comments, I'll add some docs and apply it later.

--
Alvaro Herrera                                http://www.CommandPrompt.com/
The PostgreSQL Company - Command Prompt, Inc.

Attachment

Re: log_autovacuum

From
Alvaro Herrera
Date:
Alvaro Herrera wrote:

> Seems fair.  Updated patch attached.
>
> If there are no further comments, I'll add some docs and apply it later.

If autovacuum_vacuum_cost_delay is set to 20, my pitiful desktop system
takes 8.4 seconds to analyze a 8000 page table:

DEBUG:  "bar": scanned 3000 of 8811 pages, containing 681000 live rows and 0 dead rows; 3000 rows in sample, 2000097
estimatedtotal rows 
LOG:  automatic analyze of table "alvherre.public.bar" system usage: CPU 0.00s/0.01u sec elapsed 8.39 sec

So I guess logging on ANALYZE is not that removed from reality.

I also think we should remove these DEBUG messages, that are now
useless:

DEBUG:  autovac: will ANALYZE bar

--
Alvaro Herrera                                http://www.CommandPrompt.com/
The PostgreSQL Company - Command Prompt, Inc.

Re: log_autovacuum

From
Tom Lane
Date:
Alvaro Herrera <alvherre@commandprompt.com> writes:
> I also think we should remove these DEBUG messages, that are now
> useless:

> DEBUG:  autovac: will ANALYZE bar

+1, those were just ad-hoc.

            regards, tom lane

Re: log_autovacuum

From
"Simon Riggs"
Date:
On Tue, 2007-04-17 at 21:45 -0400, Alvaro Herrera wrote:
> Alvaro Herrera wrote:
>
> > Seems fair.  Updated patch attached.
> >
> > If there are no further comments, I'll add some docs and apply it later.
>
> If autovacuum_vacuum_cost_delay is set to 20, my pitiful desktop system
> takes 8.4 seconds to analyze a 8000 page table:
>
> DEBUG:  "bar": scanned 3000 of 8811 pages, containing 681000 live rows and 0 dead rows; 3000 rows in sample, 2000097
estimatedtotal rows 
> LOG:  automatic analyze of table "alvherre.public.bar" system usage: CPU 0.00s/0.01u sec elapsed 8.39 sec
>
> So I guess logging on ANALYZE is not that removed from reality.
>
> I also think we should remove these DEBUG messages, that are now
> useless:
>
> DEBUG:  autovac: will ANALYZE bar

Looks good.

--
  Simon Riggs
  EnterpriseDB   http://www.enterprisedb.com



Re: log_autovacuum

From
Alvaro Herrera
Date:
I applied this patch some hours ago but I haven't gotten the
pgsql-committers mail and I don't see it in the archives either.  Here
is the evidence:

http://developer.postgresql.org/cvsweb.cgi/pgsql/doc/src/sgml/config.sgml

Is there a problem with pgsql-committers again?  Attached is the patch I
applied.

$ cvs commit -F msg
? msg
? cscope.out
? cscope.files
Checking in doc/src/sgml/config.sgml;
/cvsroot/pgsql/doc/src/sgml/config.sgml,v  <--  config.sgml
new revision: 1.121; previous revision: 1.120
done
Checking in src/backend/commands/analyze.c;
/cvsroot/pgsql/src/backend/commands/analyze.c,v  <--  analyze.c
new revision: 1.105; previous revision: 1.104
done
Checking in src/backend/commands/vacuumlazy.c;
/cvsroot/pgsql/src/backend/commands/vacuumlazy.c,v  <--  vacuumlazy.c
new revision: 1.86; previous revision: 1.85
done
Checking in src/backend/postmaster/autovacuum.c;
/cvsroot/pgsql/src/backend/postmaster/autovacuum.c,v  <--  autovacuum.c
new revision: 1.42; previous revision: 1.41
done
Checking in src/backend/utils/misc/guc.c;
/cvsroot/pgsql/src/backend/utils/misc/guc.c,v  <--  guc.c
new revision: 1.386; previous revision: 1.385
done
Checking in src/backend/utils/misc/postgresql.conf.sample;
/cvsroot/pgsql/src/backend/utils/misc/postgresql.conf.sample,v  <--  postgresql.conf.sample
new revision: 1.215; previous revision: 1.214
done
Checking in src/include/postmaster/autovacuum.h;
/cvsroot/pgsql/src/include/postmaster/autovacuum.h,v  <--  autovacuum.h
new revision: 1.10; previous revision: 1.9
done
Collecting file lists...Done.
Sending mail to pgsql-committers@postgresql.org...Done

--
Alvaro Herrera                                http://www.CommandPrompt.com/
The PostgreSQL Company - Command Prompt, Inc.

Attachment