Обсуждение: Proposed GUC Variable

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

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,
Pennsylvania19073
 

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
> > 
> 
> 

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,
Pennsylvania19073
 

> > 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

> -----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
> 

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,
Pennsylvania19073
 

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,
Pennsylvania19073
 

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.

> ---------------------------------------------------------------------------
> 
> 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 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,
Pennsylvania19073
 

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,
Pennsylvania19073
 

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,
Pennsylvania19073
 

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

On Tue, Aug 27, 2002 at 06:08:40PM -0400, Tom Lane wrote:
> 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 ...

I agree that a 'trimmed' query is likely to be useless, but the idea of
printing the query on ERROR is a big win for me: right now I'm logging
_all_ queries on our development machine (and sometimes on our production
machine. when there's trouble) so my logs would get considerably smaller.

A settable trim length would probably be a good idea, I suppose, for
those slinging 'bytea' and toasted texts around.

Ross

On Tue, 2002-08-27 at 17:30, Ross J. Reedstrom wrote:
> On Tue, Aug 27, 2002 at 06:08:40PM -0400, Tom Lane wrote:
> > 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 ...
> 
> I agree that a 'trimmed' query is likely to be useless, but the idea of
> printing the query on ERROR is a big win for me: right now I'm logging
> _all_ queries on our development machine (and sometimes on our production
> machine. when there's trouble) so my logs would get considerably smaller.
I agree with printing the query on error... just not limiting it to 80
characters by default. 
> 
> A settable trim length would probably be a good idea, I suppose, for
> those slinging 'bytea' and toasted texts around.
Yes, but the default should be NO TRIM or in 1K-4K range. IMHO

-- 
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

"Ross J. Reedstrom" <reedstrm@rice.edu> writes:
> I agree that a 'trimmed' query is likely to be useless, but the idea of
> printing the query on ERROR is a big win for me:

Certainly.  I think though that an on-or-off GUC option is sufficient.
We don't need a length, and we definitely don't need code to strip out
whitespace as Bruce was suggesting ...
        regards, tom lane

> > A settable trim length would probably be a good idea, I suppose, for
> > those slinging 'bytea' and toasted texts around.
> Yes, but the default should be NO TRIM or in 1K-4K range. IMHO

Ditto.

On Tue, 2002-08-27 at 17:17, Larry Rosenman wrote:
> 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.

Not sure whether it can be done easily, but I think I'd prefer to log it
to a different file/facility. That lets me keep the full query for the
users, without swamping the sysadmin's logs. Just my $0.02.

--
Karl

OK, just go with a boolean and admins can decide if they want it.

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

Tom Lane wrote:
> "Ross J. Reedstrom" <reedstrm@rice.edu> writes:
> > I agree that a 'trimmed' query is likely to be useless, but the idea of
> > printing the query on ERROR is a big win for me:
> 
> Certainly.  I think though that an on-or-off GUC option is sufficient.
> We don't need a length, and we definitely don't need code to strip out
> whitespace as Bruce was suggesting ...
> 
>             regards, tom lane
> 

--  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,
Pennsylvania19073
 

tgl@sss.pgh.pa.us (Tom Lane) wrote

> "Ross J. Reedstrom" <reedstrm@rice.edu> writes:
>> I agree that a 'trimmed' query is likely to be useless, but the idea of
>> printing the query on ERROR is a big win for me:
> 
> Certainly.  I think though that an on-or-off GUC option is sufficient.
> We don't need a length, and we definitely don't need code to strip out
> whitespace as Bruce was suggesting ...

Just out of curiosity... how much harder would it be to have the GUC 
variable represent the truncation length? so setting it to zero would be 
equivalent to turning the feature off...  I personally would have no use 
for this feature, but I am just curious.

On Tue, 27 Aug 2002, Tom Lane wrote:

> 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 ...

I completely agree. Nothing wrong with adding another guc variable and
since it is a debug variable people expect lots of verbosity.

Once I check out some other suggestions by Christopher I'll send a patch
in -- its only a 10 liner.

Gavin

On Wed, 28 Aug 2002, Gavin Sherry wrote:

> On Tue, 27 Aug 2002, Tom Lane wrote:
>
> > 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 ...
>
> I completely agree. Nothing wrong with adding another guc variable and
> since it is a debug variable people expect lots of verbosity.

Attached is the patch. debug_print_error_query is set to false by default.

For want of a better phrase, I've prepended 'original query: ' to the
error message to highlight why it is in the log.

Gavin

I tested this patch and I can confirm that it works very well on
FreeBSD/Alpha!  This is such a cool feature - it's going to make my life so
much easier!

Do you think that 'original query: ..' looks a bit like bad english?  Should
it be properly capitalised?  ie. 'Original query: ...'?  Just nitpicking...

Chris

> -----Original Message-----
> From: pgsql-patches-owner@postgresql.org
> [mailto:pgsql-patches-owner@postgresql.org]On Behalf Of Gavin Sherry
> Sent: Wednesday, 28 August 2002 2:27 PM
> To: Tom Lane
> Cc: Hackers; pgsql-patches@postgresql.org
> Subject: Re: [PATCHES] [HACKERS] Proposed GUC Variable
>
>
> On Wed, 28 Aug 2002, Gavin Sherry wrote:
>
> > On Tue, 27 Aug 2002, Tom Lane wrote:
> >
> > > 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 ...
> >
> > I completely agree. Nothing wrong with adding another guc variable and
> > since it is a debug variable people expect lots of verbosity.
>
> Attached is the patch. debug_print_error_query is set to false by default.
>
> For want of a better phrase, I've prepended 'original query: ' to the
> error message to highlight why it is in the log.
>
> Gavin
>

Gavin Sherry writes:

> Attached is the patch. debug_print_error_query is set to false by default.
>
> For want of a better phrase, I've prepended 'original query: ' to the
> error message to highlight why it is in the log.

From your resident How-To-Name-Stuff Nitpicker:

1. The names of the debug_* GUC variables are leftovers from the pre-GUC
era and the names where left to include "debug" in them because at the
time it wasn't clear whether the implementation had more than server-code
debugging quality.  New variables should be named log_*.

2. Unless you are only logging queries, the correct term is "statement" or
"commmand".  Statements are defined in the SQL standard to end at the
semicolon, but if you're logging whatever the client passed in (which may
contain multiple statements) then "command" might be best.  (consequently:
log_command_on_error or something like that)

3. Not sure what the "original" is for -- you're not transforming
anything.

--
Peter Eisentraut   peter_e@gmx.net

Christopher Kings-Lynne writes:

> Do you think that 'original query: ..' looks a bit like bad english?  Should
> it be properly capitalised?  ie. 'Original query: ...'?  Just nitpicking...

I find it's generally better to not capitalize anything in program
messages, unless the sentence/paragraph nature is very evident.  Otherwise
you get drawn into a big deal about which messages are sentences or
qualifying fragments, it creates inconsistencies if your messages get
embedded into other messages, and the next day you start thinking about
putting periods at the end, which is a really bad idea.

--
Peter Eisentraut   peter_e@gmx.net

Peter Eisentraut wrote:
> Gavin Sherry writes:
>
> > Attached is the patch. debug_print_error_query is set to false by default.
> >
> > For want of a better phrase, I've prepended 'original query: ' to the
> > error message to highlight why it is in the log.
>
> >From your resident How-To-Name-Stuff Nitpicker:
>
> 1. The names of the debug_* GUC variables are leftovers from the pre-GUC
> era and the names where left to include "debug" in them because at the
> time it wasn't clear whether the implementation had more than server-code
> debugging quality.  New variables should be named log_*.

Agreed.  They are not really _debug_ for the server, but debug for user
apps;  should be "log".


> 2. Unless you are only logging queries, the correct term is "statement" or
> "commmand".  Statements are defined in the SQL standard to end at the
> semicolon, but if you're logging whatever the client passed in (which may
> contain multiple statements) then "command" might be best.  (consequently:
> log_command_on_error or something like that)

