Set log_line_prefix and application name in test drivers

Peter Eisentraut <peter.eisentraut@2ndquadrant.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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

On 8/9/16 12:16 PM, Tom Lane wrote:

Peter Eisentraut <peter.eisentraut@2ndquadrant.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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:

On 8/9/16 12:16 PM, Tom Lane wrote:

Peter Eisentraut <peter.eisentraut@2ndquadrant.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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: Fabien COELHO 2016-08-26 <alpine.DEB.2.20.1608261620260.7102@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@%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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Christoph Berg <myon@debian.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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

On Sat, Aug 27, 2016 at 3:59 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

Christoph Berg <myon@debian.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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

On Thu, Sep 15, 2016 at 5:18 PM, Robert Haas <robertmhaas@gmail.com> wrote:

On Sat, Aug 27, 2016 at 3:59 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

Christoph Berg <myon@debian.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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Re: Robert Haas 2016-09-28 <CA+TgmobB-igLrjfH+zfmpY00ysAseCBxcRukjyhdneamyebfYA@mail.gmail.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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Robert Haas <robertmhaas@gmail.com> writes:

On Thu, Sep 15, 2016 at 5:18 PM, Robert Haas <robertmhaas@gmail.com> wrote:

On Sat, Aug 27, 2016 at 3:59 PM, Tom Lane <tgl@sss.pgh.pa.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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Tom Lane wrote:

Robert Haas <robertmhaas@gmail.com> writes:

On Thu, Sep 15, 2016 at 5:18 PM, Robert Haas <robertmhaas@gmail.com> wrote:

On Sat, Aug 27, 2016 at 3:59 PM, Tom Lane <tgl@sss.pgh.pa.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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

On Wed, Sep 28, 2016 at 6:07 PM, Alvaro Herrera
<alvherre@2ndquadrant.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@%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@%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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Alvaro Herrera <alvherre@2ndquadrant.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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

On 9/28/16 6:13 PM, Robert Haas wrote:

Christoph/Debian:
log_line_prefix = '%t [%p-%l] %q%u@%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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:

On 9/28/16 6:13 PM, Robert Haas wrote:

Christoph/Debian:
log_line_prefix = '%t [%p-%l] %q%u@%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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers