process type escape for log_line_prefix

On Mon, Feb 8, 2016 at 11:32 PM, Andres Freund <andres@anarazel.de> wrote:

Frequently when reading postgres logs to do some post mortem analysis
I'm left wondering what process emitted an error/log message. After the
fact it's often hard to know wether an error message was emitted by a
user backend or by something internal, say the checkpointer or
autovacuum. Logging all process starts is often impractical given the
log volume that causes.

So I'm proposing adding an escape displaying the process title (say 'k'
for kind?). So %k would emit something like "autovacuum worker process",
"wal sender process" etc.

It would be nice to get something consistent between the ps output and
this new prefix, say with for example a miscadmin.h parameter like
MyProcName.

I'm thinking it might make sense to give normal connections "" as the
name, they're usually already discernible.

Yeah, that sounds fine for me. What about background workers? I would
think that they should use BackgroundWorker->bgw_name.
--
Michael

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

Re: Michael Paquier 2016-02-10 <CAB7nPqS=wBbZzBcty1KyN-5Y9bPXZ+deJbfcCtebf06eF2Uyvg@mail.gmail.com>

On Mon, Feb 8, 2016 at 11:32 PM, Andres Freund <andres@anarazel.de> wrote:

Frequently when reading postgres logs to do some post mortem analysis
I'm left wondering what process emitted an error/log message. After the
fact it's often hard to know wether an error message was emitted by a
user backend or by something internal, say the checkpointer or
autovacuum. Logging all process starts is often impractical given the
log volume that causes.

So I'm proposing adding an escape displaying the process title (say 'k'
for kind?). So %k would emit something like "autovacuum worker process",
"wal sender process" etc.

It would be nice to get something consistent between the ps output and
this new prefix, say with for example a miscadmin.h parameter like
MyProcName.

I'm thinking it might make sense to give normal connections "" as the
name, they're usually already discernible.

Yeah, that sounds fine for me. What about background workers? I would
think that they should use BackgroundWorker->bgw_name.

(Rediscovering an old horse)

Couldn't these processes just set %a = application_name? (This would
obviously need %q to be taught that %a is always valid.)

Christoph

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

On Fri, Oct 14, 2016 at 4:11 AM, Christoph Berg <myon@debian.org> wrote:

Re: Michael Paquier 2016-02-10 <CAB7nPqS=wBbZzBcty1KyN-
5Y9bPXZ+deJbfcCtebf06eF2Uyvg@mail.gmail.com>

On Mon, Feb 8, 2016 at 11:32 PM, Andres Freund <andres@anarazel.de>

wrote:

Frequently when reading postgres logs to do some post mortem analysis
I'm left wondering what process emitted an error/log message. After the
fact it's often hard to know wether an error message was emitted by a
user backend or by something internal, say the checkpointer or
autovacuum. Logging all process starts is often impractical given the
log volume that causes.

So I'm proposing adding an escape displaying the process title (say 'k'
for kind?). So %k would emit something like "autovacuum worker

process",

"wal sender process" etc.

It would be nice to get something consistent between the ps output and
this new prefix, say with for example a miscadmin.h parameter like
MyProcName.

I'm thinking it might make sense to give normal connections "" as the
name, they're usually already discernible.

Yeah, that sounds fine for me. What about background workers? I would
think that they should use BackgroundWorker->bgw_name.

(Rediscovering an old horse)

Couldn't these processes just set %a = application_name? (This would
obviously need %q to be taught that %a is always valid.)

+1 from me on having non-session processes set application_name for logging
purposes, I've long wanted that.

I don't know why you would have to change %q though. I assume you would
just stick %a in from of %q, if that is what you wanted to do. But I've
never used %q myself.

Cheers,

Jeff

Re: Jeff Janes 2016-10-14 <CAMkU=1xxVuSDpRb3KS+LZU-UxhM9FShiAbs=U3FZrH3xe1B1Sw@mail.gmail.com>

I don't know why you would have to change %q though. I assume you would
just stick %a in from of %q, if that is what you wanted to do. But I've
never used %q myself.

I got it the wrong way round - the change will be that %a will be
available in non-session context as well, and hence the "Session only"
column in the log_line_prefix documentation table needs updating. Not
that %q would actually look at that table, but that was my brain was
thinking ;)

Christoph

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

On 2016-10-14 13:11:51 +0200, Christoph Berg wrote:

Re: Michael Paquier 2016-02-10 <CAB7nPqS=wBbZzBcty1KyN-5Y9bPXZ+deJbfcCtebf06eF2Uyvg@mail.gmail.com>

On Mon, Feb 8, 2016 at 11:32 PM, Andres Freund <andres@anarazel.de> wrote:

Frequently when reading postgres logs to do some post mortem analysis
I'm left wondering what process emitted an error/log message. After the
fact it's often hard to know wether an error message was emitted by a
user backend or by something internal, say the checkpointer or
autovacuum. Logging all process starts is often impractical given the
log volume that causes.

So I'm proposing adding an escape displaying the process title (say 'k'
for kind?). So %k would emit something like "autovacuum worker process",
"wal sender process" etc.

It would be nice to get something consistent between the ps output and
this new prefix, say with for example a miscadmin.h parameter like
MyProcName.

