SEO

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



---------------------------(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

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



---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings

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

---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster

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/

---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings

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.

---------------------------(end of broadcast)---------------------------
TIP 4: Have you searched our list archives?

http://archives.postgresql.org

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



---------------------------(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

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

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. +

---------------------------(end of broadcast)---------------------------
TIP 3: Have you checked our extensive FAQ?

http://www.postgresql.org/docs/faq

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

---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster

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



---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster