"unexpected EOF" messages
I had a request from a customer asking if we could make a switch to
specifically disable the "unexpected EOF" message that fills lots of
peoples logs. Along the same way that we have a flag to turn off the
"nonstandard use of string escapes" message that is another culprit
(that's actually a much *worse* problem than just the unexpected EOF).
The unexpected EOF message *does* indicate the client is doing
something stupid, but it's not like it's an *actual problem* in pretty
much every deployment out there...
Would we consider adding such a switch (it should be easy enough to
do), or do we want to push this off to the mythical "let's improve the
logging subsystem" project that might eventually materialize if we're
lucky? Meaning - would people object to such a switch?
--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/
On Thu, May 3, 2012 at 1:26 PM, Magnus Hagander <magnus@hagander.net> wrote:
I had a request from a customer asking if we could make a switch to
specifically disable the "unexpected EOF" message that fills lots of
peoples logs. Along the same way that we have a flag to turn off the
"nonstandard use of string escapes" message that is another culprit
(that's actually a much *worse* problem than just the unexpected EOF).
The unexpected EOF message *does* indicate the client is doing
something stupid, but it's not like it's an *actual problem* in pretty
much every deployment out there...Would we consider adding such a switch (it should be easy enough to
do), or do we want to push this off to the mythical "let's improve the
logging subsystem" project that might eventually materialize if we're
lucky? Meaning - would people object to such a switch?
Yes, if the new parameter allows a generic filter on multiple
user-specified message types.
--
Simon Riggs http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services
On Thu, May 3, 2012 at 2:31 PM, Simon Riggs <simon@2ndquadrant.com> wrote:
On Thu, May 3, 2012 at 1:26 PM, Magnus Hagander <magnus@hagander.net> wrote:
I had a request from a customer asking if we could make a switch to
specifically disable the "unexpected EOF" message that fills lots of
peoples logs. Along the same way that we have a flag to turn off the
"nonstandard use of string escapes" message that is another culprit
(that's actually a much *worse* problem than just the unexpected EOF).
The unexpected EOF message *does* indicate the client is doing
something stupid, but it's not like it's an *actual problem* in pretty
much every deployment out there...Would we consider adding such a switch (it should be easy enough to
do), or do we want to push this off to the mythical "let's improve the
logging subsystem" project that might eventually materialize if we're
lucky? Meaning - would people object to such a switch?Yes, if the new parameter allows a generic filter on multiple
user-specified message types.
Uh, just to be clear, you object *if* it has the generic filter?
Also, AFAIK we don't *have* a "message type" at this point (one of the
things said mythical project wanted to look at), so the only thing we
could really filter on would be the whole text of the message, no?
--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/
On Thu, May 3, 2012 at 2:31 PM, Simon Riggs <simon@2ndquadrant.com> wrote:
Would we consider adding such a switch (it should be easy enough to
do), or do we want to push this off to the mythical "let's improve the
logging subsystem" project that might eventually materialize if we're
lucky? Meaning - would people object to such a switch?Yes, if the new parameter allows a generic filter on multiple
user-specified message types.
Are you answering the "Would we consider" or the "would people object"?
On Thu, May 3, 2012 at 2:34 PM, Vik Reykja <vikreykja@gmail.com> wrote:
On Thu, May 3, 2012 at 2:31 PM, Simon Riggs <simon@2ndquadrant.com> wrote:
Would we consider adding such a switch (it should be easy enough to
do), or do we want to push this off to the mythical "let's improve the
logging subsystem" project that might eventually materialize if we're
lucky? Meaning - would people object to such a switch?Yes, if the new parameter allows a generic filter on multiple
user-specified message types.Are you answering the "Would we consider" or the "would people object"?
Oh, nice catch - I guess my phrasing of those two questions was really stupid :)
--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/
Magnus Hagander wrote:
Also, AFAIK we don't *have* a "message type" at this point (one of
the things said mythical project wanted to look at), so the only
thing we could really filter on would be the whole text of the
message, no?
We have SQLSTATE, but this seems to be one of those situations where
we've been sloppy about using the right value. We seem to be using
'08P01' (protocol_violation), which is also used for finding the
wrong bytes on a working connection. It seems to me a broken
connection is exactly the case where you would expect to see '08006'
(connection_failure). FWIW, there are also specific exceptions for
rejecting a connection attempt, and for attempting to send something
when no connection exists.
We don't need to invent new mechanisms for categorizing messages; we
just need to start consistently using the one we have correctly.
-Kevin
Import Notes
Resolved by subject fallback
Simon Riggs <simon@2ndQuadrant.com> writes:
On Thu, May 3, 2012 at 1:26 PM, Magnus Hagander <magnus@hagander.net> wrote:
I had a request from a customer asking if we could make a switch to
specifically disable the "unexpected EOF" message that fills lots of
peoples logs.
Yes, if the new parameter allows a generic filter on multiple
user-specified message types.
I agree with Simon --- a disable for that specific message seems like a
kluge, and an ugly one at that. (The right solution for this customer
is to fix their broken application.) But a generic filter capability
might be useful enough to justify its keep.
regards, tom lane
On Thu, May 3, 2012 at 2:46 PM, Kevin Grittner
<Kevin.Grittner@wicourts.gov> wrote:
Magnus Hagander wrote:
Also, AFAIK we don't *have* a "message type" at this point (one of
the things said mythical project wanted to look at), so the only
thing we could really filter on would be the whole text of the
message, no?We have SQLSTATE, but this seems to be one of those situations where
we've been sloppy about using the right value. We seem to be using
'08P01' (protocol_violation), which is also used for finding the
wrong bytes on a working connection. It seems to me a broken
connection is exactly the case where you would expect to see '08006'
(connection_failure). FWIW, there are also specific exceptions for
rejecting a connection attempt, and for attempting to send something
when no connection exists.We don't need to invent new mechanisms for categorizing messages; we
just need to start consistently using the one we have correctly.
While it might work a bit for this one, do we really expect to be able
to map a single SQLSTATE to each single message at any point? Unless
we can do that, it's never going to "go all the way" - though it might
still be useful of course.
--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/
On Thu, May 3, 2012 at 4:17 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
Simon Riggs <simon@2ndQuadrant.com> writes:
On Thu, May 3, 2012 at 1:26 PM, Magnus Hagander <magnus@hagander.net> wrote:
I had a request from a customer asking if we could make a switch to
specifically disable the "unexpected EOF" message that fills lots of
peoples logs.Yes, if the new parameter allows a generic filter on multiple
user-specified message types.I agree with Simon --- a disable for that specific message seems like a
kluge, and an ugly one at that. (The right solution for this customer
is to fix their broken application.) But a generic filter capability
might be useful enough to justify its keep.
Are you thinking basically "regexp against the main text", or
something else, when you say "generic filter capacity"?
--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/
Magnus Hagander <magnus@hagander.net> writes:
On Thu, May 3, 2012 at 4:17 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
I agree with Simon --- a disable for that specific message seems like a
kluge, and an ugly one at that. (The right solution for this customer
is to fix their broken application.) But a generic filter capability
might be useful enough to justify its keep.
Are you thinking basically "regexp against the main text", or
something else, when you say "generic filter capacity"?
In the context of yesterday's discussions, I wonder whether a filter by
SQLSTATE would be appropriate.
regards, tom lane
On Thu, May 3, 2012 at 4:53 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
Magnus Hagander <magnus@hagander.net> writes:
On Thu, May 3, 2012 at 4:17 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
I agree with Simon --- a disable for that specific message seems like a
kluge, and an ugly one at that. (The right solution for this customer
is to fix their broken application.) But a generic filter capability
might be useful enough to justify its keep.Are you thinking basically "regexp against the main text", or
something else, when you say "generic filter capacity"?In the context of yesterday's discussions, I wonder whether a filter by
SQLSTATE would be appropriate.
I'm worried it's not really granular enough.
regexp-on-text would also have the advantage of being able to filter
stuff coming from stored procedures or such as well - without having
to invent a whole bunch of SQLSTATEs to put in the stored procedures
(consider the usecase when somebody else wrote the stored procedures
and the DBA wants to limit the logging).
We could have two parameters of course - log_filter_sqlstate and
log_filter_re or something like that...
--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/
Magnus Hagander <magnus@hagander.net> writes:
On Thu, May 3, 2012 at 4:53 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
Magnus Hagander <magnus@hagander.net> writes:
Are you thinking basically "regexp against the main text", or
something else, when you say "generic filter capacity"?
In the context of yesterday's discussions, I wonder whether a filter by
SQLSTATE would be appropriate.
I'm worried it's not really granular enough.
I dislike the idea of regex-on-text because of i18n issues. There's no
guarantee for instance that all sessions are running with the same
LC_MESSAGES locale. In any case, anybody who's dead set on doing it
that way can do it today with grep.
regards, tom lane
Excerpts from Magnus Hagander's message of jue may 03 10:58:12 -0400 2012:
On Thu, May 3, 2012 at 4:53 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
In the context of yesterday's discussions, I wonder whether a filter by
SQLSTATE would be appropriate.I'm worried it's not really granular enough.
Yeah.
regexp-on-text would also have the advantage of being able to filter
stuff coming from stored procedures or such as well - without having
to invent a whole bunch of SQLSTATEs to put in the stored procedures
(consider the usecase when somebody else wrote the stored procedures
and the DBA wants to limit the logging).We could have two parameters of course - log_filter_sqlstate and
log_filter_re or something like that...
The problem with regexes is that they are so expensive. You just need
to forget the start anchor and it's suddenly a serious problem. And if
you want to filter out a second message, the config option starts
to become rather unwieldy.
I wonder if there's a better way to selectively filter out messages --
say some sort of config file that contains a list of filenames/numbers
of messages to disable. That particular idea would be a pain to
maintain, of course, not to mention that it'd change from one release to
the next.
Hey, maybe we could add a UUID to each ereport() call site ;-)
(Maybe the sites that have a load problem caused by log traffic are not
the same sites that would like to filter out messages, and thus using
regexes is not really a problem. It doesn't seem to be the kind of bet
that we want to do.)
--
Álvaro Herrera <alvherre@commandprompt.com>
The PostgreSQL Company - Command Prompt, Inc.
PostgreSQL Replication, Consulting, Custom Development, 24x7 support
On Thu, May 3, 2012 at 11:20 AM, Alvaro Herrera
<alvherre@commandprompt.com> wrote:
Hey, maybe we could add a UUID to each ereport() call site ;-)
I can't help but feel we're designing a $10.00 solution to a $0.25
problem. I think I'd actually support adding something like a UUID to
every ereport and a filtering mechanism that works on that basis. But
let's face it: this particular message is exponentially more annoying
than average. We're basically forcing application developers to jump
through hoops to avoid filling the log with unnecessary chatter. I've
spent a bunch of time trying to get rid of them in various past jobs,
and I've never gotten any benefit out of having them. Maybe the
solution is to just demote that particular message to DEBUG1 and
declare that closing the connection is a perfectly sensible way for an
application to indicate that the conversation is over.
--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company
Robert Haas <robertmhaas@gmail.com> writes:
On Thu, May 3, 2012 at 11:20 AM, Alvaro Herrera
<alvherre@commandprompt.com> wrote:Hey, maybe we could add a UUID to each ereport() call site ;-)
I can't help but feel we're designing a $10.00 solution to a $0.25
problem. I think I'd actually support adding something like a UUID to
every ereport and a filtering mechanism that works on that basis. But
let's face it: this particular message is exponentially more annoying
than average. We're basically forcing application developers to jump
through hoops to avoid filling the log with unnecessary chatter. I've
spent a bunch of time trying to get rid of them in various past jobs,
and I've never gotten any benefit out of having them. Maybe the
solution is to just demote that particular message to DEBUG1 and
declare that closing the connection is a perfectly sensible way for an
application to indicate that the conversation is over.
I could support that with one tweak: it's only DEBUG1 if you don't
have an open transaction. Dropping the connection while in a
transaction *is* an application bug; I don't care how lazy the app
programmer is feeling.
regards, tom lane
On Thu, May 3, 2012 at 11:39 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
Robert Haas <robertmhaas@gmail.com> writes:
On Thu, May 3, 2012 at 11:20 AM, Alvaro Herrera
<alvherre@commandprompt.com> wrote:Hey, maybe we could add a UUID to each ereport() call site ;-)
I can't help but feel we're designing a $10.00 solution to a $0.25
problem. I think I'd actually support adding something like a UUID to
every ereport and a filtering mechanism that works on that basis. But
let's face it: this particular message is exponentially more annoying
than average. We're basically forcing application developers to jump
through hoops to avoid filling the log with unnecessary chatter. I've
spent a bunch of time trying to get rid of them in various past jobs,
and I've never gotten any benefit out of having them. Maybe the
solution is to just demote that particular message to DEBUG1 and
declare that closing the connection is a perfectly sensible way for an
application to indicate that the conversation is over.I could support that with one tweak: it's only DEBUG1 if you don't
have an open transaction. Dropping the connection while in a
transaction *is* an application bug; I don't care how lazy the app
programmer is feeling.
I agree.
--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company
Alvaro Herrera <alvherre@commandprompt.com> wrote:
Excerpts from Magnus Hagander's message:
Tom Lane <tgl@sss.pgh.pa.us> wrote:
In the context of yesterday's discussions, I wonder whether a
filter by SQLSTATE would be appropriate.I'm worried it's not really granular enough.
Yeah.
Just to be sure we're not inventing a problem here, can someone
produce an example of a situation where it would not be granular
enough (assuming we correct bad SQLSTATE choices where they exist)?
I count 232 distinct SQLSTATE values (139 standard values and 93
PostgreSQL-specific values), and we can create more if we
want them; although I would recommend against doing that to get
finer resolution on a standard SQLSTATE value. A standard value
which is too coarse would be the strongest argument for adding some
other mechanism, IMO. If we do, I would be inclined toward
something to identify distinct conditions within a SQLSTATE, rather
than some overarching independent mechanism.
-Kevin
On Thu, May 3, 2012 at 11:46 AM, Kevin Grittner
<Kevin.Grittner@wicourts.gov> wrote:
Alvaro Herrera <alvherre@commandprompt.com> wrote:
Excerpts from Magnus Hagander's message:
Tom Lane <tgl@sss.pgh.pa.us> wrote:
In the context of yesterday's discussions, I wonder whether a
filter by SQLSTATE would be appropriate.I'm worried it's not really granular enough.
Yeah.
Just to be sure we're not inventing a problem here, can someone
produce an example of a situation where it would not be granular
enough (assuming we correct bad SQLSTATE choices where they exist)?I count 232 distinct SQLSTATE values (139 standard values and 93
PostgreSQL-specific values), and we can create more if we
want them; although I would recommend against doing that to get
finer resolution on a standard SQLSTATE value. A standard value
which is too coarse would be the strongest argument for adding some
other mechanism, IMO. If we do, I would be inclined toward
something to identify distinct conditions within a SQLSTATE, rather
than some overarching independent mechanism.
Well, nearby Tom and I discussed demoting the message to DEBUG1 when
no transaction is in progress. Presumably the two messages would
share the same SQL state, unless we're going to create separate SQL
states for connection-closed-not-in-a-txn and
connection-closed-in-a-txn; and yet I think there's a very decent
argument that you're much more likely to care about the latter than
the former.
--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company
Robert Haas <robertmhaas@gmail.com> writes:
Well, nearby Tom and I discussed demoting the message to DEBUG1 when
no transaction is in progress. Presumably the two messages would
share the same SQL state, unless we're going to create separate SQL
states for connection-closed-not-in-a-txn and
connection-closed-in-a-txn; and yet I think there's a very decent
argument that you're much more likely to care about the latter than
the former.
If we're going to treat the two cases differently then assigning
distinct SQLSTATEs seems entirely reasonable to me.
regards, tom lane
On Thu, May 3, 2012 at 5:39 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
Robert Haas <robertmhaas@gmail.com> writes:
On Thu, May 3, 2012 at 11:20 AM, Alvaro Herrera
<alvherre@commandprompt.com> wrote:Hey, maybe we could add a UUID to each ereport() call site ;-)
I can't help but feel we're designing a $10.00 solution to a $0.25
problem. I think I'd actually support adding something like a UUID to
every ereport and a filtering mechanism that works on that basis. But
let's face it: this particular message is exponentially more annoying
than average. We're basically forcing application developers to jump
through hoops to avoid filling the log with unnecessary chatter. I've
spent a bunch of time trying to get rid of them in various past jobs,
and I've never gotten any benefit out of having them. Maybe the
solution is to just demote that particular message to DEBUG1 and
declare that closing the connection is a perfectly sensible way for an
application to indicate that the conversation is over.I could support that with one tweak: it's only DEBUG1 if you don't
have an open transaction. Dropping the connection while in a
transaction *is* an application bug; I don't care how lazy the app
programmer is feeling.
I agree - that would certainly be a good fix for this one. One
question is do we want something like this:
- ereport(COMMERROR,
+ ereport(IsTransactionState() ? COMMERROR : DEBUG1,
(errcode(ERRCODE_PROTOCOL_VIOLATION),
errmsg("unexpected EOF on client connection")));(in a couple of places, yes)
or do we want to make the text of the error message different as well,
saying something like "unexpected EOF on client connection with an
open transaction"?
--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/