dbTalk Databases Forums  

Re: [BUGS] [martin@bugs.unl.edu.ar: BUG in logs]

mailing.database.pgsql-bugs mailing.database.pgsql-bugs


Discuss Re: [BUGS] [martin@bugs.unl.edu.ar: BUG in logs] in the mailing.database.pgsql-bugs forum.



Reply
 
Thread Tools Display Modes
  #1  
Old   
Martin Marques
 
Posts: n/a

Default Re: [BUGS] [martin@bugs.unl.edu.ar: BUG in logs] - 04-13-2006 , 08:59 AM







OK, you're right about the log_min_error_statement value, but this behaviour has changed from 8.0. In earlier versions ERROR statements did get logged if log_statment was set to all or in 7.4, set to "on" DMaybe I missed something in the changelog of 8.1?

On Tue, 11 Apr 2006 23:51:51 +0200, "Guillaume Smet" <guillaume.smet (AT) gmail (DOT) com> wrote:
Quote:
From: Martin Marques <martin (AT) bugs (DOT) unl.edu.ar
I encountered a rare BUG in the way PG is logging. Let me first enlight
with some configuration I have and PG version:

Perhaps I'm missing something but I think it's not a bug but a
configuration problem.

log_min_error_statement | panic

If you set this one to error instead of panic, you will have your
failed statements logged.

log_statement | all

This one only logs successful queries so it's normal you don't have
the statement in the log file if it fails.

Regards,


--
---------------------------------------------------------
Lic. MartÃ*n Marqués | SELECT 'mmarques' ||
Centro de Telemática | '@' || 'unl.edu.ar';
Universidad Nacional | DBA, Programador,
del Litoral | Administrador
---------------------------------------------------------



---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match


Reply With Quote
  #2  
Old   
Bruce Momjian
 
Posts: n/a

Default Re: [BUGS] [martin@bugs.unl.edu.ar: BUG in logs] - 04-17-2006 , 07:53 PM






--ELM1145321550-993-0_
Content-Transfer-Encoding: 7bit
Content-Type: text/plain; charset=US-ASCII


I have looked at this behavior, which indeed is new for 8.1. The change
was caused by code I think I did to improve the behavior of
log_statement, specifically streamlining how we check for the type of
command.

In looking at reverting to the 8.0 behavior of logging error commands
with 'all', I see it is going to be hard to do, specifically since we
added behavior of logging the PREPARE query when EXECUTE is sent. I
don't think we want to lose that feature, and to have it we have to
first parse the statement, with possible exit on error.

What I have done is to document that errors are not output by
log_statement, and added as suggestion to use log_min_error_statement
for this purpose. I also fixed the code so the first EXECUTE has it's
prepare, rather than the last which is what was in the current code.

I also removed the "protocol" prefix from the PREPARE output, because in
fact both protocol and SQL-level prepares can be executed by SQL
EXECUTE.

Patch attached. I have backpatched this to 8.1.X.

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

Martin Marques wrote:
Quote:
OK, you're right about the log_min_error_statement value, but this behaviour has changed from 8.0. In earlier versions ERROR statements did get logged if log_statment was set to all or in 7.4, set to "on" DMaybe I missed something in the changelog of 8.1?

On Tue, 11 Apr 2006 23:51:51 +0200, "Guillaume Smet" <guillaume.smet (AT) gmail (DOT) com> wrote:
From: Martin Marques <martin (AT) bugs (DOT) unl.edu.ar
I encountered a rare BUG in the way PG is logging. Let me first enlight
with some configuration I have and PG version:

Perhaps I'm missing something but I think it's not a bug but a
configuration problem.

log_min_error_statement | panic

If you set this one to error instead of panic, you will have your
failed statements logged.

log_statement | all

This one only logs successful queries so it's normal you don't have
the statement in the log file if it fails.

Regards,


--
---------------------------------------------------------
Lic. Mart?n Marqu?s | SELECT 'mmarques' ||
Centro de Telem?tica | '@' || 'unl.edu.ar';
Universidad Nacional | DBA, Programador,
del Litoral | Administrador
---------------------------------------------------------



---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match

--
Bruce Momjian http://candle.pha.pa.us
EnterpriseDB http://www.enterprisedb.com

+ If your life is a hard drive, Christ can be your backup. +

--ELM1145321550-993-0_
Content-Transfer-Encoding: 7bit
Content-Type: text/plain
Content-Disposition: inline; filename="/bjm/diff"

