Proposed GUC Variable

Someone asked for that recently, and the email is in my mailbox for
consideration. I think it is a great idea, and we have
debug_query_string that holds the current query. You could grab that
from elog.c. Added to TODO:

* Add GUC parameter to print queries that generate errors

---------------------------------------------------------------------------

Christopher Kings-Lynne wrote:

Hi,

My primary use of Postgres is as the backend database for a busy web site.
We have a cron job that just emails us the tail of our database, php, apache
logs every night. That way we can see some problems.

These logs almost always contain some errors. For instance, this is what I
see at the moment:

2002-08-22 19:21:57 ERROR: pg_atoi: error in "334 - 18k": can't parse " -
18k"

Now there's plenty of places that accept numeric input in the site and
obviously there's a bug in some script somewhere that's not filtering the
input properly or something. However - the error message above is useless
to me!!!

So, what I'd like to propose is a new GUC variable called
'debug_print_query_on_error' or something. Instead of turning on
debug_print_query and having my logs totally spammed up with sql, this GUC
variable would only print the query if an actual ERROR occurred. This way I
could nail the error very quickly by simply finding the query in my
codebase.

Is this possible? At the stage of processing where the elog(ERROR) occurs,
do we still have access to the original query string?

Comments?

Chris

---------------------------(end of broadcast)---------------------------
TIP 4: Don't 'kill -9' the postmaster

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

Hi all,

Quick hack while eating a sandwich.

template1=# select * frum;
ERROR: parser: parse error at or near "frum" at character 10
ERROR QUERY: select * frum;

Now, I did say quick hack. 'ERROR QUERY' isn't a new error level I just
strcat() it to buf_msg in elog() if debug_print_error_query is
true. Question: from Chris's request it doesn't sound like there is much
use writing this to the client. Does everyone else feel the same way?

If so, I'll patch it up and send off.

Gavin

On Thu, 22 Aug 2002, Bruce Momjian wrote:

Bruce Momjian <pgman@candle.pha.pa.us> writes:

Someone asked for that recently, and the email is in my mailbox for
consideration. I think it is a great idea, and we have
debug_query_string that holds the current query.

debug_query_string doesn't necessarily have a lot to do with the
proximate cause of the error. Consider queries issued by rules,
triggers, plpgsql functions, etc.

regards, tom lane

Tom Lane wrote:

Bruce Momjian <pgman@candle.pha.pa.us> writes:

Someone asked for that recently, and the email is in my mailbox for
consideration. I think it is a great idea, and we have
debug_query_string that holds the current query.

debug_query_string doesn't necessarily have a lot to do with the
proximate cause of the error. Consider queries issued by rules,
triggers, plpgsql functions, etc.

Maybe. I think giving the user the string that caused the error is
probably what they want, rather than a rule or trigger that they can't
tie back to an actual query.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

debug_query_string doesn't necessarily have a lot to do with the
proximate cause of the error. Consider queries issued by rules,
triggers, plpgsql functions, etc.

Maybe. I think giving the user the string that caused the error is
probably what they want, rather than a rule or trigger that they can't
tie back to an actual query.

Yeah, I'd agree with that.

Chris

Quick hack while eating a sandwich.

template1=# select * frum;
ERROR: parser: parse error at or near "frum" at character 10
ERROR QUERY: select * frum;

Now, I did say quick hack. 'ERROR QUERY' isn't a new error level I just
strcat() it to buf_msg in elog() if debug_print_error_query is
true. Question: from Chris's request it doesn't sound like there is much
use writing this to the client. Does everyone else feel the same way?

If so, I'll patch it up and send off.

How about the ERROR occurs and is sent to client and logged. Then you do
another elog(LOG, querystring) sort of thing. That way you won't confuse
clients that are parsing the messages but those interested in the log text
can read it quite happily.

That'd be my preferred solution...

Thanks for working on this BTW gavin.

Chris

On Fri, 2002-08-23 at 04:46, Bruce Momjian wrote:

* Add GUC parameter to print queries that generate errors

Maybe don't make that an option, but rather do it always. I don't see
where that would hurt. And killing configuration options that are
unneeded is always a Good Thing.

--
Markus Bertheau.
Berlin, Berlin.
Germany.

So long as the change is only evident in the log, I agree.

Chris

This is an intersting mix of features. First, use LOG so it goes only
to the log file by default _but_ can be turned on to be seen by the
client, and remove the GUC completely.