Or log_statement_on_error.  I think statement is better because we are
using that now for statement_timeout.

> 3. Not sure what the "original" is for -- you're not transforming
> anything.

Agreed.  Just call it "Error query".  Seems clear to me.

--
  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 Wed, 2002-08-28 at 14:05, Bruce Momjian wrote:
> Peter Eisentraut wrote:
> > Gavin Sherry writes:
> >
> > > Attached is the patch. debug_print_error_query is set to false by default.
> > >
> > > For want of a better phrase, I've prepended 'original query: ' to the
> > > error message to highlight why it is in the log.
> >
> > >From your resident How-To-Name-Stuff Nitpicker:
> >
> > 1. The names of the debug_* GUC variables are leftovers from the pre-GUC
> > era and the names where left to include "debug" in them because at the
> > time it wasn't clear whether the implementation had more than server-code
> > debugging quality.  New variables should be named log_*.
>
> Agreed.  They are not really _debug_ for the server, but debug for user
> apps;  should be "log".
>
>
> > 2. Unless you are only logging queries, the correct term is "statement" or
> > "commmand".  Statements are defined in the SQL standard to end at the
> > semicolon, but if you're logging whatever the client passed in (which may
> > contain multiple statements) then "command" might be best.  (consequently:
> > log_command_on_error or something like that)
>
> Or log_statement_on_error.  I think statement is better because we are
> using that now for statement_timeout.
>
> > 3. Not sure what the "original" is for -- you're not transforming
> > anything.
>
> Agreed.  Just call it "Error query".  Seems clear to me.
What about rule(s) transformation(s)?  Will we see the real query or the
transformed query?

--
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:
> > > 3. Not sure what the "original" is for -- you're not transforming
> > > anything.
> >
> > Agreed.  Just call it "Error query".  Seems clear to me.
> What about rule(s) transformation(s)?  Will we see the real query or the
> transformed query?

Well, looking at Gavin's patch, I see:

+               if(lev == ERROR && Debug_print_error_query)
+                       elog(LOG,"original query: %s",debug_query_string);

That will be the query supplied by the user.  To give them anything else
would be even more confusing --- "How did that query get executed.  I
don't even see that query in my code".  At least when they see that the
query and the error don't match, they can think, rules/triggers, etc.
We should mention the possible mismatch in the docs.

--
  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

One of my users is generating a notice message --> NOTICE:  Adding
missing FROM-clause entry for table "msg202"  It might be helpful to
dump out the query on notice messages like this, and it looks like a
simple change as far as elog.c and guc.c are concerned, but would this
be overkill?

Robert Treat

On Wed, 2002-08-28 at 02:26, Gavin Sherry wrote:
> On Wed, 28 Aug 2002, Gavin Sherry wrote:
>
> > On Tue, 27 Aug 2002, Tom Lane wrote:
> >
> > > 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 ...
> >
> > I completely agree. Nothing wrong with adding another guc variable and
> > since it is a debug variable people expect lots of verbosity.
>
> Attached is the patch. debug_print_error_query is set to false by default.
>
> For want of a better phrase, I've prepended 'original query: ' to the
> error message to highlight why it is in the log.
>
> Gavin
>
> ----
>

>
> ---------------------------(end of broadcast)---------------------------
> TIP 6: Have you searched our list archives?
>
> http://archives.postgresql.org

Robert Treat <xzilla@users.sourceforge.net> writes:
> One of my users is generating a notice message --> NOTICE:  Adding
> missing FROM-clause entry for table "msg202"  It might be helpful to
> dump out the query on notice messages like this, and it looks like a
> simple change as far as elog.c and guc.c are concerned, but would this
> be overkill?

Hm.  Maybe instead of a boolean, what we want is a message level
variable: log original query if it triggers a message >= severity X.

            regards, tom lane

On August 29, 2002 12:09 pm, Robert Treat wrote:
> One of my users is generating a notice message --> NOTICE:  Adding
> missing FROM-clause entry for table "msg202"  It might be helpful to
> dump out the query on notice messages like this, and it looks like a
> simple change as far as elog.c and guc.c are concerned, but would this
> be overkill?

Could be useful.  In the meantime you still have an option.  Turn on query 
logging and then you can go back to your logs and find this notice and the 
query that generated it.  Note that this could create lots of logs so be 
prepared.  I think that Tom's suggestion is better in the long run but if you 
need something now then that works.

