Thread: Logging pg_autovacuum

Logging pg_autovacuum

From
Bruce Momjian
Date:
Tom Lane wrote:
> momjian@postgresql.org (Bruce Momjian) writes:
> > Change log message about vacuuming database name from LOG to DEBUG1.
> > Prevents duplicate meaningless log messsages.
> 
> Could we have some discussion about this sort of thing, rather than
> unilateral actions?
> 
> Those messages were at LOG level because otherwise it's difficult to be
> sure from the log that autovac is running at all.

OK, so what do we want to do?  Clearly outputing something everytime
pg_autovacuum touches a database isn't ideal.  By default, the server
logs should show significant events, which this is not.

Do we want something output only the first time autovacuum runs?

--  Bruce Momjian   http://candle.pha.pa.us EnterpriseDB    http://www.enterprisedb.com
 + If your life is a hard drive, Christ can be your backup. +


Re: Logging pg_autovacuum

From
"Matthew T. O'Connor"
Date:
I think there are two things people typically want to know from the logs:
1) Is autovacuum running
2) Did autovacuum take action (issue a VACUUM or ANALYZE)

I don't think we need mention the name of each and every database we 
touch, we can, but it should be at a lower level like DEBUG1 or something.

I don't know what logging level these thing should go at, but I for one 
would like them to be fairly high easy to get to, perhaps NOTICE?


Matt


Bruce Momjian wrote:
> Tom Lane wrote:
>> momjian@postgresql.org (Bruce Momjian) writes:
>>> Change log message about vacuuming database name from LOG to DEBUG1.
>>> Prevents duplicate meaningless log messsages.
>> Could we have some discussion about this sort of thing, rather than
>> unilateral actions?
>>
>> Those messages were at LOG level because otherwise it's difficult to be
>> sure from the log that autovac is running at all.
> 
> OK, so what do we want to do?  Clearly outputing something everytime
> pg_autovacuum touches a database isn't ideal.  By default, the server
> logs should show significant events, which this is not.
> 
> Do we want something output only the first time autovacuum runs?
> 


Re: Logging pg_autovacuum

From
Bruce Momjian
Date:
Matthew T. O'Connor wrote:
> I think there are two things people typically want to know from the logs:
> 1) Is autovacuum running
> 2) Did autovacuum take action (issue a VACUUM or ANALYZE)
> 
> I don't think we need mention the name of each and every database we 
> touch, we can, but it should be at a lower level like DEBUG1 or something.

OK, that part is done.

> I don't know what logging level these thing should go at, but I for one 
> would like them to be fairly high easy to get to, perhaps NOTICE?

Interesting idea.  I had forgotten that for server messages, LOG is at
the top, and ERROR, NOTICE, etc are below it.  We could make them
NOTICE, but then all user NOTICE messages appear in the logs too. Yuck.

Do we want to LOG everytime autovacuum does something?  Is that going to
fill up the logs worse than the per-database line?

The real issue is that we give users zero control over what autovacuum
logs, leading to the TODO item.  I guess the question is until the TODO
item is done, what do we want to do?

How do people like the idea of having this in postgresql.conf:
autovacuum_set = 'set log_min_messages = ''error'''

and set autovacuum to output notice/info/error messages as desired by
the administrator?  This shouldn't be too hard to do, and it is very
flexible.

--  Bruce Momjian   http://candle.pha.pa.us EnterpriseDB    http://www.enterprisedb.com
 + If your life is a hard drive, Christ can be your backup. +


Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Bruce Momjian wrote:
> Matthew T. O'Connor wrote:
>> I think there are two things people typically want to know from the
>> logs: 1) Is autovacuum running 2) Did autovacuum take action (issue
>> a VACUUM or ANALYZE)
>>
>> I don't think we need mention the name of each and every database we
>> touch, we can, but it should be at a lower level like DEBUG1 or
>> something.
>
> OK, that part is done.
>
>> I don't know what logging level these thing should go at, but I for
>> one would like them to be fairly high easy to get to, perhaps NOTICE?
>
> Interesting idea.  I had forgotten that for server messages, LOG is at
> the top, and ERROR, NOTICE, etc are below it.  We could make them
> NOTICE, but then all user NOTICE messages appear in the logs too.
> Yuck.
>
> Do we want to LOG everytime autovacuum does something?  Is that going
> to fill up the logs worse than the per-database line?

My general take is I (as an admin), want to know that:
a) autovacuum is doing it's periodic checks
b) when it actually vacuums a (database|table) we know what time it did  it.


>
> The real issue is that we give users zero control over what autovacuum
> logs, leading to the TODO item.  I guess the question is until the
> TODO item is done, what do we want to do?
>
> How do people like the idea of having this in postgresql.conf:
>
>     autovacuum_set = 'set log_min_messages = ''error'''
>
> and set autovacuum to output notice/info/error messages as desired by
> the administrator?  This shouldn't be too hard to do, and it is very
> flexible.

We definitely need to do "something" wrt autovacuum messages,
but this doesn't say what gets logged at what level for autovacuum.

I'd like to see a more concrete definition of what we
want Autovacuum to output and at what levels.

LER

--
Larry Rosenman
Database Support Engineer

PERVASIVE SOFTWARE. INC.
12365B RIATA TRACE PKWY
3015
AUSTIN TX  78727-6531

Tel: 512.231.6173
Fax: 512.231.6597
Email: Larry.Rosenman@pervasive.com
Web: www.pervasive.com


