syslog_line_prefix

On Mon, Sep 14, 2009 at 02:43, Itagaki Takahiro
<itagaki.takahiro@oss.ntt.co.jp> wrote:

Here is a patch to add a GUC parameter "syslog_line_prefix".
It adds prefixes to syslog and eventlog. We still have
"log_line_prefix", that will be used only for stderr logs.

We have a tip that log_line_prefix is not required for syslog
in the documentation, but we'd better to have independent setttings
if we set log_destination to 'stderr, syslog'.

http://developer.postgresql.org/pgdocs/postgres/runtime-config-logging.html#RUNTIME-CONFIG-LOGGING-WHAT
| Tip:  Syslog produces its own time stamp and process ID
| information, so you probably do not want to use those escapes
| if you are logging to syslog.

I'm not sure I like this as a GUC. We're going to end up with a lot of
different GUCs, and everytime we add a new log destination (admittedly
not often, of course), that increases even further. And GUCs really
don't provide the level of flexibility you'd really like to have. I've
been thinking (long-term) in the direction of a separate config file,
since that could contain an arbitrary number of lines, with "rules" on
them (somewhat like pg_hba.conf maybe). You'd do the matching on
things like error level and destination, and then specify a bunch of
flags. Or potentially do it on error level and contents, and filtering
which destinations get it.

Forcing it into the guc framework seems like a limiting long-term strategy.

--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/

Magnus Hagander wrote:

I'm not sure I like this as a GUC. We're going to end up with a lot of
different GUCs, and everytime we add a new log destination (admittedly
not often, of course), that increases even further. And GUCs really
don't provide the level of flexibility you'd really like to have. I've
been thinking (long-term) in the direction of a separate config file,
since that could contain an arbitrary number of lines, with "rules" on
them (somewhat like pg_hba.conf maybe).

I tend to agree with this idea, but I'm not sure about rejecting the
current patch because of it.

FWIW one of the things that this "rules of logging config" system should
support is configuring each type of server process differently, for
example set min_log_level to debug2 for autovacuum only, etc.

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

On Tue, Sep 15, 2009 at 2:18 PM, Alvaro Herrera
<alvherre@commandprompt.com> wrote:

Magnus Hagander wrote:

I'm not sure I like this as a GUC. We're going to end up with a lot of
different GUCs, and everytime we add a new log destination (admittedly
not often, of course), that increases even further. And GUCs really
don't provide the level of flexibility you'd really like to have. I've
been thinking (long-term) in the direction of a separate config file,
since that could contain an arbitrary number of lines, with "rules" on
them (somewhat like pg_hba.conf maybe).

I tend to agree with this idea, but I'm not sure about rejecting the
current patch because of it.

I'm picking up this patch to review for this CommitFest. I agree that
the idea of this patch is good. It's pretty silly for us to give
people advice that they should not log time stamps and pids to syslog,
but then provide them no way of actually implementing that behavior
when logging to multiple destinations.

On the other hand, I don't think this is the right way to do it. The
patch proposes the following mapping of logging destinations to GUCs:

stderr -> log_line_prefix (same as now)
csvlog -> not applicable (same as now)
syslog -> syslog_line_prefix
eventlog -> syslog_line_prefix

That's not exactly mnemonic; I think we'd want
{stderr,syslog,eventlog}_log_line_prefix if anything. But that seems
like too many GUCs already - for anyone logging to a single
destination (which I would think by far the most common case), it's
just extra work. So I'm inclined to say that we should reject this
patch for now and see what other ideas come down the pipe.

...Robert

Robert Haas escribi�:

On the other hand, I don't think this is the right way to do it. The
patch proposes the following mapping of logging destinations to GUCs:

stderr -> log_line_prefix (same as now)
csvlog -> not applicable (same as now)
syslog -> syslog_line_prefix
eventlog -> syslog_line_prefix

That's not exactly mnemonic; I think we'd want
{stderr,syslog,eventlog}_log_line_prefix if anything.

So let's have a (ugh) fourth GUC that keeps the current name
log_line_prefix and is the default value for all the other vars.
So today's config would continue to work identically, and people wanting
more configurable behavior could get it by simply setting one or more of
the new vars.

The only problem is what would we do when we implement Magnus' idea.
Are we close to that?

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

On Fri, Sep 25, 2009 at 12:13 PM, Alvaro Herrera
<alvherre@commandprompt.com> wrote:

Robert Haas escribió:

On the other hand, I don't think this is the right way to do it.  The
patch proposes the following mapping of logging destinations to GUCs:

stderr -> log_line_prefix (same as now)
csvlog -> not applicable (same as now)
syslog -> syslog_line_prefix
eventlog -> syslog_line_prefix

That's not exactly mnemonic; I think we'd want
{stderr,syslog,eventlog}_log_line_prefix if anything.

So let's have a (ugh) fourth GUC that keeps the current name
log_line_prefix and is the default value for all the other vars.
So today's config would continue to work identically, and people wanting
more configurable behavior could get it by simply setting one or more of
the new vars.

That might be workable, if there's a reasonable way to make the
default for one GUC depend on the value of another GUC. But it
doesn't make a good idea.

The only problem is what would we do when we implement Magnus' idea.
Are we close to that?

Unless there's some code out there that hasn't been posted, I don't
think so. I don't think we even have a complete design, which would
be a good thing to have in trying to compare this proposal vs. that
one.

...Robert

On Mon, 2009-09-14 at 09:43 +0900, Itagaki Takahiro wrote:

Here is a patch to add a GUC parameter "syslog_line_prefix".
It adds prefixes to syslog and eventlog. We still have
"log_line_prefix", that will be used only for stderr logs.

We have a tip that log_line_prefix is not required for syslog
in the documentation, but we'd better to have independent setttings
if we set log_destination to 'stderr, syslog'.

IMO we should just make log_line_prefix work with syslog/eventlog too.

http://developer.postgresql.org/pgdocs/postgres/runtime-config-logging.html#RUNTIME-CONFIG-LOGGING-WHAT
| Tip: Syslog produces its own time stamp and process ID
| information, so you probably do not want to use those escapes
| if you are logging to syslog.

Regards,
---
ITAGAKI Takahiro
NTT Open Source Software Center

--
PostgreSQL.org Major Contributor
Command Prompt, Inc: http://www.commandprompt.com/ - 503.667.4564
Consulting, Training, Support, Custom Development, Engineering
If the world pushes look it in the eye and GRR. Then push back harder. - Salamander

"Joshua D. Drake" <jd@commandprompt.com> writes:

On Mon, 2009-09-14 at 09:43 +0900, Itagaki Takahiro wrote:

We have a tip that log_line_prefix is not required for syslog
in the documentation, but we'd better to have independent setttings
if we set log_destination to 'stderr, syslog'.

IMO we should just make log_line_prefix work with syslog/eventlog too.

It *does* work with syslog. You missed the point, which is that because
syslog sticks on timestamp and PID information of its own accord, you'd
typically want a different prefix setting for syslog than for stderr.

However, I don't think I actually believe the premise of this patch,
which is that sending log information to both stderr and syslog is
a useful thing to do --- so useful that it's worth greatly complicating
the elog stuff to support it a trifle better. Given the amount of
whining we hear about the overhead of logging, who is going to want
duplicate output? And especially, who is going to want elog.c to do
twice as much work to format the log output differently for the two
destinations?

regards, tom lane

On Fri, Sep 25, 2009 at 21:19, Tom Lane <tgl@sss.pgh.pa.us> wrote:

"Joshua D. Drake" <jd@commandprompt.com> writes:

On Mon, 2009-09-14 at 09:43 +0900, Itagaki Takahiro wrote:

We have a tip that log_line_prefix is not required for syslog
in the documentation, but we'd better to have independent setttings
if we set log_destination to 'stderr, syslog'.

IMO we should just make log_line_prefix work with syslog/eventlog too.

It *does* work with syslog.  You missed the point, which is that because
syslog sticks on timestamp and PID information of its own accord, you'd
typically want a different prefix setting for syslog than for stderr.

However, I don't think I actually believe the premise of this patch,
which is that sending log information to both stderr and syslog is
a useful thing to do --- so useful that it's worth greatly complicating
the elog stuff to support it a trifle better.  Given the amount of
whining we hear about the overhead of logging, who is going to want
duplicate output?  And especially, who is going to want elog.c to do
twice as much work to format the log output differently for the two
destinations?

I am :-)

I definitely want both text and CSV output - which I can't have today.
I would even more like to have some things send to CSV and some things
sent to text.

Other than if you're logging all your queries (or over <n> time, where
<n> is very small), I've never seen a system with performance issues
from logging. I'm sure others may have, but not me.

Is there really any log output other than the
query-logging-for-performance-analysis that is likely to cause any
real load on the system? If not, perhaps we need to break out that
part to a separate codepath instead, and optimize that one for speed,
while optimizing the other paths for flexibility?

--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/

Magnus Hagander wrote:

I definitely want both text and CSV output - which I can't have today.

Sure you can. What makes you think you can't?

cheers

andrew

On Fri, Sep 25, 2009 at 4:06 PM, Magnus Hagander <magnus@hagander.net> wrote:

On Fri, Sep 25, 2009 at 21:19, Tom Lane <tgl@sss.pgh.pa.us> wrote:

"Joshua D. Drake" <jd@commandprompt.com> writes:

On Mon, 2009-09-14 at 09:43 +0900, Itagaki Takahiro wrote:

We have a tip that log_line_prefix is not required for syslog
in the documentation, but we'd better to have independent setttings
if we set log_destination to 'stderr, syslog'.

IMO we should just make log_line_prefix work with syslog/eventlog too.

It *does* work with syslog.  You missed the point, which is that because
syslog sticks on timestamp and PID information of its own accord, you'd
typically want a different prefix setting for syslog than for stderr.

However, I don't think I actually believe the premise of this patch,
which is that sending log information to both stderr and syslog is
a useful thing to do --- so useful that it's worth greatly complicating
the elog stuff to support it a trifle better.  Given the amount of
whining we hear about the overhead of logging, who is going to want
duplicate output?  And especially, who is going to want elog.c to do
twice as much work to format the log output differently for the two
destinations?

I am :-)

I definitely want both text and CSV output - which I can't have today.

Huh? I thought I had that exact configuration working yesterday.

I would even more like to have some things send to CSV and some things
sent to text.

This patch won't help, then.

Other than if you're logging all your queries (or over <n> time, where
<n> is very small), I've never seen a system with performance issues
from logging. I'm sure others may have, but not me.

Is there really any log output other than the
query-logging-for-performance-analysis that is likely to cause any
real load on the system? If not, perhaps we need to break out that
part to a separate codepath instead, and optimize that one for speed,
while optimizing the other paths for flexibility?

Not sure, but I doubt it's that easy.

...Robert

On Fri, Sep 25, 2009 at 22:17, Andrew Dunstan <andrew@dunslane.net> wrote:

Magnus Hagander wrote:

I definitely want both text and CSV output - which I can't have today.

Sure you can. What makes you think you can't?

How do i do that? When I enable csv logging, it changes the log format
to csv, and my plaintext logs don't end up in the logs anymore.

Note that I'm not talking about syslog, I'm talking about the logging
that goes through the logging collector, and is dealt with by
PostgreSQL.

--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/

On Fri, Sep 25, 2009 at 22:18, Robert Haas <robertmhaas@gmail.com> wrote:

On Fri, Sep 25, 2009 at 4:06 PM, Magnus Hagander <magnus@hagander.net> wrote:

Other than if you're logging all your queries (or over <n> time, where
<n> is very small), I've never seen a system with performance issues
from logging. I'm sure others may have, but not me.

Is there really any log output other than the
query-logging-for-performance-analysis that is likely to cause any
real load on the system? If not, perhaps we need to break out that
part to a separate codepath instead, and optimize that one for speed,
while optimizing the other paths for flexibility?

Not sure, but I doubt it's that easy.

If we are talking about the "log query duration" or "log queries
longer than <n>" that's a single location in the code. It can't be
that hard...

--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/

Magnus Hagander wrote:

On Fri, Sep 25, 2009 at 22:17, Andrew Dunstan <andrew@dunslane.net> wrote:

Magnus Hagander wrote:

I definitely want both text and CSV output - which I can't have today.

Sure you can. What makes you think you can't?

How do i do that? When I enable csv logging, it changes the log format
to csv, and my plaintext logs don't end up in the logs anymore.

Note that I'm not talking about syslog, I'm talking about the logging
that goes through the logging collector, and is dealt with by
PostgreSQL.

log_destination = 'stderr, csvlog'

IIRC

cheers

andrew

On Fri, Sep 25, 2009 at 03:19:36PM -0400, Tom Lane wrote:

However, I don't think I actually believe the premise of this patch,
which is that sending log information to both stderr and syslog is
a useful thing to do

Actually the thing I want is to be able to send some stuff to syslog, and some
to a file, and other stuff to another file. This patch doesn't do all that,
but lays the necessary groundwork.

For instance, the various applications that parse query output all require
specific log line formats and various other configurations to be able to
understand our logs, and even then still have problems dealing with multi-line
entries. This is a pain. Such applications should be able to have their own
machine-readable logs, like csvlog. Unfortunately csvlogs are almost entirely
unreadable by humans, so I'd also like to have a human readable log somewhere.
These two logs need not necessarily contain the same information.

Loads of people seem to want to be able to have separate per-database log
files, which something like this could also allow.

--
Joshua Tolley / eggyknap
End Point Corporation
http://www.endpoint.com

On Fri, Sep 25, 2009 at 22:57, Andrew Dunstan <andrew@dunslane.net> wrote:

Magnus Hagander wrote:

On Fri, Sep 25, 2009 at 22:17, Andrew Dunstan <andrew@dunslane.net> wrote:

Magnus Hagander wrote:

I definitely want both text and CSV output - which I can't have today.

Sure you can. What makes you think you can't?

How do i do that? When I enable csv logging, it changes the log format
to csv, and my plaintext logs don't end up in the logs anymore.

Note that I'm not talking about syslog, I'm talking about the logging
that goes through the logging collector, and is dealt with by
PostgreSQL.

log_destination = 'stderr, csvlog'

Clearly that works. I wonder why that didn't work when I last tried it :S

/me wipes the egg off.

(it's still weird that it's called stderr when it's a logfile, but
that's a different story)

Without looking deeply at the code, does it also properly route these
famous "messages from third party libraries" to both files?

--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/

On Fri, Sep 25, 2009 at 4:33 PM, Magnus Hagander <magnus@hagander.net> wrote:

On Fri, Sep 25, 2009 at 22:18, Robert Haas <robertmhaas@gmail.com> wrote:

On Fri, Sep 25, 2009 at 4:06 PM, Magnus Hagander <magnus@hagander.net> wrote:

Other than if you're logging all your queries (or over <n> time, where
<n> is very small), I've never seen a system with performance issues
from logging. I'm sure others may have, but not me.

Is there really any log output other than the
query-logging-for-performance-analysis that is likely to cause any
real load on the system? If not, perhaps we need to break out that
part to a separate codepath instead, and optimize that one for speed,
while optimizing the other paths for flexibility?

Not sure, but I doubt it's that easy.

If we are talking about the "log query duration" or "log queries
longer than <n>" that's a single location in the code. It can't be
that hard...

I'm not sure that's really the only thing that can cause a logging
bottleneck. I would be kinda surprised.

...Robert

On Fri, Sep 25, 2009 at 4:58 PM, Joshua Tolley <eggyknap@gmail.com> wrote:

On Fri, Sep 25, 2009 at 03:19:36PM -0400, Tom Lane wrote:

However, I don't think I actually believe the premise of this patch,
which is that sending log information to both stderr and syslog is
a useful thing to do

Actually the thing I want is to be able to send some stuff to syslog, and some
to a file, and other stuff to another file. This patch doesn't do all that,
but lays the necessary groundwork.

I don't think it does anything of the sort. Getting to that point by
adding GUCs is quickly going to produce obviously unacceptable numbers
of GUCs. Or if it isn't, then I'd like to hear the whole designed
laid out. I think Magnus's idea of a separate config file is much
more likely to be succesful than what we have here, but that too will
require some design that hasn't been done yet.

...Robert

On Fri, Sep 25, 2009 at 04:18:08PM -0400, Robert Haas wrote:

I would even more like to have some things send to CSV and some things
sent to text.

This patch won't help, then.

No, it won't, but as said before, it lays the groundwork, namely letting the
syslogger know things about the log messages it gets (rather than just having
an opaque string), and route messages various places, accordingly.

--
Joshua Tolley / eggyknap
End Point Corporation
http://www.endpoint.com

On Fri, Sep 25, 2009 at 5:01 PM, Magnus Hagander <magnus@hagander.net> wrote:

On Fri, Sep 25, 2009 at 22:57, Andrew Dunstan <andrew@dunslane.net> wrote:

Magnus Hagander wrote:

On Fri, Sep 25, 2009 at 22:17, Andrew Dunstan <andrew@dunslane.net> wrote:

Magnus Hagander wrote:

I definitely want both text and CSV output - which I can't have today.

Sure you can. What makes you think you can't?

How do i do that? When I enable csv logging, it changes the log format
to csv, and my plaintext logs don't end up in the logs anymore.

Note that I'm not talking about syslog, I'm talking about the logging
that goes through the logging collector, and is dealt with by
PostgreSQL.

log_destination = 'stderr, csvlog'

Clearly that works. I wonder why that didn't work when I last tried it :S

/me wipes the egg off.

(it's still weird that it's called stderr when it's a logfile, but
that's a different story)

Without looking deeply at the code, does it also properly route these
famous "messages from third party libraries" to both files?

Rather than looking at the code, I'd suggest testing it. But I bet it
does. The whole point of redirecting stderr specifically (rather than
logging to some other random fd we keep around) is to catch those
random messages, and it would be pretty silly to catch them and then
not bother processing them properly.

For whatever it's worth, I think your (as perceived by me) scorn
regarding this issue is off base. I have this problem all the time,
and not just in C, but also in Perl, shell scripts, etc. I can't tell
you how many times I've tried to write code to ensure that ALL error
messages get logged to some database, file, sent as an email message,
etc. and inevitably something happens that my clever plan fails to
catch, and the darn thing fails without alerting me. You have to have
a collector process to make failure detection robust, and it has to
capture stderr. Period, full stop.

...Robert