-- 
D'Arcy J.M. Cain <darcy@{druid|vex}.net>   |  Democracy is three wolves
http://www.druid.net/darcy/                |  and a sheep voting on
+1 416 425 1212     (DoD#0082)    (eNTP)   |  what's for dinner.

On Thu, 29 Aug 2002, Tom Lane wrote:

> Robert Treat <xzilla@users.sourceforge.net> writes:
> > One of my users is generating a notice message --> NOTICE:  Adding
> > missing FROM-clause entry for table "msg202"  It might be helpful to
> > dump out the query on notice messages like this, and it looks like a
> > simple change as far as elog.c and guc.c are concerned, but would this
> > be overkill?
>
> Hm.  Maybe instead of a boolean, what we want is a message level
> variable: log original query if it triggers a message >= severity X.

That's a pretty good idea. Now, what format will the argument take: text
(NOTICE, ERROR, DEBUG, etc) or integer? The increasing severity is clear
with numbers but the correlation to NOTICE, ERROR etc is undocumented
IIRC. On the other hand, the textual form is clear but INFO < NOTICE <
WARNING < ERROR < FATAL, etc, is note necessarily obvious. (Also, with the
textual option the word will need to be converted to the corresponding
number by the GUC code).

Naturally, the problem with each option can be cleared up with
documentation.

Does anyone have a preference here?

Gavin

On Thu, 2002-08-29 at 19:04, Gavin Sherry wrote:
> On Thu, 29 Aug 2002, Tom Lane wrote:
>
> > Robert Treat <xzilla@users.sourceforge.net> writes:
> > > One of my users is generating a notice message --> NOTICE:  Adding
> > > missing FROM-clause entry for table "msg202"  It might be helpful to
> > > dump out the query on notice messages like this, and it looks like a
> > > simple change as far as elog.c and guc.c are concerned, but would this
> > > be overkill?
> >
> > Hm.  Maybe instead of a boolean, what we want is a message level
> > variable: log original query if it triggers a message >= severity X.
>
> That's a pretty good idea. Now, what format will the argument take: text
> (NOTICE, ERROR, DEBUG, etc) or integer? The increasing severity is clear
> with numbers but the correlation to NOTICE, ERROR etc is undocumented
> IIRC. On the other hand, the textual form is clear but INFO < NOTICE <
> WARNING < ERROR < FATAL, etc, is note necessarily obvious. (Also, with the
> textual option the word will need to be converted to the corresponding
> number by the GUC code).
>
> Naturally, the problem with each option can be cleared up with
> documentation.
my gut feeling is use the words.


--
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

Gavin Sherry wrote:
> On Thu, 29 Aug 2002, Tom Lane wrote:
>
> > Robert Treat <xzilla@users.sourceforge.net> writes:
> > > One of my users is generating a notice message --> NOTICE:  Adding
> > > missing FROM-clause entry for table "msg202"  It might be helpful to
> > > dump out the query on notice messages like this, and it looks like a
> > > simple change as far as elog.c and guc.c are concerned, but would this
> > > be overkill?
> >
> > Hm.  Maybe instead of a boolean, what we want is a message level
> > variable: log original query if it triggers a message >= severity X.
>
> That's a pretty good idea. Now, what format will the argument take: text
> (NOTICE, ERROR, DEBUG, etc) or integer? The increasing severity is clear
> with numbers but the correlation to NOTICE, ERROR etc is undocumented
> IIRC. On the other hand, the textual form is clear but INFO < NOTICE <
> WARNING < ERROR < FATAL, etc, is note necessarily obvious. (Also, with the
> textual option the word will need to be converted to the corresponding
> number by the GUC code).
>
> Naturally, the problem with each option can be cleared up with
> documentation.

I think the arg has to be text.  See server_min_messages GUC for an
example.

--
  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

Gavin Sherry <swm@linuxworld.com.au> writes:
> That's a pretty good idea. Now, what format will the argument take: text
> (NOTICE, ERROR, DEBUG, etc) or integer? The increasing severity is clear
> with numbers but the correlation to NOTICE, ERROR etc is undocumented
> IIRC. On the other hand, the textual form is clear but INFO < NOTICE <
> WARNING < ERROR < FATAL, etc, is note necessarily obvious.

The variable should take the same values as SERVER_MIN_MESSAGES and
impose the same priority order as it does.  I would assume you could
share code, or at worst copy-and-paste a few dozen lines.

            regards, tom lane

On Thu, 29 Aug 2002, Tom Lane wrote:

> Gavin Sherry <swm@linuxworld.com.au> writes:
> > That's a pretty good idea. Now, what format will the argument take: text
> > (NOTICE, ERROR, DEBUG, etc) or integer? The increasing severity is clear
> > with numbers but the correlation to NOTICE, ERROR etc is undocumented
> > IIRC. On the other hand, the textual form is clear but INFO < NOTICE <
> > WARNING < ERROR < FATAL, etc, is note necessarily obvious.
>
> The variable should take the same values as SERVER_MIN_MESSAGES and
> impose the same priority order as it does.  I would assume you could
> share code, or at worst copy-and-paste a few dozen lines.

A patch implementing this is attached. Instead of copy-and-pasting the
code, I abstracted out of the lookup and converted the existing functions
to use it.

I was careful in elog() to ignore elog(LOG) calls when
log_min_error_query >= LOG.

Gavin

OK, attached patch applied.  I made a few changes.  I added a mention
they may want to enable LOG_PID because there is no guarantee that the
statement and error will appear next to each other in the log file.  I
also renamed 'query' to 'statement' to be more precise.

Also, is there any way to disable this feature?   I can't see how.

Also, you added this line:

    + extern bool Debug_print_error_query;

I assume it was a mistake.

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

Gavin Sherry wrote:
> On Thu, 29 Aug 2002, Tom Lane wrote:
>
> > Gavin Sherry <swm@linuxworld.com.au> writes:
> > > That's a pretty good idea. Now, what format will the argument take: text
> > > (NOTICE, ERROR, DEBUG, etc) or integer? The increasing severity is clear
> > > with numbers but the correlation to NOTICE, ERROR etc is undocumented
> > > IIRC. On the other hand, the textual form is clear but INFO < NOTICE <
> > > WARNING < ERROR < FATAL, etc, is note necessarily obvious.
> >
> > The variable should take the same values as SERVER_MIN_MESSAGES and
> > impose the same priority order as it does.  I would assume you could
> > share code, or at worst copy-and-paste a few dozen lines.
>
> A patch implementing this is attached. Instead of copy-and-pasting the
> code, I abstracted out of the lookup and converted the existing functions
> to use it.
>
> I was careful in elog() to ignore elog(LOG) calls when
> log_min_error_query >= LOG.
>
> Gavin

Content-Description:

[ Attachment, skipping... ]

>
> ---------------------------(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
Index: doc/src/sgml/runtime.sgml
===================================================================
RCS file: /cvsroot/pgsql-server/doc/src/sgml/runtime.sgml,v
retrieving revision 1.132
diff -c -c -r1.132 runtime.sgml
*** doc/src/sgml/runtime.sgml    1 Sep 2002 23:26:06 -0000    1.132
--- doc/src/sgml/runtime.sgml    2 Sep 2002 05:35:45 -0000
***************
*** 942,948 ****
         </para>
        </listitem>
       </varlistentry>
-
       <varlistentry>
        <term><varname>EXPLAIN_PRETTY_PRINT</varname> (<type>boolean</type>)</term>
        <listitem>
--- 942,947 ----
***************
*** 979,984 ****
--- 978,1005 ----
       </varlistentry>

       <varlistentry>
+       <term><varname>LOG_MIN_ERROR_STATEMENT</varname> (<type>string</type>)</term>
+       <listitem>
+        <para>
+         This controls which log messages are accompanied by the original
+         query which generated the message. All queries matching the setting
+         or which are of a higher severity than the setting are logged. The
+         default is <literal>ERROR</literal>. Valid values are
+         <literal>DEBUG5</literal>, <literal>DEBUG4</literal>,
+         <literal>DEBUG3</literal>, <literal>DEBUG2</literal>,
+         <literal>DEBUG1</literal>, <literal>INFO</literal>,
+         <literal>NOTICE</literal>, <literal>WARNING</literal>
+         and <literal>ERROR</literal>.
+        </para>
+        <para>
+         It is recommended you enable <literal>LOG_PID</literal> as well
+         so you can more easily match the error statement with the error
+         message.
+        </para>
+       </listitem>
+      </varlistentry>
+
+      <varlistentry>
        <term><varname>LOG_PID</varname> (<type>boolean</type>)</term>
        <listitem>
         <para>
***************
*** 1005,1012 ****
        <listitem>
         <para>
          Prints the duration of every completed query.  To use this option,
!         enable LOG_STATEMENT and LOG_PID so you can link the original query
!         to the duration using the process id.
         </para>
        </listitem>
       </varlistentry>
--- 1026,1033 ----
        <listitem>
         <para>
          Prints the duration of every completed query.  To use this option,
!         enable <literal>LOG_STATEMENT</> and <literal>LOG_PID</> so you
!         can link the original query to the duration using the process id.
         </para>
        </listitem>
       </varlistentry>
Index: src/backend/utils/error/elog.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/error/elog.c,v
retrieving revision 1.101
diff -c -c -r1.101 elog.c
*** src/backend/utils/error/elog.c    2 Sep 2002 02:47:05 -0000    1.101
--- src/backend/utils/error/elog.c    2 Sep 2002 05:35:51 -0000
***************
*** 33,49 ****
  #include "storage/proc.h"
  #include "tcop/tcopprot.h"
  #include "utils/memutils.h"

  #include "mb/pg_wchar.h"

- int            server_min_messages;
- char       *server_min_messages_str = NULL;
- const char    server_min_messages_str_default[] = "notice";
-
- int            client_min_messages;
- char       *client_min_messages_str = NULL;
- const char    client_min_messages_str_default[] = "notice";
-
  #ifdef HAVE_SYSLOG
  /*
   * 0 = only stdout/stderr
--- 33,42 ----
  #include "storage/proc.h"
  #include "tcop/tcopprot.h"
  #include "utils/memutils.h"
+ #include "utils/guc.h"

  #include "mb/pg_wchar.h"

  #ifdef HAVE_SYSLOG
  /*
   * 0 = only stdout/stderr
***************
*** 345,350 ****
--- 338,344 ----
          }
      }

+
      /*
       * Message prepared; send it where it should go
       */
***************
*** 433,438 ****
--- 427,440 ----
      if (msg_buf != msg_fixedbuf)
          free(msg_buf);

+     /* If the user wants this elog() generating query logged,
+      * do so. We only want to log if the query has been
+      * written to debug_query_string. Also, avoid infinite loops.
+      */
+
+     if(lev != LOG && lev >= log_min_error_statement && debug_query_string)
+         elog(LOG,"statement: %s",debug_query_string);
+
      /*
       * Perform error recovery action as specified by lev.
       */
***************
*** 835,905 ****
  }


- /*
-  * GUC support routines
-  */
- const char *
- assign_server_min_messages(const char *newval,
-                            bool doit, bool interactive)
- {
-     if (strcasecmp(newval, "debug") == 0)
-         { if (doit) server_min_messages = DEBUG1; }
-     else if (strcasecmp(newval, "debug5") == 0)
-         { if (doit) server_min_messages = DEBUG5; }
-     else if (strcasecmp(newval, "debug4") == 0)
-         { if (doit) server_min_messages = DEBUG4; }
-     else if (strcasecmp(newval, "debug3") == 0)
-         { if (doit) server_min_messages = DEBUG3; }
-     else if (strcasecmp(newval, "debug2") == 0)
-         { if (doit) server_min_messages = DEBUG2; }
-     else if (strcasecmp(newval, "debug1") == 0)
-         { if (doit) server_min_messages = DEBUG1; }
-     else if (strcasecmp(newval, "info") == 0)
-         { if (doit) server_min_messages = INFO; }
-     else if (strcasecmp(newval, "notice") == 0)
-         { if (doit) server_min_messages = NOTICE; }
-     else if (strcasecmp(newval, "warning") == 0)
-         { if (doit) server_min_messages = WARNING; }
-     else if (strcasecmp(newval, "error") == 0)
-         { if (doit) server_min_messages = ERROR; }
-     else if (strcasecmp(newval, "log") == 0)
-         { if (doit) server_min_messages = LOG; }
-     else if (strcasecmp(newval, "fatal") == 0)
-         { if (doit) server_min_messages = FATAL; }
-     else if (strcasecmp(newval, "panic") == 0)
-         { if (doit) server_min_messages = PANIC; }
-     else
-         return NULL;            /* fail */
-     return newval;                /* OK */
- }

- const char *
- assign_client_min_messages(const char *newval,
-                            bool doit, bool interactive)
- {
-     if (strcasecmp(newval, "debug") == 0)
-         { if (doit) client_min_messages = DEBUG1; }
-     else if (strcasecmp(newval, "debug5") == 0)
-         { if (doit) client_min_messages = DEBUG5; }
-     else if (strcasecmp(newval, "debug4") == 0)
-         { if (doit) client_min_messages = DEBUG4; }
-     else if (strcasecmp(newval, "debug3") == 0)
-         { if (doit) client_min_messages = DEBUG3; }
-     else if (strcasecmp(newval, "debug2") == 0)
-         { if (doit) client_min_messages = DEBUG2; }
-     else if (strcasecmp(newval, "debug1") == 0)
-         { if (doit) client_min_messages = DEBUG1; }
-     else if (strcasecmp(newval, "log") == 0)
-         { if (doit) client_min_messages = LOG; }
-     else if (strcasecmp(newval, "info") == 0)
-         { if (doit) client_min_messages = INFO; }
-     else if (strcasecmp(newval, "notice") == 0)
-         { if (doit) client_min_messages = NOTICE; }
-     else if (strcasecmp(newval, "warning") == 0)
-         { if (doit) client_min_messages = WARNING; }
-     else if (strcasecmp(newval, "error") == 0)
-         { if (doit) client_min_messages = ERROR; }
-     else
-         return NULL;            /* fail */
-     return newval;                /* OK */
- }
--- 837,840 ----
Index: src/backend/utils/misc/guc.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/misc/guc.c,v
retrieving revision 1.91
diff -c -c -r1.91 guc.c
*** src/backend/utils/misc/guc.c    2 Sep 2002 01:05:06 -0000    1.91
--- src/backend/utils/misc/guc.c    2 Sep 2002 05:35:59 -0000
***************
*** 71,76 ****
--- 71,79 ----
                                     bool doit, bool interactive);
  #endif