Re: Logging pg_autovacuum

From
Tom Lane
Date:
"Larry Rosenman" <lrosenman@pervasive.com> writes:
> I'd like to see a more concrete definition of what we 
> want Autovacuum to output and at what levels. 

I would argue that what people typically want is
(0)    nothing
(1)    per-database log messages

or
(2)    per-table log messages (including per-database)

The first problem is that (2) is only available at DEBUG2 or below,
which is not good because that also clutters the log with a whole lot of
implementer-level debugging info.

The second problem is that we don't really want to use the global
log_min_messages setting to determine this, because that constrains
your decision about how much chatter you want from ordinary backends.

I suggest that maybe the cleanest solution is to not use log level at
all for this, but to invent a separate "autovacuum_verbosity" setting
that controls how many messages autovac tries to log, using the above
scale.  Anything it does try to log can just come out at LOG message
setting.
        regards, tom lane


Re: Logging pg_autovacuum

From
"Jonah H. Harris"
Date:
On 4/27/06, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> I suggest that maybe the cleanest solution is to not use log level at
> all for this, but to invent a separate "autovacuum_verbosity" setting
> that controls how many messages autovac tries to log, using the above
> scale.  Anything it does try to log can just come out at LOG message
> setting.

/me agrees this is by all accounts, the best and cleanest option.

--
Jonah H. Harris, Database Internals Architect
EnterpriseDB Corporation
732.331.1324


Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Tom Lane wrote:
> "Larry Rosenman" <lrosenman@pervasive.com> writes:
>> I'd like to see a more concrete definition of what we
>> want Autovacuum to output and at what levels.
>
> I would argue that what people typically want is
>
>     (0)    nothing
>
>     (1)    per-database log messages
>
> or
>
>     (2)    per-table log messages (including per-database)
>
> The first problem is that (2) is only available at DEBUG2 or below,
> which is not good because that also clutters the log with a whole lot
> of implementer-level debugging info.
>
> The second problem is that we don't really want to use the global
> log_min_messages setting to determine this, because that constrains
> your decision about how much chatter you want from ordinary backends.
>
> I suggest that maybe the cleanest solution is to not use log level at
> all for this, but to invent a separate "autovacuum_verbosity" setting
> that controls how many messages autovac tries to log, using the above
> scale.  Anything it does try to log can just come out at LOG message
> setting.

This sounds like a winner to me.  Anyone else want to grab it?  I'm
in the position to try and do this, but don't want to step on anyone
else's toes.

LER

>
>             regards, tom lane



--
Larry Rosenman
Database Support Engineer

PERVASIVE SOFTWARE. INC.
12365B RIATA TRACE PKWY
3015
AUSTIN TX  78727-6531

Tel: 512.231.6173
Fax: 512.231.6597
Email: Larry.Rosenman@pervasive.com
Web: www.pervasive.com


Re: Logging pg_autovacuum

From
Chris Browne
Date:
tgl@sss.pgh.pa.us (Tom Lane) writes:

> "Larry Rosenman" <lrosenman@pervasive.com> writes:
>> I'd like to see a more concrete definition of what we 
>> want Autovacuum to output and at what levels. 
>
> I would argue that what people typically want is
>
>     (0)    nothing
>
>     (1)    per-database log messages
>
> or
>
>     (2)    per-table log messages (including per-database)
>
> The first problem is that (2) is only available at DEBUG2 or below,
> which is not good because that also clutters the log with a whole
> lot of implementer-level debugging info.
>
> The second problem is that we don't really want to use the global
> log_min_messages setting to determine this, because that constrains
> your decision about how much chatter you want from ordinary
> backends.
>
> I suggest that maybe the cleanest solution is to not use log level
> at all for this, but to invent a separate "autovacuum_verbosity"
> setting that controls how many messages autovac tries to log, using
> the above scale.  Anything it does try to log can just come out at
> LOG message setting.

At "level 2," it seems to me that it would be quite useful to have
some way of getting at the verbose output of VACUUM.

Consider when I vacuum a table, thus:

/* cbbrowne@[local]/dba2 performance=*/ vacuum verbose analyze days;
INFO:  vacuuming "public.days"
INFO:  "days": found 0 removable, 1893 nonremovable row versions in 9 pages
DETAIL:  0 dead row versions cannot be removed yet.
There were 0 unused item pointers.
0 pages are entirely empty.
CPU 0.00s/0.00u sec elapsed 0.03 sec.
INFO:  analyzing "public.days"
INFO:  "days": 9 pages, 1893 rows sampled, 1893 estimated total rows
VACUUM

The only thing that PostgreSQL will log generally about this is, if
the query runs for a while, that I requested "vacuum verbose analyze
days;", and that this took 4284ms to run.

It would be really nice if we could have some way of logging the
details, namely of numbers of row versions removed/nonremovable, and
of pages affected.

If we could regularly log that sort of information, that could be very
useful in figuring out some "more nearly optimal" schedule for
vacuuming.

One of our people wrote a Perl script that will take verbose VACUUM
output and essentially parses it so as to be able to generate a bunch
of SQL queries to try to collect how much time was spent, and what
sorts of changes got accomplished.

At present, getting anything out of that mandates that every VACUUM
request have stdout tied to this Perl script, which I'm not overly
keen on, for any number of reasons, notably:

- Any vacuums run separately aren't monitored at all

- Parsing not-forcibly-stable-across-versions file formats with Perl is a fragile thing

- Ideally, this would be nice to get into the PG "engine," somewhere, whether as part of standard logging, or as part
ofhow pg_autovacuum works...
 

Having some ability to collect statistics about "we recovered 42 pages
from table foo at 12:45" would seem useful both from an immediate
temporal perspective where it could suggest whether specific tables
were being vacuumed too (seldom|often), and from a more
global/analytic perspective of perhaps suggesting better kinds of
vacuuming policies.  (In much the same way that I'd like to have some
way of moving towards an analytically better value for
default_statistics_target than 10...)

If people are interested, I could provide a copy of the "analyze
VACUUM stats" script...
-- 
(reverse (concatenate 'string "gro.mca" "@" "enworbbc"))
http://www.ntlug.org/~cbbrowne/sgml.html
"I would rather spend 10 hours reading someone else's source code than
10  minutes listening  to Musak  waiting for  technical  support which
isn't." -- Dr. Greg Wettstein, Roger Maris Cancer Center


Re: Logging pg_autovacuum

From
Bruce Momjian
Date:
Uh, while you are at it, the background writer and checkpoint operations
need similar treatment.  :-)

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

Larry Rosenman wrote:
> Tom Lane wrote:
> > "Larry Rosenman" <lrosenman@pervasive.com> writes:
> >> I'd like to see a more concrete definition of what we
> >> want Autovacuum to output and at what levels.
> > 
> > I would argue that what people typically want is
> > 
> >     (0)    nothing
> > 
> >     (1)    per-database log messages
> > 
> > or
> > 
> >     (2)    per-table log messages (including per-database)
> > 
> > The first problem is that (2) is only available at DEBUG2 or below,
> > which is not good because that also clutters the log with a whole lot
> > of implementer-level debugging info.
> > 
> > The second problem is that we don't really want to use the global
> > log_min_messages setting to determine this, because that constrains
> > your decision about how much chatter you want from ordinary backends.
> > 
> > I suggest that maybe the cleanest solution is to not use log level at
> > all for this, but to invent a separate "autovacuum_verbosity" setting
> > that controls how many messages autovac tries to log, using the above
> > scale.  Anything it does try to log can just come out at LOG message
> > setting.
> 
> This sounds like a winner to me.  Anyone else want to grab it?  I'm 
> in the position to try and do this, but don't want to step on anyone
> else's toes.
> 
> LER
> 
> > 
> >             regards, tom lane
> 
> 
> 
> -- 
> Larry Rosenman
> Database Support Engineer
> 
> PERVASIVE SOFTWARE. INC.
> 12365B RIATA TRACE PKWY
> 3015
> AUSTIN TX  78727-6531
> 
> Tel: 512.231.6173
> Fax: 512.231.6597
> Email: Larry.Rosenman@pervasive.com
> Web: www.pervasive.com
> 

--  Bruce Momjian   http://candle.pha.pa.us EnterpriseDB    http://www.enterprisedb.com
 + If your life is a hard drive, Christ can be your backup. +


Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Bruce Momjian wrote:
> Uh, while you are at it, the background writer and checkpoint
> operations need similar treatment.  :-)
>
Sure.....

I'm willing to look at and work it out, if no one else is currently
working on it.

LER

>
------------------------------------------------------------------------
---
>
>>>

>>
>> This sounds like a winner to me.  Anyone else want to grab it?  I'm
>> in the position to try and do this, but don't want to step on anyone
>> else's toes.
>>
>> LER
--
Larry Rosenman
Database Support Engineer

PERVASIVE SOFTWARE. INC.
12365B RIATA TRACE PKWY
3015
AUSTIN TX  78727-6531

Tel: 512.231.6173
Fax: 512.231.6597
Email: Larry.Rosenman@pervasive.com
Web: www.pervasive.com


Re: Logging pg_autovacuum

From
Tom Lane
Date:
Chris Browne <cbbrowne@acm.org> writes:
> At "level 2," it seems to me that it would be quite useful to have
> some way of getting at the verbose output of VACUUM.

I think you can do that now, if you set min_log_level to INFO.  However,
it might be cleaner if we allowed a "level 3" that made all of autovac's
vacuums be VERBOSE.
        regards, tom lane


Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Tom Lane wrote:
> Chris Browne <cbbrowne@acm.org> writes:
>> At "level 2," it seems to me that it would be quite useful to have
>> some way of getting at the verbose output of VACUUM.
> 
> I think you can do that now, if you set min_log_level to INFO. 
> However, it might be cleaner if we allowed a "level 3" that made all
> of autovac's vacuums be VERBOSE.
> 

I was thinking along those exact lines.  (A 3rd level).

LER

-- 
Larry Rosenman                     http://www.lerctr.org/~ler
Phone: +1 512-248-2683                 E-Mail: ler@lerctr.org
US Mail: 430 Valona Loop, Round Rock, TX 78681-3893



Re: Logging pg_autovacuum

From
Alvaro Herrera
Date:
Larry Rosenman wrote:
> Tom Lane wrote:
> > Chris Browne <cbbrowne@acm.org> writes:
> >> At "level 2," it seems to me that it would be quite useful to have
> >> some way of getting at the verbose output of VACUUM.
> > 
> > I think you can do that now, if you set min_log_level to INFO. 
> > However, it might be cleaner if we allowed a "level 3" that made all
> > of autovac's vacuums be VERBOSE.
> 
> I was thinking along those exact lines.  (A 3rd level).

Also it'd be nice to have it a (4th?) level which would show the results
of the equations being applied.

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


Re: Logging pg_autovacuum

From
Tom Lane
Date:
Alvaro Herrera <alvherre@commandprompt.com> writes:
> Also it'd be nice to have it a (4th?) level which would show the results
> of the equations being applied.

That I think would fall more naturally into the category of debug
support --- I'm happy if we just emit that at DEBUG1 and let people
select it with log_min_messages.
        regards, tom lane


Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Tom Lane wrote:
> Alvaro Herrera <alvherre@commandprompt.com> writes:
>> Also it'd be nice to have it a (4th?) level which would show the
>> results of the equations being applied.
>
> That I think would fall more naturally into the category of debug
> support --- I'm happy if we just emit that at DEBUG1 and let people
> select it with log_min_messages.
>
>             regards, tom lane

I was going to make that same comment, as this seems to be more
implementation
detail, which should be at DEBUGn.

LER

--
Larry Rosenman
Database Support Engineer

PERVASIVE SOFTWARE. INC.
12365B RIATA TRACE PKWY
3015
AUSTIN TX  78727-6531

Tel: 512.231.6173
Fax: 512.231.6597
Email: Larry.Rosenman@pervasive.com
Web: www.pervasive.com


Re: Logging pg_autovacuum

From
Simon Riggs
Date:
On Thu, 2006-04-27 at 14:53 -0400, Tom Lane wrote:
> "Larry Rosenman" <lrosenman@pervasive.com> writes:
> > I'd like to see a more concrete definition of what we 
> > want Autovacuum to output and at what levels. 
> 
> autovacuum_verbosity

Should we call it autovacuum_messages?

In current usage...

_verbosity controls how much information each message gives
_messages controls what types of messages are logged

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



Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Simon Riggs wrote:
> On Thu, 2006-04-27 at 14:53 -0400, Tom Lane wrote:
>> "Larry Rosenman" <lrosenman@pervasive.com> writes:
>>> I'd like to see a more concrete definition of what we
>>> want Autovacuum to output and at what levels.
>>
>> autovacuum_verbosity
>
> Should we call it autovacuum_messages?
>
> In current usage...
>
> _verbosity controls how much information each message gives
> _messages controls what types of messages are logged

That probably works, but I'm not sure about the one to add the VERBOSE
to the
VACUUM commands autovacuum.c emits.



--
Larry Rosenman
Database Support Engineer

PERVASIVE SOFTWARE. INC.
12365B RIATA TRACE PKWY
3015
AUSTIN TX  78727-6531

Tel: 512.231.6173
Fax: 512.231.6597
Email: Larry.Rosenman@pervasive.com
Web: www.pervasive.com


Re: Logging pg_autovacuum

From
Christopher Kings-Lynne
Date:
>> Those messages were at LOG level because otherwise it's difficult to be
>> sure from the log that autovac is running at all.
> 
> OK, so what do we want to do?  Clearly outputing something everytime
> pg_autovacuum touches a database isn't ideal.  By default, the server
> logs should show significant events, which this is not.
> 
> Do we want something output only the first time autovacuum runs?

I've considered several times proposing that I want to be able to turn 
off or do something about autovacuum log messages.  I just always 
thought it would be rejected.

I have it set up so that I get the last few hundred lines of my postgres 
logs mailed to me each day.  However, most of the time I just get a few 
hundred autovacuum messages.  So, I had to much around with grepping out 
the autovacuum lines, etc.

I personally don't see the point of there being soooo many of those 
autovacuum log messages...

Chris



Re: Logging pg_autovacuum

From
Christopher Kings-Lynne
Date:
> I suggest that maybe the cleanest solution is to not use log level at
> all for this, but to invent a separate "autovacuum_verbosity" setting
> that controls how many messages autovac tries to log, using the above
> scale.  Anything it does try to log can just come out at LOG message
> setting.

+1



Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Larry Rosenman wrote:
> Simon Riggs wrote:
>> On Thu, 2006-04-27 at 14:53 -0400, Tom Lane wrote:
>>> "Larry Rosenman" <lrosenman@pervasive.com> writes:
>>>> I'd like to see a more concrete definition of what we
>>>> want Autovacuum to output and at what levels.
>>>
>>> autovacuum_verbosity
>>
>> Should we call it autovacuum_messages?
>>
>> In current usage...
>>
>> _verbosity controls how much information each message gives
>> _messages controls what types of messages are logged
>
> That probably works, but I'm not sure about the one to add the VERBOSE
> to the
> VACUUM commands autovacuum.c emits.

does the following options satisfy everyone:

autovacuum_messages=
none silent (nothing output at LOG level)
database we'd output a LOG message processing database <name>
table    we'd output a LOG message for each table we actually vacuum /
analyze
verbose  we'd add the verbose flag to each command

the lower levels would include the upper (I.E. verbose implies table +
database).

If this is acceptable, I'm going to start working on the code to
implement it.

LER

--
Larry Rosenman
Database Support Engineer

PERVASIVE SOFTWARE. INC.
12365B RIATA TRACE PKWY
3015
AUSTIN TX  78727-6531

Tel: 512.231.6173
Fax: 512.231.6597
Email: Larry.Rosenman@pervasive.com
Web: www.pervasive.com


Re: Logging pg_autovacuum

From
Robert Treat
Date:
On Friday 28 April 2006 12:09, Larry Rosenman wrote:
> Larry Rosenman wrote:
> > Simon Riggs wrote:
> >> On Thu, 2006-04-27 at 14:53 -0400, Tom Lane wrote:
> >>> "Larry Rosenman" <lrosenman@pervasive.com> writes:
> >>>> I'd like to see a more concrete definition of what we
> >>>> want Autovacuum to output and at what levels.
> >>>
> >>> autovacuum_verbosity
> >>
> >> Should we call it autovacuum_messages?
> >>
> >> In current usage...
> >>
> >> _verbosity controls how much information each message gives
> >> _messages controls what types of messages are logged
> >
> > That probably works, but I'm not sure about the one to add the VERBOSE
> > to the
> > VACUUM commands autovacuum.c emits.
>
> does the following options satisfy everyone:
>
> autovacuum_messages=
> none silent (nothing output at LOG level)
> database we'd output a LOG message processing database <name>
> table    we'd output a LOG message for each table we actually vacuum /
> analyze
> verbose  we'd add the verbose flag to each command
>
> the lower levels would include the upper (I.E. verbose implies table +
> database).
>
> If this is acceptable, I'm going to start working on the code to
> implement it.
>

This would certainly be an improvement, but in the intrest of full discussion, 
I want to toss out a couple of ideas (they are only partially thought out, 
but I think could be useful) 

The first is to add a column(s) to pg_class to hold last vaccum/analyze time 
for each table.  The upsides would be that this puts the information in a 
readily accessable place that can be viewed from third party tools and 
queried against for easier management along with accomplishing what the 
current logging is giving you.  

The second is to add a "verbosity level" to pg_autovacuum for each table, to 
allow admins to configure specific tables for a more verbose logging.  This 
way if you have a perticular table that needs additional logging, this could 
allow you to have only its vacuums emmitied at whichever log level seemed 
appropriate. 

-- 
Robert Treat
Build A Brighter Lamp :: Linux Apache {middleware} PostgreSQL


Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Robert Treat wrote:
> On Friday 28 April 2006 12:09, Larry Rosenman wrote:
>> Larry Rosenman wrote:
>>> Simon Riggs wrote:
>>>> On Thu, 2006-04-27 at 14:53 -0400, Tom Lane wrote:
>>>>> "Larry Rosenman" <lrosenman@pervasive.com> writes:
>>>>>> I'd like to see a more concrete definition of what we
>>>>>> want Autovacuum to output and at what levels.
>>>>>
>>>>> autovacuum_verbosity
>>>>
>>>> Should we call it autovacuum_messages?
>>>>
>>>> In current usage...
>>>>
>>>> _verbosity controls how much information each message gives
>>>> _messages controls what types of messages are logged
>>>
>>> That probably works, but I'm not sure about the one to add the
>>> VERBOSE to the VACUUM commands autovacuum.c emits.
>>
>> does the following options satisfy everyone:
>>
>> autovacuum_messages=
>> none silent (nothing output at LOG level)
>> database we'd output a LOG message processing database <name>
>> table    we'd output a LOG message for each table we actually vacuum
>> / analyze verbose  we'd add the verbose flag to each command
>>
>> the lower levels would include the upper (I.E. verbose implies table
>> + database).
>>
>> If this is acceptable, I'm going to start working on the code to
>> implement it.
>>
>
> This would certainly be an improvement, but in the intrest of full
> discussion, I want to toss out a couple of ideas (they are only
> partially thought out, but I think could be useful)
>
> The first is to add a column(s) to pg_class to hold last
> vaccum/analyze time for each table.  The upsides would be that this
> puts the information in a readily accessable place that can be viewed
> from third party tools and queried against for easier management
> along with accomplishing what the current logging is giving you.
I'm not so sure I have the catalog skill fu to do this, but am willing
to
do it, with some hand holding.  breaking pg_class is not my idea of fun
:)


>
> The second is to add a "verbosity level" to pg_autovacuum for each
> table, to allow admins to configure specific tables for a more
> verbose logging.  This way if you have a perticular table that needs
> additional logging, this could allow you to have only its vacuums
> emmitied at whichever log level seemed appropriate.
I was thinking about this as well, but wanted to see if others wanted
it.

LER


--
Larry Rosenman
Database Support Engineer

PERVASIVE SOFTWARE. INC.
12365B RIATA TRACE PKWY
3015
AUSTIN TX  78727-6531

Tel: 512.231.6173
Fax: 512.231.6597
Email: Larry.Rosenman@pervasive.com
Web: www.pervasive.com


Re: Logging pg_autovacuum

From
Martijn van Oosterhout
Date:
On Fri, Apr 28, 2006 at 04:08:41PM -0400, Robert Treat wrote:
> The first is to add a column(s) to pg_class to hold last vaccum/analyze time
> for each table.  The upsides would be that this puts the information in a
> readily accessable place that can be viewed from third party tools and
> queried against for easier management along with accomplishing what the
> current logging is giving you.

You know, rather than adding new columns to pg_class, why not extend
the stats collector to collect this information. This seems to fall
well within its mandate and it already has the necessary infrastructure
to store info like this. The people likely to want this sort of info
are likely to be running the stats collector anyway. The GUC then
becomes.

stats_autovacuum= on

No more fiddling with log levels or parsing log file, just:

select <the info you want> from pg_stats_autovacuum;

If this table is empty, it isn't running. How often do you want to know
if it was running 5 hours ago?

Thoughts?
--
Martijn van Oosterhout   <kleptog@svana.org>   http://svana.org/kleptog/
> From each according to his ability. To each according to his ability to litigate.

Re: Logging pg_autovacuum

From
Tom Lane
Date:
Robert Treat <xzilla@users.sourceforge.net> writes:
> The first is to add a column(s) to pg_class to hold last vaccum/analyze time 
> for each table.

I really don't want us to do that.  relpages/reltuples are already an
ugly wart.  The fundamental problem with this (or indeed any of the
various proposals for "let's make vacuum store results someplace")
is that vacuum is supposed to *clean up* dead rows.  Not make more.
We don't want a pass of autovacuum to leave pg_class in a desperately-
needs-vacuumed-again state.

> The second is to add a "verbosity level" to pg_autovacuum for each table, to 
> allow admins to configure specific tables for a more verbose logging.

No fundamental objection, but I can't really see the need either.
        regards, tom lane


Re: Logging pg_autovacuum

From
Tom Lane
Date:
Martijn van Oosterhout <kleptog@svana.org> writes:
> You know, rather than adding new columns to pg_class, why not extend
> the stats collector to collect this information.

+1
        regards, tom lane


Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Tom Lane wrote:
> Martijn van Oosterhout <kleptog@svana.org> writes:
>> You know, rather than adding new columns to pg_class, why not extend
>> the stats collector to collect this information.
>
> +1
>
>             regards, tom lane

That sounds doable.  And a lot less scary for me (as a relative noobie)
to
do.



--
Larry Rosenman
Database Support Engineer

PERVASIVE SOFTWARE. INC.
12365B RIATA TRACE PKWY
3015
AUSTIN TX  78727-6531

Tel: 512.231.6173
Fax: 512.231.6597
Email: Larry.Rosenman@pervasive.com
Web: www.pervasive.com


Re: Logging pg_autovacuum

From
Martijn van Oosterhout
Date:
On Fri, Apr 28, 2006 at 03:18:56PM -0500, Larry Rosenman wrote:
> > Martijn van Oosterhout <kleptog@svana.org> writes:
> >> You know, rather than adding new columns to pg_class, why not extend
> >> the stats collector to collect this information.
>
> That sounds doable.  And a lot less scary for me (as a relative
> noobie) to do.

Well, I've been thinking a bit more and it seems a perfect fit in many
ways. None of the info we're talking about here takes any extra time to
calculate, it's all debates about what to log. So send it to the stats
collector and let it deal with it.

It should probably tie in with normal vacuum. We get requests from time
to time from people wanting to know the last time a table was vacuumed
(not autovacuumed) for example.

And it's probably a nice little sub-project someone can work on :)

Have a nice day,
--
Martijn van Oosterhout   <kleptog@svana.org>   http://svana.org/kleptog/
> From each according to his ability. To each according to his ability to litigate.

Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Martijn van Oosterhout wrote:
> On Fri, Apr 28, 2006 at 03:18:56PM -0500, Larry Rosenman wrote:
>>> Martijn van Oosterhout <kleptog@svana.org> writes:
>>>> You know, rather than adding new columns to pg_class, why not
>>>> extend the stats collector to collect this information.
>>
>> That sounds doable.  And a lot less scary for me (as a relative
>> noobie) to do.
>
> Well, I've been thinking a bit more and it seems a perfect fit in many
> ways. None of the info we're talking about here takes any extra time
> to calculate, it's all debates about what to log. So send it to the
> stats collector and let it deal with it.
>
> It should probably tie in with normal vacuum. We get requests from
> time to time from people wanting to know the last time a table was
> vacuumed (not autovacuumed) for example.
>
> And it's probably a nice little sub-project someone can work on :)
>
Yeah, I was thinking about seeing about that (tying it into vacuum).

I have the time, and the inclination.  Just want to get all the details
ironed out before I start doing serious code crunching.  I have the
time and Pervasive is ok with me doing it on their dime.

LER

--
Larry Rosenman
Database Support Engineer

PERVASIVE SOFTWARE. INC.
12365B RIATA TRACE PKWY
3015
AUSTIN TX  78727-6531

Tel: 512.231.6173
Fax: 512.231.6597
Email: Larry.Rosenman@pervasive.com
Web: www.pervasive.com


Re: Logging pg_autovacuum

From
Alvaro Herrera
Date:
Martijn van Oosterhout wrote:
> On Fri, Apr 28, 2006 at 03:18:56PM -0500, Larry Rosenman wrote:
> > > Martijn van Oosterhout <kleptog@svana.org> writes:
> > >> You know, rather than adding new columns to pg_class, why not extend
> > >> the stats collector to collect this information.
> > 
> > That sounds doable.  And a lot less scary for me (as a relative
> > noobie) to do.
> 
> Well, I've been thinking a bit more and it seems a perfect fit in many
> ways. None of the info we're talking about here takes any extra time to
> calculate, it's all debates about what to log. So send it to the stats
> collector and let it deal with it.
> 
> It should probably tie in with normal vacuum. We get requests from time
> to time from people wanting to know the last time a table was vacuumed
> (not autovacuumed) for example. 

Yup, currently the stock VACUUM code emits stat messages about what it's
doing, which is right the place where to put this stuff.  (See
pgstat_report_vacuum and pgstat_report_analyze).

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


Re: Logging pg_autovacuum

From
Mark Dilger
Date:
Should we make the whole postgres logging system configurable, similar to log4j
(or log4perl) rather than special-casing the autovacuum logs?  Do we want to see
options added piecemeal to the conf file such as "autovacuum_messages=silent"?

mark


Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Martijn van Oosterhout wrote:
> On Fri, Apr 28, 2006 at 04:08:41PM -0400, Robert Treat wrote:
>> The first is to add a column(s) to pg_class to hold last
>> vaccum/analyze time
>> for each table.  The upsides would be that this puts the information
>> in a readily accessable place that can be viewed from third party
>> tools and
>> queried against for easier management along with accomplishing what
>> the
>> current logging is giving you.
>
> You know, rather than adding new columns to pg_class, why not extend
> the stats collector to collect this information. This seems to fall
> well within its mandate and it already has the necessary
> infrastructure to store info like this. The people likely to want
> this sort of info are likely to be running the stats collector
> anyway. The GUC then becomes.
>
> stats_autovacuum= on
>
> No more fiddling with log levels or parsing log file, just:
>
> select <the info you want> from pg_stats_autovacuum;
>
> If this table is empty, it isn't running. How often do you want to
> know if it was running 5 hours ago?
>
> Thoughts?
[put just to the list, unless folks still want personal CC's.].

Since both vacuum and autovacuum will be cutting stats records, do we
want to just have the autovacuum
stats record have the fact that it was autovacuum that did the vacuum?

Or, is there a way when vacuum is run by autovacuum that I can get a
flag to set that says this
(vacuum|analyze) was done by the autovacuum daemon?

I agree that the existing stats calls are good, but I'm still reading
code to see whether I can determine
at the time they are cut that this was autovacuum that did it.

Thanks for the nice introductory project :)

LER




--
Larry Rosenman
Database Support Engineer

PERVASIVE SOFTWARE. INC.
12365B RIATA TRACE PKWY
3015
AUSTIN TX  78727-6531

Tel: 512.231.6173
Fax: 512.231.6597
Email: Larry.Rosenman@pervasive.com
Web: www.pervasive.com


Re: Logging pg_autovacuum

From
"Jim C. Nasby"
Date:
On Thu, Apr 27, 2006 at 08:12:23PM +0000, Chris Browne wrote:
> Having some ability to collect statistics about "we recovered 42 pages
> from table foo at 12:45" would seem useful both from an immediate
> temporal perspective where it could suggest whether specific tables
> were being vacuumed too (seldom|often), and from a more
> global/analytic perspective of perhaps suggesting better kinds of
> vacuuming policies.  (In much the same way that I'd like to have some
> way of moving towards an analytically better value for
> default_statistics_target than 10...)
> 
> If people are interested, I could provide a copy of the "analyze
> VACUUM stats" script...

Yeah, I'm interested. Though just like EXPLAIN output this seems like
another case where having the ability to log this information into the
database itself would be incredibly valuable for anyone wanting to do
later analysis.
-- 
Jim C. Nasby, Sr. Engineering Consultant      jnasby@pervasive.com
Pervasive Software      http://pervasive.com    work: 512-231-6117
vcard: http://jim.nasby.net/pervasive.vcf       cell: 512-569-9461


Re: Logging pg_autovacuum

From
"Jim C. Nasby"
Date:
On Sat, Apr 29, 2006 at 10:05:51AM -0700, Mark Dilger wrote:
> Should we make the whole postgres logging system configurable, similar to log4j
> (or log4perl) rather than special-casing the autovacuum logs?  Do we want to see
> options added piecemeal to the conf file such as "autovacuum_messages=silent"?

This does sound like a better idea, especially since there's call for
improving bgwriter and stats collector logging as well.
-- 
Jim C. Nasby, Sr. Engineering Consultant      jnasby@pervasive.com
Pervasive Software      http://pervasive.com    work: 512-231-6117
vcard: http://jim.nasby.net/pervasive.vcf       cell: 512-569-9461


Re: Logging pg_autovacuum

From
"Jim C. Nasby"
Date:
On Mon, May 01, 2006 at 12:28:21PM -0500, Larry Rosenman wrote:
> Since both vacuum and autovacuum will be cutting stats records, do we
> want to just have the autovacuum
> stats record have the fact that it was autovacuum that did the vacuum?
> 
> Or, is there a way when vacuum is run by autovacuum that I can get a
> flag to set that says this
> (vacuum|analyze) was done by the autovacuum daemon?
> 
> I agree that the existing stats calls are good, but I'm still reading
> code to see whether I can determine
> at the time they are cut that this was autovacuum that did it.

I think noting autovac vacuums/analyzes seperately is 'nice-to-have' but
not all that important. It'd probably be pretty easy to tell the
difference just knowing what (if any) manual vacuums your system runs.

