Re: Set log_line_prefix and application name in test drivers

Here is a small patch that sets log_line_prefix and application name in
pg_regress and the TAP tests, to make analyzing the server log output
easier.

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Peter Eisentraut <peter(dot)eisentraut(at)2ndquadrant(dot)com> writes:
> Here is a small patch that sets log_line_prefix and application name in
> pg_regress and the TAP tests, to make analyzing the server log output
> easier.

How would this interact with the buildfarm's existing policies
on setting log_line_prefix?

regards, tom lane

On 8/9/16 12:16 PM, Tom Lane wrote:
> Peter Eisentraut <peter(dot)eisentraut(at)2ndquadrant(dot)com> writes:
>> > Here is a small patch that sets log_line_prefix and application name in
>> > pg_regress and the TAP tests, to make analyzing the server log output
>> > easier.
> How would this interact with the buildfarm's existing policies
> on setting log_line_prefix?

AFAICT, that only applies if the build farm client runs initdb itself,
that is, for the installcheck parts.

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Peter Eisentraut <peter(dot)eisentraut(at)2ndquadrant(dot)com> writes:
> On 8/9/16 12:16 PM, Tom Lane wrote:
>> Peter Eisentraut <peter(dot)eisentraut(at)2ndquadrant(dot)com> writes:
>>> Here is a small patch that sets log_line_prefix and application name in
>>> pg_regress and the TAP tests, to make analyzing the server log output
>>> easier.

>> How would this interact with the buildfarm's existing policies
>> on setting log_line_prefix?

> AFAICT, that only applies if the build farm client runs initdb itself,
> that is, for the installcheck parts.

Well, I guess the subtext of my question was whether we shouldn't try
to align this with the buildfarm's choices, or vice versa. Andrew made
some different choices than you have done here, and it seems like we
ought to strive for a meeting of the minds on what's appropriate.

Or in short: I don't want to be seeing one prefix format in some buildfarm
logs and a different format in others.

regards, tom lane

On 8/10/16 5:18 PM, Tom Lane wrote:
> Or in short: I don't want to be seeing one prefix format in some buildfarm
> logs and a different format in others.

Sure. My patch has

log_line_prefix = '%t [%p]: [%l] %qapp=%a '

which is modeled after the pgfouine recommendation, which is I believe a
wide-spread convention, and it also vaguely follows syslog customs.

The build farm client has

log_line_prefix = '%m [%c:%l] '

which is very similar, but the lack of the PID makes it unsuitable for
the purposes that I have set out, and there is no obvious place to put
additional information such as %a.

%m vs %t is obviously a minor issue that I will gladly adjust, but
besides that I prefer to stick with my version.

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On 8/10/16 9:36 PM, Peter Eisentraut wrote:
> %m vs %t is obviously a minor issue that I will gladly adjust, but
> besides that I prefer to stick with my version.

Updated patch with %m instead of %t. Will submit to CF.

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On 8/16/16 2:23 PM, Peter Eisentraut wrote:
> On 8/10/16 9:36 PM, Peter Eisentraut wrote:
>> %m vs %t is obviously a minor issue that I will gladly adjust, but
>> besides that I prefer to stick with my version.
>
> Updated patch with %m instead of %t. Will submit to CF.

attached

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Hello Peter,

> log_line_prefix = '%t [%p]: [%l] %qapp=%a '
>
> which is modeled after the pgfouine recommendation, which is I believe a
> wide-spread convention, and it also vaguely follows syslog customs.
>
> The build farm client has
>
> log_line_prefix = '%m [%c:%l] '
>
> which is very similar, but the lack of the PID makes it unsuitable for
> the purposes that I have set out, and there is no obvious place to put
> additional information such as %a.
>
> %m vs %t is obviously a minor issue that I will gladly adjust, but
> besides that I prefer to stick with my version.

v2 patch looks ok, applies without trouble and works as intended:

2016-08-26 09:19:31.191 CEST [7571]: [58] app=pg_regress/event_trigger STATEMENT: alter type rewritetype alter attribute a type varchar cascade;

About the format: '[\d+]' pattern is used twice, which makes the output
less easily grep-able.