+ static const char *assign_msglvl(int *var, const char *newval,
+                                     bool doit, bool interactive);
+
  /*
   * Debugging options
   */
***************
*** 99,104 ****
--- 102,120 ----

  bool        Password_encryption = true;

+ int            log_min_error_statement;
+ char        *log_min_error_statement_str = NULL;
+ const char    log_min_error_statement_str_default[] = "error";
+
+ int         server_min_messages;
+ char       *server_min_messages_str = NULL;
+ const char  server_min_messages_str_default[] = "notice";
+
+ int         client_min_messages;
+ char       *client_min_messages_str = NULL;
+ const char  client_min_messages_str_default[] = "notice";
+
+
  #ifndef PG_KRB_SRVTAB
  #define PG_KRB_SRVTAB ""
  #endif
***************
*** 727,732 ****
--- 743,753 ----
      },

      {
+         { "log_min_error_statement", PGC_USERSET }, &log_min_error_statement_str,
+         log_min_error_statement_str_default, assign_min_error_statement, NULL
+     },
+
+     {
          { "DateStyle", PGC_USERSET, GUC_LIST_INPUT }, &datestyle_string,
          "ISO, US", assign_datestyle, show_datestyle
      },
***************
*** 2877,2879 ****
--- 2898,2951 ----

      return newarray;
  }
