Thread: Adding error message "source"
Since Alvaro is talking about error messages in another thread, I figured I should post this idea now as well. Something that keeps annoying me a lot when trying to look through what comes out of PostgreSQL logs is that errors generated by the user (syntax errors in queries, warnings due to incorrect string escaping, statements terminated due to timeout etc etc) are intermixed completely with warnings and errors from internal server functions like checkpoints and log archiving. This makes it much more harder than it should be to find the important messages. I'd like to add another field to messages called "source" (not wedded to the name). Initially, this could just be "user" and "internal", but I can see a use-case in the future for it to differ between for example "archiver" and "bgwriter" (it's certainly not unheard of that one would want to look at all output from the archiver, but ignore all other output). This could then be written as a field in log_line_prefix, and obviously included as it's own column in CVS output, to allow for further processing outside the database. As for the source, I think we'd just "decorate" the error messages with errsource(ERRSOURCE_USER) or something like that at places where needed, and have it default to "internal" - so we don't have to touch each and every error message in the backend. Sometime in the future I am considering implementing the ability to filter messages to different targets (files, syslog facilities, whatever), and this would also be a very interesting field to do such filtering on. But that's for sometime much further in the future, I haven't even started thinking about *how* to do that. But it's another possible use-case for this decoration. Thoughts? -- Magnus HaganderMe: http://www.hagander.net/Work: http://www.redpill-linpro.com/
Magnus Hagander <magnus@hagander.net> writes:
> I'd like to add another field to messages called "source" (not wedded
> to the name). Initially, this could just be "user" and "internal", but
> I can see a use-case in the future for it to differ between for
> example "archiver" and "bgwriter" (it's certainly not unheard of that
> one would want to look at all output from the archiver, but ignore all
> other output).
I think you'd have great difficulty making this work reliably ---
there are lots of messages that could be emitted in multiple contexts.
Just about all of bufmgr.c, for instance.
regards, tom lane
Magnus Hagander wrote: > Something that keeps annoying me a lot when trying to look through > what comes out of PostgreSQL logs is that errors generated by the user > (syntax errors in queries, warnings due to incorrect string escaping, > statements terminated due to timeout etc etc) are intermixed > completely with warnings and errors from internal server functions > like checkpoints and log archiving. This makes it much more harder > than it should be to find the important messages. > > I'd like to add another field to messages called "source" (not wedded > to the name). Initially, this could just be "user" and "internal", but > I can see a use-case in the future for it to differ between for > example "archiver" and "bgwriter" (it's certainly not unheard of that > one would want to look at all output from the archiver, but ignore all > other output). This could then be written as a field in > log_line_prefix, and obviously included as it's own column in CVS > output, to allow for further processing outside the database. > > As for the source, I think we'd just "decorate" the error messages > with errsource(ERRSOURCE_USER) or something like that at places where > needed, and have it default to "internal" - so we don't have to touch > each and every error message in the backend. Are you suggesting that all messages would have source of "internal", until we get around to change them? That doesn't seem nice. There is a *lot* of messages that are not internal. I think we should classify all messages correctly, or not at all. Decorating every ereport() seems like a daunting effort, both up-front and to maintain. And it could not easily differentiate between e.g "write failed" error coming from bgwriter and a backend. Could we deduce the category through some other means? Messages related to bgwriter or archiver, for example, would be differentiate by looking at what the current process is. Differentiating between "write failed because disk is full" and "syntax error because you typoed a query" would be harder. Maybe we could classify all messages coming from md.c and smgr.c into a "storage" category, but you'd likely need a lot of exceptions to that rule. Would you like to propose a concrete list sources that we would have? The implementation effort depends a lot on the categorization. -- Heikki Linnakangas EnterpriseDB http://www.enterprisedb.com
2009/8/5 Magnus Hagander <magnus@hagander.net>: > Since Alvaro is talking about error messages in another thread, I > figured I should post this idea now as well. > > Something that keeps annoying me a lot when trying to look through > what comes out of PostgreSQL logs is that errors generated by the user > (syntax errors in queries, warnings due to incorrect string escaping, > statements terminated due to timeout etc etc) are intermixed > completely with warnings and errors from internal server functions > like checkpoints and log archiving. This makes it much more harder > than it should be to find the important messages. > > I'd like to add another field to messages called "source" (not wedded > to the name). Initially, this could just be "user" and "internal", but > I can see a use-case in the future for it to differ between for > example "archiver" and "bgwriter" (it's certainly not unheard of that > one would want to look at all output from the archiver, but ignore all > other output). This could then be written as a field in > log_line_prefix, and obviously included as it's own column in CVS > output, to allow for further processing outside the database. > > As for the source, I think we'd just "decorate" the error messages > with errsource(ERRSOURCE_USER) or something like that at places where > needed, and have it default to "internal" - so we don't have to touch > each and every error message in the backend. > > Sometime in the future I am considering implementing the ability to > filter messages to different targets (files, syslog facilities, > whatever), and this would also be a very interesting field to do such > filtering on. But that's for sometime much further in the future, I > haven't even started thinking about *how* to do that. But it's another > possible use-case for this decoration. > > I agree with some new error attribs, but about this, I don't know. Can you show some use case? SQLCODE could carry enough information about user or system exception. There are reserved space for custom codes. Maybe for administration should be interesting, if error is system error or application error - but this should be described by SQLCODE well too. Pavel > Thoughts? > > -- > Magnus Hagander > Me: http://www.hagander.net/ > Work: http://www.redpill-linpro.com/ > > -- > Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) > To make changes to your subscription: > http://www.postgresql.org/mailpref/pgsql-hackers >
On Wednesday 05 August 2009 17:45:46 Pavel Stehule wrote: > SQLCODE could carry enough information about user or system exception. > There are reserved space for custom codes. Maybe for administration > should be interesting, if error is system error or application error - > but this should be described by SQLCODE well too. Yes, for exactly this reason, we just added SQLSTATE support to log_line_prefix.
On Wed, Aug 5, 2009 at 16:11, Heikki Linnakangas<heikki.linnakangas@enterprisedb.com> wrote: > Magnus Hagander wrote: >> As for the source, I think we'd just "decorate" the error messages >> with errsource(ERRSOURCE_USER) or something like that at places where >> needed, and have it default to "internal" - so we don't have to touch >> each and every error message in the backend. > > Are you suggesting that all messages would have source of "internal", > until we get around to change them? That doesn't seem nice. There is a > *lot* of messages that are not internal. I think we should classify all > messages correctly, or not at all. No, but under the idea I had most *would* be internal. Not until we get around to change them, but always. > Could we deduce the category through some other means? Messages related > to bgwriter or archiver, for example, would be differentiate by looking > at what the current process is. Yes. > Differentiating between "write failed because disk is full" and "syntax > error because you typoed a query" would be harder. Maybe we could > classify all messages coming from md.c and smgr.c into a "storage" > category, but you'd likely need a lot of exceptions to that rule. That's exactly the one I want to differentiate between. > Would you like to propose a concrete list sources that we would have? > The implementation effort depends a lot on the categorization. Well, the only one I have a direct usecase for is the one that is "I want logs that are created because of typos in a psql client, or because an application does bad things (sends broken queries, bad escaping, NULL in not-NULL field etc) to not clutter up the log when I look for information about checkpoints and log archiving". I don't really have a case for making it more fine-grained like that, but I figured someone else might have :-) Having SQLSTATE in log_line_prefix is certainly a good thing, but I don't see how I can easily use that to filter for this. Perhaps I'm wrong at that? Maybe I can do something with a very long chain of different greps on the different classes, but that seems to almost guarantee that i'll miss something... And we seem to set for example ERRCODE_WARNING as a default for everything that's a warning and doesn't specify an explicit SQLSTATE - I bet that includes both warnings that are "caused" by the client and that are "caused" by the system. -- Magnus HaganderMe: http://www.hagander.net/Work: http://www.redpill-linpro.com/
Magnus Hagander <magnus@hagander.net> writes:
> On Wed, Aug 5, 2009 at 16:11, Heikki
> Linnakangas<heikki.linnakangas@enterprisedb.com> wrote:
>> Would you like to propose a concrete list sources that we would have?
>> The implementation effort depends a lot on the categorization.
> Well, the only one I have a direct usecase for is the one that is "I
> want logs that are created because of typos in a psql client, or
> because an application does bad things (sends broken queries, bad
> escaping, NULL in not-NULL field etc) to not clutter up the log when I
> look for information about checkpoints and log archiving".
Well, it seems like you could get 90% of the way there just by filtering
on the PID --- watching the bgwriter, walwriter, and archiver should
cover this use-case reasonably well.
regards, tom lane
On Thu, Aug 6, 2009 at 16:20, Tom Lane<tgl@sss.pgh.pa.us> wrote: > Magnus Hagander <magnus@hagander.net> writes: >> On Wed, Aug 5, 2009 at 16:11, Heikki >> Linnakangas<heikki.linnakangas@enterprisedb.com> wrote: >>> Would you like to propose a concrete list sources that we would have? >>> The implementation effort depends a lot on the categorization. > >> Well, the only one I have a direct usecase for is the one that is "I >> want logs that are created because of typos in a psql client, or >> because an application does bad things (sends broken queries, bad >> escaping, NULL in not-NULL field etc) to not clutter up the log when I >> look for information about checkpoints and log archiving". > > Well, it seems like you could get 90% of the way there just by filtering > on the PID --- watching the bgwriter, walwriter, and archiver should > cover this use-case reasonably well. Right. But that's pretty hard to do automated, since they will get a new pid whenever the database is restarted. Which is hopefully not very often, but still an issue. Plus, it's hard to do any kind of historical look at things. -- Magnus HaganderMe: http://www.hagander.net/Work: http://www.redpill-linpro.com/
Magnus Hagander <magnus@hagander.net> writes:
> On Thu, Aug 6, 2009 at 16:20, Tom Lane<tgl@sss.pgh.pa.us> wrote:
>> Well, it seems like you could get 90% of the way there just by filtering
>> on the PID --- watching the bgwriter, walwriter, and archiver should
>> cover this use-case reasonably well.
> Right. But that's pretty hard to do automated, since they will get a
> new pid whenever the database is restarted. Which is hopefully not
> very often, but still an issue. Plus, it's hard to do any kind of
> historical look at things.
I don't think there'd be much logical difficulty in having an output
field (ie, CSV column or log_line_prefix escape) that represents a
classification of the PID, say as "postmaster, backend, AV worker,
AV launcher, bgwriter, ...". It would only require changing things
in one place, whereas your original proposal seemed mighty open-ended.
regards, tom lane
On Thu, Aug 6, 2009 at 16:33, Tom Lane<tgl@sss.pgh.pa.us> wrote: > Magnus Hagander <magnus@hagander.net> writes: >> On Thu, Aug 6, 2009 at 16:20, Tom Lane<tgl@sss.pgh.pa.us> wrote: >>> Well, it seems like you could get 90% of the way there just by filtering >>> on the PID --- watching the bgwriter, walwriter, and archiver should >>> cover this use-case reasonably well. > >> Right. But that's pretty hard to do automated, since they will get a >> new pid whenever the database is restarted. Which is hopefully not >> very often, but still an issue. Plus, it's hard to do any kind of >> historical look at things. > > I don't think there'd be much logical difficulty in having an output > field (ie, CSV column or log_line_prefix escape) that represents a > classification of the PID, say as "postmaster, backend, AV worker, > AV launcher, bgwriter, ...". It would only require changing things > in one place, whereas your original proposal seemed mighty open-ended. Good point. That *would* probably take care of much of the need. The downside is aggressive filtering that way would get rid of important messages coming out of a single backend, like out of disk space. Meaning it would still not be possible to filter on the difference between ERROR: syntax error in query and ERROR: out of disk space? But it'd be an improvement still. -- Magnus HaganderMe: http://www.hagander.net/Work: http://www.redpill-linpro.com/
Magnus Hagander <magnus@hagander.net> writes:
> On Thu, Aug 6, 2009 at 16:33, Tom Lane<tgl@sss.pgh.pa.us> wrote:
>> I don't think there'd be much logical difficulty in having an output
>> field (ie, CSV column or log_line_prefix escape) that represents a
>> classification of the PID, say as "postmaster, backend, AV worker,
>> AV launcher, bgwriter, ...". �It would only require changing things
>> in one place, whereas your original proposal seemed mighty open-ended.
> Good point. That *would* probably take care of much of the need. The
> downside is aggressive filtering that way would get rid of important
> messages coming out of a single backend, like out of disk space.
> Meaning it would still not be possible to filter on the difference
> between ERROR: syntax error in query and ERROR: out of disk space? But
> it'd be an improvement still.
Hmm, well, what about filtering on the SQLSTATE? You could do that
today. A category-level filter would probably serve pretty well.
regards, tom lane
On Thursday 06 August 2009 17:33:40 Tom Lane wrote: > I don't think there'd be much logical difficulty in having an output > field (ie, CSV column or log_line_prefix escape) that represents a > classification of the PID, say as "postmaster, backend, AV worker, > AV launcher, bgwriter, ...". It would only require changing things > in one place, whereas your original proposal seemed mighty open-ended. You might be able to achieve that if you use the %q escape and put something after the %q that you can search for.
On Thu, Aug 6, 2009 at 19:04, Peter Eisentraut<peter_e@gmx.net> wrote: > On Thursday 06 August 2009 17:33:40 Tom Lane wrote: >> I don't think there'd be much logical difficulty in having an output >> field (ie, CSV column or log_line_prefix escape) that represents a >> classification of the PID, say as "postmaster, backend, AV worker, >> AV launcher, bgwriter, ...". It would only require changing things >> in one place, whereas your original proposal seemed mighty open-ended. > > You might be able to achieve that if you use the %q escape and put something > after the %q that you can search for. You could do part of it, but you could still not differ them from each other. And really, it seems very much like a kludge to me. I'd rather have a "proper field" for it. -- Magnus HaganderMe: http://www.hagander.net/Work: http://www.redpill-linpro.com/
Magnus Hagander wrote: > On Thu, Aug 6, 2009 at 19:04, Peter Eisentraut<peter_e@gmx.net> wrote: > > On Thursday 06 August 2009 17:33:40 Tom Lane wrote: > >> I don't think there'd be much logical difficulty in having an output > >> field (ie, CSV column or log_line_prefix escape) that represents a > >> classification of the PID, say as "postmaster, backend, AV worker, > >> AV launcher, bgwriter, ...". ?It would only require changing things > >> in one place, whereas your original proposal seemed mighty open-ended. > > > > You might be able to achieve that if you use the %q escape and put something > > after the %q that you can search for. > > You could do part of it, but you could still not differ them from each > other. And really, it seems very much like a kludge to me. I'd rather > have a "proper field" for it. Is this a TODO? -- Bruce Momjian <bruce@momjian.us> http://momjian.us EnterpriseDB http://enterprisedb.com + If your life is a hard drive, Christ can be your backup. +