Also, the ':' is used as a separator in the remainder of the message, so
maybe once is enough at this level.

I'm not sure about the "app=" is really necessary, given its very explicit
definition as can be seen above above.

So I would suggest something like the following, which is also a little
bit more compact:

log_line_prefix = '%m [%p:%l] %q%a '

If you want to keep something with %a, maybe parentheses?

Finally I'm wondering also whether a timestamp since the server has
started (which does not exists) would be more useful for a "make check",
or at default maybe %n?

--
Fabien

Re: Fabien COELHO 2016-08-26 <alpine(dot)DEB(dot)2(dot)20(dot)1608261620260(dot)7102(at)lancre>
> So I would suggest something like the following, which is also a little bit
> more compact:
>
> log_line_prefix = '%m [%p:%l] %q%a '
>
> If you want to keep something with %a, maybe parentheses?
>
> Finally I'm wondering also whether a timestamp since the server has started
> (which does not exists) would be more useful for a "make check", or at
> default maybe %n?

I've always been wondering why we don't set a log_line_prefix by
default. Logs without timestamps and (pid or session id or equivalent)
are useless. Of course in practise the log_line_prefix needs to be
different depending on the log_destination (syslog adds its own
timestamps, ...), but the current default of '' doesn't help anyone.

The above looks quite similar to what the Debian packages have been
setting as their default for some time, with standard stderr logging:

log_line_prefix = '%t [%p-%l] %q%u(at)%d '

People who want a different log channel need to touch the config
anyway and can update log_line_prefix as they go.

The concrete value to be used needs to be discussed, but I think we'd
end up with something like '%m [%p:%l] ' plus maybe some suffix.

Christoph

Christoph Berg <myon(at)debian(dot)org> writes:
> I've always been wondering why we don't set a log_line_prefix by
> default.

I think the odds of getting to something that everyone would agree on
are nil, so I'm not excited about getting into that particular
bikeshed-painting discussion. Look at the amount of trouble we're
having converging on a default for the regression tests, which are
a far narrower use-case than "everybody".

> The above looks quite similar to what the Debian packages have been
> setting as their default for some time, with standard stderr logging:

I think Debian's choice was probably made by fiat, not by consensus.
Packagers seem to be able to get away with quite a lot in that regard.

regards, tom lane

On Sat, Aug 27, 2016 at 3:59 PM, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:
> Christoph Berg <myon(at)debian(dot)org> writes:
>> I've always been wondering why we don't set a log_line_prefix by
>> default.
>
> I think the odds of getting to something that everyone would agree on
> are nil, so I'm not excited about getting into that particular
> bikeshed-painting discussion. Look at the amount of trouble we're
> having converging on a default for the regression tests, which are
> a far narrower use-case than "everybody".

Well, practically anything that includes a PID and the timestamp is
going to be an improvement over the status quo. Just because we can't
all agree on what would be perfect does not mean that we can't do
better than what we've got now. +1 for trying.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

On Thu, Sep 15, 2016 at 5:18 PM, Robert Haas <robertmhaas(at)gmail(dot)com> wrote:
> On Sat, Aug 27, 2016 at 3:59 PM, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:
>> Christoph Berg <myon(at)debian(dot)org> writes:
>>> I've always been wondering why we don't set a log_line_prefix by
>>> default.
>>
>> I think the odds of getting to something that everyone would agree on
>> are nil, so I'm not excited about getting into that particular
>> bikeshed-painting discussion. Look at the amount of trouble we're
>> having converging on a default for the regression tests, which are
>> a far narrower use-case than "everybody".
>
> Well, practically anything that includes a PID and the timestamp is
> going to be an improvement over the status quo. Just because we can't
> all agree on what would be perfect does not mean that we can't do
> better than what we've got now. +1 for trying.

Is there any chance we can move forward here, or is this effort doomed for now?

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Re: Robert Haas 2016-09-28 <CA+TgmobB-igLrjfH+zfmpY00ysAseCBxcRukjyhdneamyebfYA(at)mail(dot)gmail(dot)com>
> > Well, practically anything that includes a PID and the timestamp is
> > going to be an improvement over the status quo. Just because we can't
> > all agree on what would be perfect does not mean that we can't do
> > better than what we've got now. +1 for trying.
>
> Is there any chance we can move forward here, or is this effort doomed for now?

IMHO it would make sense. Maybe we should collect a few suggestions,
and then take a poll?

Christoph

Robert Haas <robertmhaas(at)gmail(dot)com> writes:
> On Thu, Sep 15, 2016 at 5:18 PM, Robert Haas <robertmhaas(at)gmail(dot)com> wrote:
>> On Sat, Aug 27, 2016 at 3:59 PM, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:
>>> I think the odds of getting to something that everyone would agree on
>>> are nil, so I'm not excited about getting into that particular
>>> bikeshed-painting discussion. Look at the amount of trouble we're
>>> having converging on a default for the regression tests, which are
>>> a far narrower use-case than "everybody".

>> Well, practically anything that includes a PID and the timestamp is
>> going to be an improvement over the status quo. Just because we can't
>> all agree on what would be perfect does not mean that we can't do
>> better than what we've got now. +1 for trying.

> Is there any chance we can move forward here, or is this effort doomed for now?

It seemed like nobody wanted to try to push this forward, and it will take
somebody actively pushing, IMO, for something to happen.

Perhaps we should first try to get a consensus on the regression test
use-case.

regards, tom lane

Tom Lane wrote:
> Robert Haas <robertmhaas(at)gmail(dot)com> writes:
> > On Thu, Sep 15, 2016 at 5:18 PM, Robert Haas <robertmhaas(at)gmail(dot)com> wrote:
> >> On Sat, Aug 27, 2016 at 3:59 PM, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:
> >>> I think the odds of getting to something that everyone would agree on
> >>> are nil, so I'm not excited about getting into that particular
> >>> bikeshed-painting discussion. Look at the amount of trouble we're
> >>> having converging on a default for the regression tests, which are
> >>> a far narrower use-case than "everybody".
>
> >> Well, practically anything that includes a PID and the timestamp is
> >> going to be an improvement over the status quo. Just because we can't
> >> all agree on what would be perfect does not mean that we can't do
> >> better than what we've got now. +1 for trying.
>
> > Is there any chance we can move forward here, or is this effort doomed for now?
>
> It seemed like nobody wanted to try to push this forward, and it will take
> somebody actively pushing, IMO, for something to happen.
>
> Perhaps we should first try to get a consensus on the regression test
> use-case.

I thought Peter's suggestion for regression test drivers was a good one
and I see no reason to block that. Why do you (Tom) object so strongly
against having a different one on buildfarm than elsewhere? I'd rather
have buildfarm adopt the new suggestion than having buildfarm drive the
new stuff.

Adopting a default prefix is a different question. For one thing IMHO
it should not have %a (application name). Christoph's suggestion
(Debian's default) seemed good.

--
Álvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On Wed, Sep 28, 2016 at 6:07 PM, Alvaro Herrera
<alvherre(at)2ndquadrant(dot)com> wrote:
> I thought Peter's suggestion for regression test drivers was a good one
> and I see no reason to block that. Why do you (Tom) object so strongly
> against having a different one on buildfarm than elsewhere? I'd rather
> have buildfarm adopt the new suggestion than having buildfarm drive the
> new stuff.
>
> Adopting a default prefix is a different question. For one thing IMHO
> it should not have %a (application name). Christoph's suggestion
> (Debian's default) seemed good.

Yeah, I like Cristoph's suggestion fine. It meets my criteria of
"includes timestamp and PID" and overall seems reasonable. If we
adopted that across the board, it wouldn't be too much different from
what Peter proposed for the regression test. Just to compare.

Christoph/Debian:
log_line_prefix = '%t [%p-%l] %q%u(at)%d '
Peter:
log_line_prefix = '%t [%p]: [%l] %qapp=%a '

So Peter's got %p and %l separated by "]: [" whereas Christoph has
them separated only by a dash. Presumably that's minor. Then they've
both got %q. After that, Christoph has %u(at)%d, which seems reasonable
for an actual system, and Peter's got app=%a, which is better for the
regression tests because the user name will depend on the UNIX
username of the person running the tests.

So how about we adopt both suggestions, except changing Peter's to '%t
[%p-%l] %qapp=%a ' so that they are a bit more similar? I bet that
would make more people happier than it would make less happy.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Alvaro Herrera <alvherre(at)2ndquadrant(dot)com> writes:
> Tom Lane wrote:
>> Perhaps we should first try to get a consensus on the regression test
>> use-case.

> I thought Peter's suggestion for regression test drivers was a good one
> and I see no reason to block that. Why do you (Tom) object so strongly
> against having a different one on buildfarm than elsewhere? I'd rather
> have buildfarm adopt the new suggestion than having buildfarm drive the
> new stuff.

Well, my point is only that if you can't convince Andrew to sync the
buildfarm's choices with whatever your proposal is, then you haven't
got consensus.

regards, tom lane

On 9/28/16 6:07 PM, Alvaro Herrera wrote:
> Adopting a default prefix is a different question.

A default prefix would require different settings for syslog, plain
text, and possibly some of the other variants. I'm all in favor of
figuring that out, but it needs more work.

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On 9/28/16 6:13 PM, Robert Haas wrote:
> Christoph/Debian:
> log_line_prefix = '%t [%p-%l] %q%u(at)%d '
> Peter:
> log_line_prefix = '%t [%p]: [%l] %qapp=%a '

I'm aware of two existing guidelines on log line formats: syslog and
pgbadger. Syslog output looks like this:

Sep 28 00:58:56 hostname syslogd[46]: some text here

pgbadger by default asks for this:

log_line_prefix = '%t [%p]: [%l-1] user=%u,db=%d,app=%a,client=%h '

I don't know why it wants that "-1" there, and I'm actually not sure
what the point of %l is in practice. Those are separate issues that are
having their own lively discussions at times. I could drop the [%l]
from my proposal if that causes concerns.

On balance, I think my proposal is more in line with existing
wide-spread conventions.

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Peter Eisentraut <peter(dot)eisentraut(at)2ndquadrant(dot)com> writes:
> On 9/28/16 6:13 PM, Robert Haas wrote:
>> Christoph/Debian:
>> log_line_prefix = '%t [%p-%l] %q%u(at)%d '
>> Peter:
>> log_line_prefix = '%t [%p]: [%l] %qapp=%a '

> ...
> I don't know why it wants that "-1" there, and I'm actually not sure
> what the point of %l is in practice. Those are separate issues that are
> having their own lively discussions at times. I could drop the [%l]
> from my proposal if that causes concerns.

+1 for dropping %l --- seems to me that its main result is to add useless
bytes to the log. Surely if you need to match up lines from the same
process, that's not that hard as long as %p is in there.

I'd also vote for dropping "app=" out of the regression test version;
again, that seems like basically dead weight.

regards, tom lane

On Wed, Sep 28, 2016 at 10:30 PM, Peter Eisentraut
<peter(dot)eisentraut(at)2ndquadrant(dot)com> wrote:
> On 9/28/16 6:13 PM, Robert Haas wrote:
>> Christoph/Debian:
>> log_line_prefix = '%t [%p-%l] %q%u(at)%d '
>> Peter:
>> log_line_prefix = '%t [%p]: [%l] %qapp=%a '
>
> I'm aware of two existing guidelines on log line formats: syslog and
> pgbadger. Syslog output looks like this:
>
> Sep 28 00:58:56 hostname syslogd[46]: some text here
>
> pgbadger by default asks for this:
>
> log_line_prefix = '%t [%p]: [%l-1] user=%u,db=%d,app=%a,client=%h '
>
> I don't know why it wants that "-1" there, and I'm actually not sure
> what the point of %l is in practice. Those are separate issues that are
> having their own lively discussions at times. I could drop the [%l]
> from my proposal if that causes concerns.
>
> On balance, I think my proposal is more in line with existing
> wide-spread conventions.

As long as we get %t and %p in there we're going to be way ahead, really.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Robert Haas <robertmhaas(at)gmail(dot)com> writes:
> As long as we get %t and %p in there we're going to be way ahead, really.

Could we get consensus on just changing the default to

log_line_prefix = '%t [%p] '

and leaving the rest out of it? I think pretty much everybody agrees
that those fields are useful, whereas the rest of it is a lot more
context-dependent. (For example, there are a whole lot of real
installations where neither %u nor %d would be worth the log space.)

Personally I'm also on board with using this for regression testing:

log_line_prefix = '%t [%p] %q%a '

but I doubt it can be sold as a general-purpose default.

regards, tom lane

Re: Peter Eisentraut 2016-09-29 <21d2719f-36ff-06d2-5856-25ed48b965c5(at)2ndquadrant(dot)com>
> > Christoph/Debian:
> > log_line_prefix = '%t [%p-%l] %q%u(at)%d '
> > Peter:
> > log_line_prefix = '%t [%p]: [%l] %qapp=%a '
>
> I'm aware of two existing guidelines on log line formats: syslog and
> pgbadger. Syslog output looks like this:
>
> Sep 28 00:58:56 hostname syslogd[46]: some text here
>
> pgbadger by default asks for this:
>
> log_line_prefix = '%t [%p]: [%l-1] user=%u,db=%d,app=%a,client=%h '
>
> I don't know why it wants that "-1" there, and I'm actually not sure
> what the point of %l is in practice. Those are separate issues that are
> having their own lively discussions at times. I could drop the [%l]
> from my proposal if that causes concerns.

[%l-1] is originally from pgfouine, and I vaguely remember that it
used to be something like [%l-%c] where %c was some extra line
numbering removed in later (7.something?) PG versions. In any case,
the -1 isn't useful.

I'm happy to remove %l as well. Log lines won't be out of order
anyway, and one needs to look at %p anyway to correlate them. %l
doesn't help there.

Christoph

Re: Tom Lane 2016-09-29 <16946(dot)1475157978(at)sss(dot)pgh(dot)pa(dot)us>
> Robert Haas <robertmhaas(at)gmail(dot)com> writes:
> > As long as we get %t and %p in there we're going to be way ahead, really.
>
> Could we get consensus on just changing the default to
>
> log_line_prefix = '%t [%p] '
>
> and leaving the rest out of it? I think pretty much everybody agrees
> that those fields are useful, whereas the rest of it is a lot more
> context-dependent. (For example, there are a whole lot of real
> installations where neither %u nor %d would be worth the log space.)

Nod. In many installations %u and %d will be effectively constants.

> Personally I'm also on board with using this for regression testing:
>
> log_line_prefix = '%t [%p] %q%a '
>
> but I doubt it can be sold as a general-purpose default.

I don't think it makes much sense to log only %a unconditionally,
except maybe for making more applications actually set it.

If we were to add more fields I'd go for

log_line_prefix = '%t [%p] %q%u(at)%d/%a '

but the above-proposed '%t [%p] ' is already fixing 95% of the problem
(and the remaining 5% are unclear).

Possibly the longer version could be added as an example in the
documentation.

So, in short, +1.

Christoph

Christoph Berg <myon(at)debian(dot)org> writes:
> Re: Tom Lane 2016-09-29 <16946(dot)1475157978(at)sss(dot)pgh(dot)pa(dot)us>
>> Personally I'm also on board with using this for regression testing:
>> log_line_prefix = '%t [%p] %q%a '
>> but I doubt it can be sold as a general-purpose default.

> I don't think it makes much sense to log only %a unconditionally,

Right; this is helpful for the regression tests, now that Peter has set
up pg_regress to set the application name, but I can't see trying to
push it on the rest of the world.

> Possibly the longer version could be added as an example in the
> documentation.

I suspect that simply having a nonempty default in the first place
is going to do more to raise peoples' awareness than anything we
could do in the documentation. But perhaps an example along these
lines would be useful for showing proper use of %q.

regards, tom lane

Tom Lane wrote:
> Robert Haas <robertmhaas(at)gmail(dot)com> writes:
> > As long as we get %t and %p in there we're going to be way ahead, really.
>
> Could we get consensus on just changing the default to
>
> log_line_prefix = '%t [%p] '
>
> and leaving the rest out of it?

+1 from me.

--
Álvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On 9/29/16 10:06 AM, Tom Lane wrote:
> Personally I'm also on board with using this for regression testing:
>
> log_line_prefix = '%t [%p] %q%a '

Committed that way, but with %m instead of %t, as discussed earlier.

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Re: Tom Lane 2016-09-29 <18642(dot)1475159736(at)sss(dot)pgh(dot)pa(dot)us>
> > Possibly the longer version could be added as an example in the
> > documentation.
>
> I suspect that simply having a nonempty default in the first place
> is going to do more to raise peoples' awareness than anything we
> could do in the documentation. But perhaps an example along these
> lines would be useful for showing proper use of %q.

Patch attached. (Still using %t, I don't think %m makes sense for the
default.)

Christoph

On 10/2/16 4:20 PM, Christoph Berg wrote:
>> I suspect that simply having a nonempty default in the first place
>> > is going to do more to raise peoples' awareness than anything we
>> > could do in the documentation. But perhaps an example along these
>> > lines would be useful for showing proper use of %q.
> Patch attached. (Still using %t, I don't think %m makes sense for the
> default.)

That still doesn't address what to do about syslog and eventlog users.
We would need either a separate prefix setting for those, or maybe
something like %q that says, skip to here if using syslog. (I don't
know eventlog, so I don't know if a common setting for syslog and
eventlog would work.)

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Peter Eisentraut <peter(dot)eisentraut(at)2ndquadrant(dot)com> writes:
> That still doesn't address what to do about syslog and eventlog users.
> We would need either a separate prefix setting for those, or maybe
> something like %q that says, skip to here if using syslog. (I don't
> know eventlog, so I don't know if a common setting for syslog and
> eventlog would work.)

Meh. Those aren't default log output targets, so I don't think the
default prefix needs to cater for them. People who adjust one setting
can adjust the other too.

There would be some value in the complexity you're thinking of for
installations that log to multiple targets concurrently, but really,
who does that? Most production installations already begrudge
the I/O volume for a single log target.

regards, tom lane

Re: Peter Eisentraut 2016-10-12 <0caa6d7f-deb6-9a43-2b38-60e63af93183(at)2ndquadrant(dot)com>
> >> > is going to do more to raise peoples' awareness than anything we
> >> > could do in the documentation. But perhaps an example along these
> >> > lines would be useful for showing proper use of %q.
> > Patch attached. (Still using %t, I don't think %m makes sense for the
> > default.)
>
> That still doesn't address what to do about syslog and eventlog users.
> We would need either a separate prefix setting for those, or maybe
> something like %q that says, skip to here if using syslog. (I don't
> know eventlog, so I don't know if a common setting for syslog and
> eventlog would work.)

This patch simply tries to fix the default (stderr + '') which wasn't
useful for anyone. Note that there is already a hint in the
documentation that says timestamps and PID are not useful for syslog.

(Yes, the '' default might be fine for syslog, but I don't think
that's a good argument for sticking with it for default installs. I've
seen way too many useless log files out there, and at worst we'll have
syslogs with two timestamps.)

Christoph

On Sun, Oct 2, 2016 at 1:20 PM, Christoph Berg <myon(at)debian(dot)org> wrote:

> Re: Tom Lane 2016-09-29 <18642(dot)1475159736(at)sss(dot)pgh(dot)pa(dot)us>
> > > Possibly the longer version could be added as an example in the
> > > documentation.
> >
> > I suspect that simply having a nonempty default in the first place
> > is going to do more to raise peoples' awareness than anything we
> > could do in the documentation. But perhaps an example along these
> > lines would be useful for showing proper use of %q.
>
> Patch attached. (Still using %t, I don't think %m makes sense for the
> default.)
>

I don't agree with that part. When looking at sections of log files that
people post on help forums, I've often wished people had shared
milliseconds, and I've never wished they had truncated them off.

If two messages are separated by 0.950 seconds, it can have entirely
different implications than if they are separated by 0.002 seconds.

What is the cost of using %m, other than 4 (rather compressible) bytes per
log entry?

Cheers,

Jeff

Jeff Janes <jeff(dot)janes(at)gmail(dot)com> writes:
> On Sun, Oct 2, 2016 at 1:20 PM, Christoph Berg <myon(at)debian(dot)org> wrote:
>> Patch attached. (Still using %t, I don't think %m makes sense for the
>> default.)

> What is the cost of using %m, other than 4 (rather compressible) bytes per
> log entry?

More log I/O, which is not free ... and that remark about compressibility
is bogus for anyone who doesn't pipe their postmaster stderr into gzip.
I'm already afraid that adding the timestamps will get us some pushback
about log volume.

regards, tom lane

On Wed, Oct 12, 2016 at 10:11 AM, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:

> Jeff Janes <jeff(dot)janes(at)gmail(dot)com> writes:
> > On Sun, Oct 2, 2016 at 1:20 PM, Christoph Berg <myon(at)debian(dot)org> wrote:
> >> Patch attached. (Still using %t, I don't think %m makes sense for the
> >> default.)
>
> > What is the cost of using %m, other than 4 (rather compressible) bytes
> per
> > log entry?
>
> More log I/O, which is not free ... and that remark about compressibility
> is bogus for anyone who doesn't pipe their postmaster stderr into gzip.
> I'm already afraid that adding the timestamps will get us some pushback
> about log volume.
>

I don't pipe them into gzip, but every few months I go and pxz any of them
more than few months old.

Do you think the pushback will come from people who just accept the
defaults?

Cheers,

Jeff

Re: Jeff Janes 2016-10-12 <CAMkU=1zmOp5T70MX508nwFf8tvv2jOT+hGwLq8fNHLSxp-wVmQ(at)mail(dot)gmail(dot)com>
> Do you think the pushback will come from people who just accept the
> defaults?

I'm concerned about readability. "2016-10-12 20:14:30.449 CEST" is a
lot of digits. My eyes can parse "20:14:30" as a timestamp, but
"20:14:30.449" looks more like an IP address. (Admittedly I don't have
experience with reading %m logs.)

Overall, I'd prefer %t but %m would be ok as well.

Christoph

On Wed, Oct 12, 2016 at 11:20 AM, Christoph Berg <myon(at)debian(dot)org> wrote:
> Re: Jeff Janes 2016-10-12 <CAMkU=1zmOp5T70MX508nwFf8tvv2jOT+hGwLq8fNHLSxp-wVmQ(at)mail(dot)gmail(dot)com>
>> Do you think the pushback will come from people who just accept the
>> defaults?
>
> I'm concerned about readability. "2016-10-12 20:14:30.449 CEST" is a
> lot of digits. My eyes can parse "20:14:30" as a timestamp, but
> "20:14:30.449" looks more like an IP address. (Admittedly I don't have
> experience with reading %m logs.)
>
> Overall, I'd prefer %t but %m would be ok as well.

I'm fine with either! Both are much better than the empty string.
One of the problems with the status quo is that many users don't even
realize that log_line_prefix exists, so they don't configure it at
all. They don't even realize that they have the option to add a
prefix. I think configuring a non-empty default will be both better
by default and more likely to make people realize that they have
choices.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Hi,

On Wed, 2016-10-12 at 13:11 -0400, Tom Lane wrote:
> > What is the cost of using %m, other than 4 (rather compressible) bytes per
> > log entry?
>
> More log I/O, which is not free ...

FWIW, we've been setting log_line_prefix to '< %m > ' for quite a long time in
PGDG RPMs, and did not get any complaints. I'd vote for %m for default.

Regards,
--
Devrim GÜNDÜZ
EnterpriseDB: http://www.enterprisedb.com
PostgreSQL Danışmanı/Consultant, Red Hat Certified Engineer
Twitter: @DevrimGunduz , @DevrimGunduzTR

* Robert Haas (robertmhaas(at)gmail(dot)com) wrote:
> On Wed, Oct 12, 2016 at 11:20 AM, Christoph Berg <myon(at)debian(dot)org> wrote:
> > Re: Jeff Janes 2016-10-12 <CAMkU=1zmOp5T70MX508nwFf8tvv2jOT+hGwLq8fNHLSxp-wVmQ(at)mail(dot)gmail(dot)com>
> >> Do you think the pushback will come from people who just accept the
> >> defaults?
> >
> > I'm concerned about readability. "2016-10-12 20:14:30.449 CEST" is a
> > lot of digits. My eyes can parse "20:14:30" as a timestamp, but
> > "20:14:30.449" looks more like an IP address. (Admittedly I don't have
> > experience with reading %m logs.)
> >
> > Overall, I'd prefer %t but %m would be ok as well.
>
> I'm fine with either! Both are much better than the empty string.
> One of the problems with the status quo is that many users don't even
> realize that log_line_prefix exists, so they don't configure it at
> all. They don't even realize that they have the option to add a
> prefix. I think configuring a non-empty default will be both better
> by default and more likely to make people realize that they have
> choices.

For my 2c, I'd rather have %m, but I definitely agree with Robert that
we need to do *something* here and if the only thing holding us back is
%t vs. %m, then let's just pick one and move on. I'll just hold my nose
when I see the default and change it to %m.

Thanks!

Stephen

On 10/12/16 11:40 AM, Tom Lane wrote:
> There would be some value in the complexity you're thinking of for
> installations that log to multiple targets concurrently, but really,
> who does that?

I see that a lot.

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On 10/12/16 11:58 AM, Christoph Berg wrote:
> (Yes, the '' default might be fine for syslog, but I don't think
> that's a good argument for sticking with it for default installs. I've
> seen way too many useless log files out there, and at worst we'll have
> syslogs with two timestamps.)

We'd have to think of a way to sort this out during upgrades.
Documentation might be enough.

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Peter Eisentraut wrote:
> On 10/12/16 11:58 AM, Christoph Berg wrote:
> > (Yes, the '' default might be fine for syslog, but I don't think
> > that's a good argument for sticking with it for default installs. I've
> > seen way too many useless log files out there, and at worst we'll have
> > syslogs with two timestamps.)
>
> We'd have to think of a way to sort this out during upgrades.

Sure, but we don't have to do that in this patch, do we?

Some systems such as Debian copy the postgresql.conf file from the old
installation to the new one, and then have specific code to adjust
settings that no longer exist in the new version. I'm not a fan of that
approach myself precisely because if PGDG installs new defaults (such as
in this case), the sites using that upgrade tool don't benefit. A
better approach might be to copy over the non-default settings from the
old install to the new. If Debian were to do that then we wouldn't need
to do anything here.

--
Álvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Re: Stephen Frost 2016-10-12 <20161012190732(dot)GJ13284(at)tamriel(dot)snowman(dot)net>
> For my 2c, I'd rather have %m, but I definitely agree with Robert that
> we need to do *something* here and if the only thing holding us back is
> %t vs. %m, then let's just pick one and move on. I'll just hold my nose
> when I see the default and change it to %m.

Here's the very same patch with %m instead of %t. Pick one :)

(Fwiw, I'm still leaning towards %t, but my eyes are becoming more and
more accustomed to %m as well. I'd be fine with it as well. (I'd
rather want to try to get rid of the timezone identifier there...))

Christoph

On Fri, Oct 14, 2016 at 7:04 AM, Christoph Berg <myon(at)debian(dot)org> wrote:
> Re: Stephen Frost 2016-10-12 <20161012190732(dot)GJ13284(at)tamriel(dot)snowman(dot)net>
>> For my 2c, I'd rather have %m, but I definitely agree with Robert that
>> we need to do *something* here and if the only thing holding us back is
>> %t vs. %m, then let's just pick one and move on. I'll just hold my nose
>> when I see the default and change it to %m.
>
> Here's the very same patch with %m instead of %t. Pick one :)
>
> (Fwiw, I'm still leaning towards %t, but my eyes are becoming more and
> more accustomed to %m as well. I'd be fine with it as well. (I'd
> rather want to try to get rid of the timezone identifier there...))

So, surveying this thread, what I see is:

People who prefer %m: Jeff Janes, Devrim Gündüz, Stephen Frost
People who prefer %t: Christoph Berg, Tom Lane (I think)

We can kibitz this more later, but for now I've committed it with %m.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company