+
+ const char *
+ assign_server_min_messages(const char *newval,
+                            bool doit, bool interactive)
+ {
+     return(assign_msglvl(&server_min_messages,newval,doit,interactive));
+ }
+
+ const char *
+ assign_client_min_messages(const char *newval,
+                            bool doit, bool interactive)
+ {
+     return(assign_msglvl(&client_min_messages,newval,doit,interactive));
+ }
+
+ const char *
+ assign_min_error_statement(const char *newval, bool doit, bool interactive)
+ {
+     return(assign_msglvl(&log_min_error_statement,newval,doit,interactive));
+ }
+
+ static const char *
+ assign_msglvl(int *var, const char *newval, bool doit, bool interactive)
+ {
+     if (strcasecmp(newval, "debug") == 0)
+         { if (doit) (*var) = DEBUG1; }
+     else if (strcasecmp(newval, "debug5") == 0)
+         { if (doit) (*var) = DEBUG5; }
+     else if (strcasecmp(newval, "debug4") == 0)
+         { if (doit) (*var) = DEBUG4; }
+     else if (strcasecmp(newval, "debug3") == 0)
+         { if (doit) (*var) = DEBUG3; }
+     else if (strcasecmp(newval, "debug2") == 0)
+         { if (doit) (*var) = DEBUG2; }
+     else if (strcasecmp(newval, "debug1") == 0)
+         { if (doit) (*var) = DEBUG1; }
+     else if (strcasecmp(newval, "log") == 0)
+         { if (doit) (*var) = LOG; }
+     else if (strcasecmp(newval, "info") == 0)
+         { if (doit) (*var) = INFO; }
+     else if (strcasecmp(newval, "notice") == 0)
+         { if (doit) (*var) = NOTICE; }
+     else if (strcasecmp(newval, "warning") == 0)
+         { if (doit) (*var) = WARNING; }
+     else if (strcasecmp(newval, "error") == 0)
+         { if (doit) (*var) = ERROR; }
+     else
+         return NULL;            /* fail */
+     return newval;                /* OK */
+ }
+
Index: src/backend/utils/misc/postgresql.conf.sample
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/misc/postgresql.conf.sample,v
retrieving revision 1.51
diff -c -c -r1.51 postgresql.conf.sample
*** src/backend/utils/misc/postgresql.conf.sample    1 Sep 2002 23:26:06 -0000    1.51
--- src/backend/utils/misc/postgresql.conf.sample    2 Sep 2002 05:36:00 -0000
***************
*** 127,132 ****
--- 127,135 ----
  #log_duration = false
  #log_timestamp = false