This does make 100% sense because an ERROR is going to go the client and
the server logs by default, and LOG is going to go to the server logs by
default _but_ can optionally be seen by the client by modifying
min_client_messagses.

---------------------------------------------------------------------------

Christopher Kings-Lynne wrote:

So long as the change is only evident in the log, I agree.

Chris

-----Original Message-----
From: pgsql-hackers-owner@postgresql.org
[mailto:pgsql-hackers-owner@postgresql.org]On Behalf Of Markus Bertheau
Sent: Friday, 23 August 2002 3:55 PM
To: Bruce Momjian
Cc: Christopher Kings-Lynne; Hackers
Subject: Re: [HACKERS] Proposed GUC Variable

On Fri, 2002-08-23 at 04:46, Bruce Momjian wrote:

* Add GUC parameter to print queries that generate errors

Maybe don't make that an option, but rather do it always. I don't see
where that would hurt. And killing configuration options that are
unneeded is always a Good Thing.

--
Markus Bertheau.
Berlin, Berlin.
Germany.

---------------------------(end of broadcast)---------------------------
TIP 6: Have you searched our list archives?

http://archives.postgresql.org

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

Markus Bertheau <twanger@bluetwanger.de> writes:

On Fri, 2002-08-23 at 04:46, Bruce Momjian wrote:

* Add GUC parameter to print queries that generate errors

Maybe don't make that an option, but rather do it always. I don't
see where that would hurt.

It would hurt in situations in which an error is expected to occur
(e.g. INSERT into table, if constraint violation then do XYZ). It
would also make the logs a lot larger + less readable if long (say,
100 line) queries are being executed.

I don't think either situation is particularly common, but I do think
it's worth keeping a GUC variable for it. The GUC var should probably
default to being enabled though.

Cheers,

Neil

--
Neil Conway <neilc@samurai.com> || PGP Key ID: DB3C29FC

I had an idea on this. It seems pretty pointless to show a query error
without a query, but some queries are very large.

How about if we print only the first 80 characters of the query, with
newlines, tabs, and spaces reduced to a single space, and send that as
LOG to the server logs. That would give people enough context, and
prevent us from having another GUC variable.

---------------------------------------------------------------------------

Gavin Sherry wrote:

Hi all,

Quick hack while eating a sandwich.

template1=# select * frum;
ERROR: parser: parse error at or near "frum" at character 10
ERROR QUERY: select * frum;

Now, I did say quick hack. 'ERROR QUERY' isn't a new error level I just
strcat() it to buf_msg in elog() if debug_print_error_query is
true. Question: from Chris's request it doesn't sound like there is much
use writing this to the client. Does everyone else feel the same way?

If so, I'll patch it up and send off.

Gavin

On Thu, 22 Aug 2002, Bruce Momjian wrote:

Someone asked for that recently, and the email is in my mailbox for
consideration. I think it is a great idea, and we have
debug_query_string that holds the current query. You could grab that
from elog.c. Added to TODO:

* Add GUC parameter to print queries that generate errors

---------------------------------------------------------------------------

Christopher Kings-Lynne wrote:

Hi,

My primary use of Postgres is as the backend database for a busy web site.
We have a cron job that just emails us the tail of our database, php, apache
logs every night. That way we can see some problems.

These logs almost always contain some errors. For instance, this is what I
see at the moment:

2002-08-22 19:21:57 ERROR: pg_atoi: error in "334 - 18k": can't parse " -
18k"

Now there's plenty of places that accept numeric input in the site and
obviously there's a bug in some script somewhere that's not filtering the
input properly or something. However - the error message above is useless
to me!!!

So, what I'd like to propose is a new GUC variable called
'debug_print_query_on_error' or something. Instead of turning on
debug_print_query and having my logs totally spammed up with sql, this GUC
variable would only print the query if an actual ERROR occurred. This way I
could nail the error very quickly by simply finding the query in my
codebase.

Is this possible? At the stage of processing where the elog(ERROR) occurs,
do we still have access to the original query string?

Comments?

Chris

---------------------------(end of broadcast)---------------------------
TIP 4: Don't 'kill -9' the postmaster

---------------------------(end of broadcast)---------------------------
TIP 2: you can get off all lists at once with the unregister command
(send "unregister YourEmailAddressHere" to majordomo@postgresql.org)

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

On Tue, 2002-08-27 at 15:54, Bruce Momjian wrote:

I had an idea on this. It seems pretty pointless to show a query error
without a query, but some queries are very large.

How about if we print only the first 80 characters of the query, with
newlines, tabs, and spaces reduced to a single space, and send that as
LOG to the server logs. That would give people enough context, and
prevent us from having another GUC variable.

Not necessarily giving enough context. I know I've had program
generated query's that were syntactically invalid WAY after the 80th
character.

If you print ANY of the query, you should print all of it. Look at the
code in elog.c that does the syslog splitting.

LER

---------------------------------------------------------------------------

Gavin Sherry wrote:

Hi all,

Quick hack while eating a sandwich.

template1=# select * frum;
ERROR: parser: parse error at or near "frum" at character 10
ERROR QUERY: select * frum;

Now, I did say quick hack. 'ERROR QUERY' isn't a new error level I just
strcat() it to buf_msg in elog() if debug_print_error_query is
true. Question: from Chris's request it doesn't sound like there is much
use writing this to the client. Does everyone else feel the same way?

If so, I'll patch it up and send off.

Gavin

On Thu, 22 Aug 2002, Bruce Momjian wrote:

Someone asked for that recently, and the email is in my mailbox for
consideration. I think it is a great idea, and we have
debug_query_string that holds the current query. You could grab that
from elog.c. Added to TODO:

* Add GUC parameter to print queries that generate errors

---------------------------------------------------------------------------

Christopher Kings-Lynne wrote:

Hi,

My primary use of Postgres is as the backend database for a busy web site.
We have a cron job that just emails us the tail of our database, php, apache
logs every night. That way we can see some problems.

These logs almost always contain some errors. For instance, this is what I
see at the moment:

2002-08-22 19:21:57 ERROR: pg_atoi: error in "334 - 18k": can't parse " -
18k"

Now there's plenty of places that accept numeric input in the site and
obviously there's a bug in some script somewhere that's not filtering the
input properly or something. However - the error message above is useless
to me!!!

So, what I'd like to propose is a new GUC variable called
'debug_print_query_on_error' or something. Instead of turning on
debug_print_query and having my logs totally spammed up with sql, this GUC
variable would only print the query if an actual ERROR occurred. This way I
could nail the error very quickly by simply finding the query in my
codebase.

Is this possible? At the stage of processing where the elog(ERROR) occurs,
do we still have access to the original query string?

Comments?

Chris

---------------------------(end of broadcast)---------------------------
TIP 4: Don't 'kill -9' the postmaster

---------------------------(end of broadcast)---------------------------
TIP 2: you can get off all lists at once with the unregister command
(send "unregister YourEmailAddressHere" to majordomo@postgresql.org)

-- 
Bruce Momjian                        |  http://candle.pha.pa.us
pgman@candle.pha.pa.us               |  (610) 359-1001
+  If your life is a hard drive,     |  13 Roberts Road
+  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

---------------------------(end of broadcast)---------------------------
TIP 3: if posting/reading through Usenet, please send an appropriate
subscribe-nomail command to majordomo@postgresql.org so that your
message can get through to the mailing list cleanly

--
Larry Rosenman http://www.lerctr.org/~ler
Phone: +1 972-414-9812 E-Mail: ler@lerctr.org
US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749

On Tue, 2002-08-27 at 16:54, Bruce Momjian wrote:

I had an idea on this. It seems pretty pointless to show a query error
without a query, but some queries are very large.

How about if we print only the first 80 characters of the query, with
newlines, tabs, and spaces reduced to a single space, and send that as
LOG to the server logs. That would give people enough context, and
prevent us from having another GUC variable.

I could go for the first 1000 characters, but 80 is almost useless for
most of our stuff. 80 wouldn't get through the select list a good chunk
of the time.

If an application in the product environment is throwing an error, we'd
want the full thing. Most of our internal systems are completely hands
off unless it's been scripted and tested elsewhere, so it's not like
user queries would be getting into it.

Perhaps a GUC for the length? But I'd still opt for storing the whole
thing. Yes, someone could fill up the disk but a rotating log would
help that.

Larry Rosenman wrote:

On Tue, 2002-08-27 at 15:54, Bruce Momjian wrote:

I had an idea on this. It seems pretty pointless to show a query error
without a query, but some queries are very large.

How about if we print only the first 80 characters of the query, with
newlines, tabs, and spaces reduced to a single space, and send that as
LOG to the server logs. That would give people enough context, and
prevent us from having another GUC variable.

Not necessarily giving enough context. I know I've had program
generated query's that were syntactically invalid WAY after the 80th
character.

If you print ANY of the query, you should print all of it. Look at the
code in elog.c that does the syslog splitting.

But we should have some default to print some of the query, because
right now we print none of it. I am not saying it is perfect, but it is
better than what we have, and is a reasonable default.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

Rod Taylor wrote:

On Tue, 2002-08-27 at 16:54, Bruce Momjian wrote:

I had an idea on this. It seems pretty pointless to show a query error
without a query, but some queries are very large.

How about if we print only the first 80 characters of the query, with
newlines, tabs, and spaces reduced to a single space, and send that as
LOG to the server logs. That would give people enough context, and
prevent us from having another GUC variable.

I could go for the first 1000 characters, but 80 is almost useless for
most of our stuff. 80 wouldn't get through the select list a good chunk
of the time.

If an application in the product environment is throwing an error, we'd
want the full thing. Most of our internal systems are completely hands
off unless it's been scripted and tested elsewhere, so it's not like
user queries would be getting into it.

Perhaps a GUC for the length? But I'd still opt for storing the whole
thing. Yes, someone could fill up the disk but a rotating log would
help that.

A length value would work, default to 80 and let someone turn it off
with zero and unlimited with 9999 or -1.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

On Tue, 2002-08-27 at 16:05, Bruce Momjian wrote:

Larry Rosenman wrote:

On Tue, 2002-08-27 at 15:54, Bruce Momjian wrote:

I had an idea on this. It seems pretty pointless to show a query error
without a query, but some queries are very large.

How about if we print only the first 80 characters of the query, with
newlines, tabs, and spaces reduced to a single space, and send that as
LOG to the server logs. That would give people enough context, and
prevent us from having another GUC variable.

Not necessarily giving enough context. I know I've had program
generated query's that were syntactically invalid WAY after the 80th
character.

If you print ANY of the query, you should print all of it. Look at the
code in elog.c that does the syslog splitting.

But we should have some default to print some of the query, because
right now we print none of it. I am not saying it is perfect, but it is
better than what we have, and is a reasonable default.

On an error, you may not be able to reproduce it. Why not print the
whole query to the log?

I don't see a reason for truncating it at 80 chars.

IMHO, of course.
--
Larry Rosenman http://www.lerctr.org/~ler
Phone: +1 972-414-9812 E-Mail: ler@lerctr.org
US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749

Larry Rosenman wrote:

But we should have some default to print some of the query, because
right now we print none of it. I am not saying it is perfect, but it is
better than what we have, and is a reasonable default.

On an error, you may not be able to reproduce it. Why not print the
whole query to the log?

I don't see a reason for truncating it at 80 chars.

IMHO, of course.

Because every typo query, every syntax error of a user in psql would
appear in your logs. That seems excessive. Already the ERROR line
appears in the logs. Do we want to see their bad query too?

My concern is that long queries could easily bulk up the logs to the
point where the actual important log messages would be lost in the fog.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

On Tue, 2002-08-27 at 16:14, Bruce Momjian wrote:

Larry Rosenman wrote:

But we should have some default to print some of the query, because
right now we print none of it. I am not saying it is perfect, but it is
better than what we have, and is a reasonable default.

On an error, you may not be able to reproduce it. Why not print the
whole query to the log?

I don't see a reason for truncating it at 80 chars.

IMHO, of course.

Because every typo query, every syntax error of a user in psql would
appear in your logs. That seems excessive. Already the ERROR line
appears in the logs. Do we want to see their bad query too?

My concern is that long queries could easily bulk up the logs to the
point where the actual important log messages would be lost in the fog.

Hmm. I think the 80 should be a GUC variable (and also settable from
SQL SET as well), and the 80 should probably be higher.

And, maybe send the full query at a different Syslog(3) level.

--
Larry Rosenman http://www.lerctr.org/~ler
Phone: +1 972-414-9812 E-Mail: ler@lerctr.org
US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749

Bruce Momjian <pgman@candle.pha.pa.us> writes:

But we should have some default to print some of the query,

Why? So far you've been told by two different people (make that three
now) that such a behavior is useless, and no one's weighed in in its
favor ...

regards, tom lane