I'm thinking it might make sense to give normal connections "" as the
name, they're usually already discernible.

Yeah, that sounds fine for me. What about background workers? I would
think that they should use BackgroundWorker->bgw_name.

(Rediscovering an old horse)

Couldn't these processes just set %a = application_name?

It'd not get me what I'd want, no. E.g for walsenders that'd not be
parsable in a meaningful way. I really would like an escape that'd
always output one of:
Postmaster, Startup, BgWriter, Checkpointer, WalWriter, WalReceiver,
AutovacLauncher, AutovacWorker, PgArch, PgStat, SysLogger, Backend,
BackgroundWorker.

Greetings,

Andres Freund

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

On Fri, Oct 14, 2016 at 11:51 AM, Andres Freund <andres@anarazel.de> wrote:

On 2016-10-14 13:11:51 +0200, Christoph Berg wrote:

Re: Michael Paquier 2016-02-10 <CAB7nPqS=wBbZzBcty1KyN-

5Y9bPXZ+deJbfcCtebf06eF2Uyvg@mail.gmail.com>

On Mon, Feb 8, 2016 at 11:32 PM, Andres Freund <andres@anarazel.de>

wrote:

Frequently when reading postgres logs to do some post mortem analysis
I'm left wondering what process emitted an error/log message. After

the

fact it's often hard to know wether an error message was emitted by a
user backend or by something internal, say the checkpointer or
autovacuum. Logging all process starts is often impractical given

the

log volume that causes.

So I'm proposing adding an escape displaying the process title (say

'k'

for kind?). So %k would emit something like "autovacuum worker

process",

"wal sender process" etc.

It would be nice to get something consistent between the ps output and
this new prefix, say with for example a miscadmin.h parameter like
MyProcName.

I'm thinking it might make sense to give normal connections "" as the
name, they're usually already discernible.

Yeah, that sounds fine for me. What about background workers? I would
think that they should use BackgroundWorker->bgw_name.

(Rediscovering an old horse)

Couldn't these processes just set %a = application_name?

It'd not get me what I'd want, no. E.g for walsenders that'd not be
parsable in a meaningful way. I really would like an escape that'd
always output one of:
Postmaster, Startup, BgWriter, Checkpointer, WalWriter, WalReceiver,
AutovacLauncher, AutovacWorker, PgArch, PgStat, SysLogger, Backend,
BackgroundWorker.

I'm not sure what you are proposing. Which of those 13 strings you listed
would a walsender advertise itself as? Why would stuffing one of those
words into %k be different than stuffing that same word into %a, where %a
would otherwise be the empty string? The only problem I can see is if
someone has an application which calls itself "WalReceiver", for example,
so you can't distinguish a real WalReceiver from a self-declared
WalReceiver.

I'd be happy to replace the %a in my log_line_prefix with %a%k, but I don't
really see the point of of %a and %k being different things.

Cheers,

Jeff

On 2016-10-15 17:43:40 -0700, Jeff Janes wrote:

On Fri, Oct 14, 2016 at 11:51 AM, Andres Freund <andres@anarazel.de> wrote:

On 2016-10-14 13:11:51 +0200, Christoph Berg wrote:

Re: Michael Paquier 2016-02-10 <CAB7nPqS=wBbZzBcty1KyN-

5Y9bPXZ+deJbfcCtebf06eF2Uyvg@mail.gmail.com>

On Mon, Feb 8, 2016 at 11:32 PM, Andres Freund <andres@anarazel.de>

wrote:

Frequently when reading postgres logs to do some post mortem analysis
I'm left wondering what process emitted an error/log message. After

the

fact it's often hard to know wether an error message was emitted by a
user backend or by something internal, say the checkpointer or
autovacuum. Logging all process starts is often impractical given

the

log volume that causes.

So I'm proposing adding an escape displaying the process title (say

'k'

for kind?). So %k would emit something like "autovacuum worker

process",

"wal sender process" etc.

It would be nice to get something consistent between the ps output and
this new prefix, say with for example a miscadmin.h parameter like
MyProcName.

I'm thinking it might make sense to give normal connections "" as the
name, they're usually already discernible.

Yeah, that sounds fine for me. What about background workers? I would
think that they should use BackgroundWorker->bgw_name.

(Rediscovering an old horse)

Couldn't these processes just set %a = application_name?

It'd not get me what I'd want, no. E.g for walsenders that'd not be
parsable in a meaningful way. I really would like an escape that'd
always output one of:
Postmaster, Startup, BgWriter, Checkpointer, WalWriter, WalReceiver,
AutovacLauncher, AutovacWorker, PgArch, PgStat, SysLogger, Backend,
BackgroundWorker.

I'm not sure what you are proposing. Which of those 13 strings you listed
would a walsender advertise itself as?

Oops, left that one out (as it's not one of the pids explicitly listed
in postmaster.c, which I went over). 'WalSender'.

Why would stuffing one of those words into %k be different than
stuffing that same word into %a, where %a would otherwise be the empty
string?

Because you very well might want to keep tracking application_name for
walsenders - as that's important e.g. for sync replica tracking purposes
- and be able to categorize log messages by the type of process.

- Andres

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