+ #log_min_error_statement = error        # Values in order of increasing severity:
+                                     # debug5, debug4, debug3, debug2, debug1,
+                                     # info, notice, warning, error
  #debug_print_parse = false
  #debug_print_rewritten = false
  #debug_print_plan = false
Index: src/bin/psql/tab-complete.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/bin/psql/tab-complete.c,v
retrieving revision 1.61
diff -c -c -r1.61 tab-complete.c
*** src/bin/psql/tab-complete.c    1 Sep 2002 23:26:06 -0000    1.61
--- src/bin/psql/tab-complete.c    2 Sep 2002 05:36:05 -0000
***************
*** 271,277 ****
          "default_transaction_isolation",
          "search_path",
          "statement_timeout",
!
          NULL
      };

--- 271,277 ----
          "default_transaction_isolation",
          "search_path",
          "statement_timeout",
!         "log_min_error_statement",
          NULL
      };

Index: src/include/utils/elog.h
===================================================================
RCS file: /cvsroot/pgsql-server/src/include/utils/elog.h,v
retrieving revision 1.38
diff -c -c -r1.38 elog.h
*** src/include/utils/elog.h    20 Jun 2002 20:29:52 -0000    1.38
--- src/include/utils/elog.h    2 Sep 2002 05:36:06 -0000
***************
*** 47,68 ****
  extern bool Log_timestamp;
  extern bool Log_pid;