Index: doc/src/sgml/config.sgml
================================================== =================
RCS file: /cvsroot/pgsql/doc/src/sgml/config.sgml,v
retrieving revision 1.52
diff -c -c -r1.52 config.sgml
*** doc/src/sgml/config.sgml 10 Mar 2006 19:10:47 -0000 1.52
--- doc/src/sgml/config.sgml 18 Apr 2006 00:35:12 -0000
***************
*** 2758,2766 ****
<note>
<para>
The <command>EXECUTE</command> statement is not considered a
! <literal>ddl</> or <literal>mod</> statement. When it is logged,
! only the name of the prepared statement is reported, not the
! actual prepared statement.
</para>

<para>
--- 2758,2767 ----
<note>
<para>
The <command>EXECUTE</command> statement is not considered a
! <literal>ddl</> or <literal>mod</> statement. Statements that
! generate errors are not logged. Set
! <varname>log_min_error_statement</> to <literal>error</> to
! log such statements.
</para>

<para>
Index: src/backend/tcop/postgres.c
================================================== =================
RCS file: /cvsroot/pgsql/src/backend/tcop/postgres.c,v
retrieving revision 1.483
diff -c -c -r1.483 postgres.c
*** src/backend/tcop/postgres.c 4 Apr 2006 19:35:35 -0000 1.483
--- src/backend/tcop/postgres.c 18 Apr 2006 00:35:21 -0000
***************
*** 586,604 ****

/*
* For the first EXECUTE we find, record the client statement used by
! * the PREPARE.
*/
if (IsA(parsetree, ExecuteStmt))
{
ExecuteStmt *stmt = (ExecuteStmt *) parsetree;
PreparedStatement *entry;

! if ((entry = FetchPreparedStatement(stmt->name, false)) != NULL &&
entry->query_string)
{
*prepare_string = palloc(strlen(entry->query_string) +
! strlen(" [protocol PREPARE: %s]") - 1);
! sprintf(*prepare_string, " [protocol PREPARE: %s]",
entry->query_string);
}
}
--- 586,606 ----

/*
* For the first EXECUTE we find, record the client statement used by
! * the PREPARE. PREPARE doesn't save the parse tree so we have no
! * way to conditionally output based on the type of query prepared.
*/
if (IsA(parsetree, ExecuteStmt))
{
ExecuteStmt *stmt = (ExecuteStmt *) parsetree;
PreparedStatement *entry;

! if (*prepare_string == NULL &&
! (entry = FetchPreparedStatement(stmt->name, false)) != NULL &&
entry->query_string)
{
*prepare_string = palloc(strlen(entry->query_string) +
! strlen(" [PREPARE: %s]") - 2 + 1);
! sprintf(*prepare_string, " [PREPARE: %s]",
entry->query_string);
}
}

--ELM1145321550-993-0_
Content-Type: text/plain
Content-Disposition: inline
Content-Transfer-Encoding: 8bit
MIME-Version: 1.0


---------------------------(end of broadcast)---------------------------
TIP 3: Have you checked our extensive FAQ?

http://www.postgresql.org/docs/faq

--ELM1145321550-993-0_--


Reply With Quote
  #3  
Old   
Bruce Momjian
 
Posts: n/a

Default Re: [BUGS] [martin@bugs.unl.edu.ar: BUG in logs] - 04-18-2006 , 07:40 AM




I have now realized another complexity. It is only _syntax_ errors that
are not logged via log_statement, not queries that generate other errors
during execution. I have updated the documentation to mention "syntax
error", but it does make log_min_error_statement sub-optimal because if
log_min_error_statement and log_statement are both on, you get two lines
for the same query of the query generates a non-syntax error. Yuck, but
I can see no better solution.

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

pgman wrote:
Quote:
I have looked at this behavior, which indeed is new for 8.1. The change
was caused by code I think I did to improve the behavior of
log_statement, specifically streamlining how we check for the type of
command.

In looking at reverting to the 8.0 behavior of logging error commands
with 'all', I see it is going to be hard to do, specifically since we
added behavior of logging the PREPARE query when EXECUTE is sent. I
don't think we want to lose that feature, and to have it we have to
first parse the statement, with possible exit on error.

What I have done is to document that errors are not output by
log_statement, and added as suggestion to use log_min_error_statement
for this purpose. I also fixed the code so the first EXECUTE has it's
prepare, rather than the last which is what was in the current code.

I also removed the "protocol" prefix from the PREPARE output, because in
fact both protocol and SQL-level prepares can be executed by SQL
EXECUTE.

Patch attached. I have backpatched this to 8.1.X.

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

Martin Marques wrote:

OK, you're right about the log_min_error_statement value, but this behaviour has changed from 8.0. In earlier versions ERROR statements did get logged if log_statment was set to all or in 7.4, set to "on" DMaybe I missed something in the changelog of 8.1?

On Tue, 11 Apr 2006 23:51:51 +0200, "Guillaume Smet" <guillaume.smet (AT) gmail (DOT) com> wrote:
From: Martin Marques <martin (AT) bugs (DOT) unl.edu.ar
I encountered a rare BUG in the way PG is logging. Let me first enlight
with some configuration I have and PG version:

Perhaps I'm missing something but I think it's not a bug but a
configuration problem.

log_min_error_statement | panic

If you set this one to error instead of panic, you will have your
failed statements logged.

log_statement | all

This one only logs successful queries so it's normal you don't have
the statement in the log file if it fails.

Regards,


--
---------------------------------------------------------
Lic. Mart?n Marqu?s | SELECT 'mmarques' ||
Centro de Telem?tica | '@' || 'unl.edu.ar';
Universidad Nacional | DBA, Programador,
del Litoral | Administrador
---------------------------------------------------------



---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match


--
Bruce Momjian http://candle.pha.pa.us
EnterpriseDB http://www.enterprisedb.com

+ If your life is a hard drive, Christ can be your backup. +

Index: doc/src/sgml/config.sgml
================================================== =================
RCS file: /cvsroot/pgsql/doc/src/sgml/config.sgml,v
retrieving revision 1.52
diff -c -c -r1.52 config.sgml
*** doc/src/sgml/config.sgml 10 Mar 2006 19:10:47 -0000 1.52
--- doc/src/sgml/config.sgml 18 Apr 2006 00:35:12 -0000
***************
*** 2758,2766 ****
note
para
The <command>EXECUTE</command> statement is not considered a
! <literal>ddl</> or <literal>mod</> statement. When it is logged,
! only the name of the prepared statement is reported, not the
! actual prepared statement.
/para

para
--- 2758,2767 ----
note
para
The <command>EXECUTE</command> statement is not considered a
! <literal>ddl</> or <literal>mod</> statement. Statements that
! generate errors are not logged. Set
! <varname>log_min_error_statement</> to <literal>error</> to
! log such statements.
/para

para
Index: src/backend/tcop/postgres.c
================================================== =================
RCS file: /cvsroot/pgsql/src/backend/tcop/postgres.c,v
retrieving revision 1.483
diff -c -c -r1.483 postgres.c
*** src/backend/tcop/postgres.c 4 Apr 2006 19:35:35 -0000 1.483
--- src/backend/tcop/postgres.c 18 Apr 2006 00:35:21 -0000
***************
*** 586,604 ****

/*
* For the first EXECUTE we find, record the client statement used by
! * the PREPARE.
*/
if (IsA(parsetree, ExecuteStmt))
{
ExecuteStmt *stmt = (ExecuteStmt *) parsetree;
PreparedStatement *entry;

! if ((entry = FetchPreparedStatement(stmt->name, false)) != NULL &&
entry->query_string)
{
*prepare_string = palloc(strlen(entry->query_string) +
! strlen(" [protocol PREPARE: %s]") - 1);
! sprintf(*prepare_string, " [protocol PREPARE: %s]",
entry->query_string);
}
}
--- 586,606 ----

/*
* For the first EXECUTE we find, record the client statement used by
! * the PREPARE. PREPARE doesn't save the parse tree so we have no
! * way to conditionally output based on the type of query prepared.
*/
if (IsA(parsetree, ExecuteStmt))
{
ExecuteStmt *stmt = (ExecuteStmt *) parsetree;
PreparedStatement *entry;

! if (*prepare_string == NULL &&
! (entry = FetchPreparedStatement(stmt->name, false)) != NULL &&
entry->query_string)
{
*prepare_string = palloc(strlen(entry->query_string) +
! strlen(" [PREPARE: %s]") - 2 + 1);
! sprintf(*prepare_string, " [PREPARE: %s]",
entry->query_string);
}
}
--
Bruce Momjian http://candle.pha.pa.us
EnterpriseDB http://www.enterprisedb.com

+ If your life is a hard drive, Christ can be your backup. +

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


Reply With Quote
Reply




Thread Tools
Display Modes

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

vB code is On
Smilies are On
[IMG] code is On
HTML code is Off



Powered by vBulletin Version 3.5.3
Copyright ©2000 - 2012, Jelsoft Enterprises Ltd.