While we're looking at logging, are you going to add stats stuff for the
bgwriter as well, or should we add this to the TODO?
-- 
Jim C. Nasby, Sr. Engineering Consultant      jnasby@pervasive.com
Pervasive Software      http://pervasive.com    work: 512-231-6117
vcard: http://jim.nasby.net/pervasive.vcf       cell: 512-569-9461


Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Jim C. Nasby wrote:
> On Mon, May 01, 2006 at 12:28:21PM -0500, Larry Rosenman wrote:
>> Since both vacuum and autovacuum will be cutting stats records, do we
>> want to just have the autovacuum
>> stats record have the fact that it was autovacuum that did the
>> vacuum?
>>
>> Or, is there a way when vacuum is run by autovacuum that I can get a
>> flag to set that says this (vacuum|analyze) was done by the
>> autovacuum daemon?
>>
>> I agree that the existing stats calls are good, but I'm still reading
>> code to see whether I can determine
>> at the time they are cut that this was autovacuum that did it.
>
> I think noting autovac vacuums/analyzes seperately is 'nice-to-have'
> but not all that important. It'd probably be pretty easy to tell the
> difference just knowing what (if any) manual vacuums your system runs.
>
> While we're looking at logging, are you going to add stats stuff for
> the bgwriter as well, or should we add this to the TODO?

I was going to do that after I got some comfort with what I'm doing
here.



--
Larry Rosenman
Database Support Engineer

PERVASIVE SOFTWARE. INC.
12365B RIATA TRACE PKWY
3015
AUSTIN TX  78727-6531

Tel: 512.231.6173
Fax: 512.231.6597
Email: Larry.Rosenman@pervasive.com
Web: www.pervasive.com


Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Larry Rosenman wrote:
> Jim C. Nasby wrote:
>> On Mon, May 01, 2006 at 12:28:21PM -0500, Larry Rosenman wrote:
>>> Since both vacuum and autovacuum will be cutting stats records, do
>>> we want to just have the autovacuum
>>> stats record have the fact that it was autovacuum that did the
>>> vacuum?
>>>
>>> Or, is there a way when vacuum is run by autovacuum that I can get a
>>> flag to set that says this (vacuum|analyze) was done by the
>>> autovacuum daemon?
>>>
>>> I agree that the existing stats calls are good, but I'm still
>>> reading code to see whether I can determine
>>> at the time they are cut that this was autovacuum that did it.
>>
>> I think noting autovac vacuums/analyzes seperately is
pg-dev/vacuum-time-patch-WIP.txt'nice-to-have'
>> but not all that important. It'd probably be pretty easy to tell the
>> difference just knowing what (if any) manual vacuums your system
>> runs.
>>
>> While we're looking at logging, are you going to add stats stuff for
>> the bgwriter as well, or should we add this to the TODO?
>
> I was going to do that after I got some comfort with what I'm doing
> here.

I've put a WIP patch up for comments:

http://www.lerctr.org/~ler/pg-dev/vacuum-time-patch-WIP.txt

this is *NOT* for application, as I still need to add access to the new
fields to
the views, etc.

I'm looking to get comments on it.





--
Larry Rosenman                     http://www.lerctr.org/~ler
Phone: +1 512-248-2683                 E-Mail: ler@lerctr.org
US Mail: 430 Valona Loop, Round Rock, TX 78681-3893


Re: Logging pg_autovacuum

From
Simon Riggs
Date:
On Fri, 2006-04-28 at 22:38 +0200, Martijn van Oosterhout wrote:
> On Fri, Apr 28, 2006 at 03:18:56PM -0500, Larry Rosenman wrote:
> > > Martijn van Oosterhout <kleptog@svana.org> writes:
> > >> You know, rather than adding new columns to pg_class, why not extend
> > >> the stats collector to collect this information.
> > 
> > That sounds doable.  And a lot less scary for me (as a relative
> > noobie) to do.
> 
> Well, I've been thinking a bit more and it seems a perfect fit in many
> ways. None of the info we're talking about here takes any extra time to
> calculate, it's all debates about what to log. So send it to the stats
> collector and let it deal with it.
> 
> It should probably tie in with normal vacuum. We get requests from time
> to time from people wanting to know the last time a table was vacuumed
> (not autovacuumed) for example. 

Good idea; Agreed.

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



Re: Logging pg_autovacuum

From
"Larry Rosenman"
Date:
Simon Riggs wrote:
> On Fri, 2006-04-28 at 22:38 +0200, Martijn van Oosterhout wrote:
>> On Fri, Apr 28, 2006 at 03:18:56PM -0500, Larry Rosenman wrote:
>>>> Martijn van Oosterhout <kleptog@svana.org> writes:
>>>>> You know, rather than adding new columns to pg_class, why not
>>>>> extend the stats collector to collect this information.
>>>
>>> That sounds doable.  And a lot less scary for me (as a relative
>>> noobie) to do.
>>
>> Well, I've been thinking a bit more and it seems a perfect fit in
>> many ways. None of the info we're talking about here takes any extra
>> time to calculate, it's all debates about what to log. So send it to
>> the stats collector and let it deal with it.
>>
>> It should probably tie in with normal vacuum. We get requests from
>> time to time from people wanting to know the last time a table was
>> vacuumed (not autovacuumed) for example.
>
> Good idea; Agreed.
I've done this (collecting the data), and actually what I have is BOTH,
last vacuum and last
autovacuum, as well as last analyze and last autovacuum analyze.

Do folks want both, or is just one sufficient.

I posted a WIP patch yesterday that just does the collection and
storage, but not
added the columns to the views.

I'm planning on doing the view stuff and docs today.

Comments/feedback welcome.

LER


--
Larry Rosenman
Database Support Engineer

PERVASIVE SOFTWARE. INC.
12365B RIATA TRACE PKWY
3015
AUSTIN TX  78727-6531

Tel: 512.231.6173
Fax: 512.231.6597
Email: Larry.Rosenman@pervasive.com
Web: www.pervasive.com