- extern char       *server_min_messages_str;
- extern char       *client_min_messages_str;
- extern const char server_min_messages_str_default[];
- extern const char client_min_messages_str_default[];
-
  extern void
  elog(int lev, const char *fmt,...)
  /* This extension allows gcc to check the format string for consistency with
     the supplied arguments. */
  __attribute__((format(printf, 2, 3)));

! extern int    DebugFileOpen(void);
!
! extern const char *assign_server_min_messages(const char *newval,
!                                               bool doit, bool interactive);
! extern const char *assign_client_min_messages(const char *newval,
!                                               bool doit, bool interactive);

  #endif   /* ELOG_H */
--- 47,58 ----
  extern bool Log_timestamp;
  extern bool Log_pid;

  extern void
  elog(int lev, const char *fmt,...)
  /* This extension allows gcc to check the format string for consistency with
     the supplied arguments. */
  __attribute__((format(printf, 2, 3)));

! extern int  DebugFileOpen(void);

  #endif   /* ELOG_H */
Index: src/include/utils/guc.h
===================================================================
RCS file: /cvsroot/pgsql-server/src/include/utils/guc.h,v
retrieving revision 1.21
diff -c -c -r1.21 guc.h
*** src/include/utils/guc.h    1 Sep 2002 23:26:06 -0000    1.21
--- src/include/utils/guc.h    2 Sep 2002 05:36:07 -0000
***************
*** 100,105 ****
--- 100,112 ----
  extern ArrayType *GUCArrayAdd(ArrayType *array, const char *name, const char *value);
  extern ArrayType *GUCArrayDelete(ArrayType *array, const char *name);

+ extern const char *assign_min_error_statement(const char *newval, bool doit,
+             bool interactive);
+
+ extern const char *assign_server_min_messages(const char *newval,
+                                               bool doit, bool interactive);
+ extern const char *assign_client_min_messages(const char *newval,
+                                               bool doit, bool interactive);
  extern bool Log_statement;
  extern bool Log_duration;
  extern bool Debug_print_plan;
***************
*** 117,121 ****
--- 124,143 ----

  extern bool SQL_inheritance;
  extern bool Australian_timezones;
+
+ extern char *debug_query_string;
+
+ extern int    log_min_error_statement;
+ extern char *log_min_error_statement_str;
+ extern const char log_min_error_statement_str_default[];
+
+ extern int    server_min_messages;
+ extern char    *server_min_messages_str;
+ extern const char server_min_messages_str_default[];
+
+ extern int client_min_messages;
+ extern char    *client_min_messages_str;
+
+ extern const char client_min_messages_str_default[];

  #endif   /* GUC_H */