Make log_min_error_statement put LOG level at the same priority as

log_min_messages does; and arrange to suppress the duplicative output
that would otherwise result from log_statement and log_duration messages.
Bruce Momjian and Tom Lane.

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index bbddbe59039d09d3fa87ee2e06ce563f41c52266..d3f09f6376948fc61cb05e8b026eb69078cfb916 100644 (file)
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -1,4 +1,4 @@
-<!-- $PostgreSQL: pgsql/doc/src/sgml/config.sgml,v 1.112 2007/02/16 16:37:29 tgl Exp $ -->
+<!-- $PostgreSQL: pgsql/doc/src/sgml/config.sgml,v 1.113 2007/03/02 23:37:22 tgl Exp $ -->
 
 <chapter Id="runtime-config">
   <title>Server Configuration</title>
@@ -2507,9 +2507,10 @@ SELECT * FROM parent WHERE key = 2400;
         <literal>DEBUG2</literal>, <literal>DEBUG1</literal>,
         <literal>INFO</literal>, <literal>NOTICE</literal>,
         <literal>WARNING</literal>, <literal>ERROR</literal>,
+        <literal>LOG</literal>,
         <literal>FATAL</literal>, and <literal>PANIC</literal>.
         The default is <literal>ERROR</literal>, which means statements
-        causing errors, fatal errors, or panics will be logged.
+        causing errors, log messages, fatal errors, or panics will be logged.
         To effectively turn off logging of failing statements,
         set this parameter to <literal>PANIC</literal>.
         Only superusers can change this setting.

diff --git a/doc/src/sgml/sources.sgml b/doc/src/sgml/sources.sgml
index 873ba6b2f257f1d0ae84400c27e700a403cbbb9d..5d9043a16a7b72ce008e4d66b2981a01d9dd5b15 100644 (file)
--- a/doc/src/sgml/sources.sgml
+++ b/doc/src/sgml/sources.sgml
@@ -1,4 +1,4 @@
-<!-- $PostgreSQL: pgsql/doc/src/sgml/sources.sgml,v 2.27 2007/02/01 22:06:14 tgl Exp $ -->
+<!-- $PostgreSQL: pgsql/doc/src/sgml/sources.sgml,v 2.28 2007/03/02 23:37:22 tgl Exp $ -->
 
  <chapter id="source">
   <title>PostgreSQL Coding Conventions</title>
@@ -206,6 +206,14 @@ ereport(ERROR,
      socket-related system call.
     </para>
    </listitem>
+   <listitem>
+    <para>
+     <function>errhidestmt(bool hide_stmt)</function> can be called to specify
+     suppression of the <literal>STATEMENT:</> portion of a message in the
+     postmaster log.  Generally this is appropriate if the message text
+     includes the current statement already.
+    </para>
+   </listitem>
   </itemizedlist>
    </para>
 

diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 1c40a8752e953e34e2f23924b679676ebf4bbacf..afb6b4db0a1e8ffbe7bceb973da8e14351bdf9f3 100644 (file)
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/tcop/postgres.c,v 1.525 2007/02/20 17:32:16 tgl Exp $
+ *   $PostgreSQL: pgsql/src/backend/tcop/postgres.c,v 1.526 2007/03/02 23:37:22 tgl Exp $
  *
  * NOTES
  *   this is the "main" module of the postgres backend and
@@ -823,6 +823,7 @@ exec_simple_query(const char *query_string)
    {
        ereport(LOG,
                (errmsg("statement: %s", query_string),
+                errhidestmt(true),
                 errdetail_execute(parsetree_list)));
        was_logged = true;
    }
@@ -1020,12 +1021,14 @@ exec_simple_query(const char *query_string)
    {
        case 1:
            ereport(LOG,
-                   (errmsg("duration: %s ms", msec_str)));
+                   (errmsg("duration: %s ms", msec_str),
+                    errhidestmt(true)));
            break;
        case 2:
            ereport(LOG,
                    (errmsg("duration: %s ms  statement: %s",
                            msec_str, query_string),
+                    errhidestmt(true),
                     errdetail_execute(parsetree_list)));
            break;
    }
@@ -1281,14 +1284,16 @@ exec_parse_message(const char *query_string,    /* string to execute */
    {
        case 1:
            ereport(LOG,
-                   (errmsg("duration: %s ms", msec_str)));
+                   (errmsg("duration: %s ms", msec_str),
+                    errhidestmt(true)));
            break;
        case 2:
            ereport(LOG,
                    (errmsg("duration: %s ms  parse %s: %s",
                            msec_str,
                            *stmt_name ? stmt_name : "<unnamed>",
-                           query_string)));
+                           query_string),
+                    errhidestmt(true)));
            break;
    }
 
@@ -1635,7 +1640,8 @@ exec_bind_message(StringInfo input_message)
    {
        case 1:
            ereport(LOG,
-                   (errmsg("duration: %s ms", msec_str)));
+                   (errmsg("duration: %s ms", msec_str),
+                    errhidestmt(true)));
            break;
        case 2:
            ereport(LOG,
@@ -1645,6 +1651,7 @@ exec_bind_message(StringInfo input_message)
                            *portal_name ? "/" : "",
                            *portal_name ? portal_name : "",
                            pstmt->query_string ? pstmt->query_string : "<source not stored>"),
+                    errhidestmt(true),
                     errdetail_params(params)));
            break;
    }
@@ -1778,6 +1785,7 @@ exec_execute_message(const char *portal_name, long max_rows)
                        *portal_name ? portal_name : "",
                        sourceText ? ": " : "",
                        sourceText ? sourceText : ""),
+                errhidestmt(true),
                 errdetail_params(portalParams)));
        was_logged = true;
    }
@@ -1846,7 +1854,8 @@ exec_execute_message(const char *portal_name, long max_rows)
    {
        case 1:
            ereport(LOG,
-                   (errmsg("duration: %s ms", msec_str)));
+                   (errmsg("duration: %s ms", msec_str),
+                    errhidestmt(true)));
            break;
        case 2:
            ereport(LOG,
@@ -1860,6 +1869,7 @@ exec_execute_message(const char *portal_name, long max_rows)
                            *portal_name ? portal_name : "",
                            sourceText ? ": " : "",
                            sourceText ? sourceText : ""),
+                    errhidestmt(true),
                     errdetail_params(portalParams)));
            break;
    }

diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index 3700c4ecdc08741e1777b0d6ad3d5c3e78fe0f47..c76d817bb1464c122a99696ea5853867e6622406 100644 (file)
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -42,7 +42,7 @@
  *
  *
  * IDENTIFICATION
- *   $PostgreSQL: pgsql/src/backend/utils/error/elog.c,v 1.182 2007/02/11 11:59:26 mha Exp $
+ *   $PostgreSQL: pgsql/src/backend/utils/error/elog.c,v 1.183 2007/03/02 23:37:23 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -731,6 +731,25 @@ errcontext(const char *fmt,...)
 }
 
 
+/*
+ * errhidestmt --- optionally suppress STATEMENT: field of log entry
+ *
+ * This should be called if the message text already includes the statement.
+ */
+int
+errhidestmt(bool hide_stmt)
+{
+   ErrorData  *edata = &errordata[errordata_stack_depth];
+
+   /* we don't bother incrementing recursion_depth */
+   CHECK_STACK_DEPTH();
+
+   edata->hide_stmt = hide_stmt;
+
+   return 0;                   /* return value does not matter */
+}
+
+
 /*
  * errfunction --- add reporting function name to the current error
  *
@@ -1629,7 +1648,9 @@ send_message_to_server_log(ErrorData *edata)
    /*
     * If the user wants the query that generated this error logged, do it.
     */
-   if (edata->elevel >= log_min_error_statement && debug_query_string != NULL)
+   if (is_log_level_output(edata->elevel, log_min_error_statement) &&
+       debug_query_string != NULL &&
+       !edata->hide_stmt)
    {
        log_line_prefix(&buf);
        appendStringInfoString(&buf, _("STATEMENT:  "));
@@ -2046,7 +2067,7 @@ write_stderr(const char *fmt,...)
 
        vsnprintf(errbuf, sizeof(errbuf), fmt, ap);
 
-       write_eventlog(EVENTLOG_ERROR_TYPE, errbuf);
+       write_eventlog(ERROR, errbuf);
    }
    else
        /* Not running as service, write to stderr */
@@ -2055,13 +2076,18 @@ write_stderr(const char *fmt,...)
    va_end(ap);
 }
 
+
+/*
+ * is_log_level_output -- is elevel logically >= log_min_level?
+ *
+ * We use this for tests that should consider LOG to sort out-of-order,
+ * between ERROR and FATAL.  Generally this is the right thing for testing
+ * whether a message should go to the postmaster log, whereas a simple >=
+ * test is correct for testing whether the message should go to the client.
+ */
 static bool
 is_log_level_output(int elevel, int log_min_level)
 {
-   /*
-    *  Complicated because LOG is sorted out-of-order here, between
-    *  ERROR and FATAL.
-    */
    if (elevel == LOG || elevel == COMMERROR)
    {
        if (log_min_level == LOG || log_min_level <= ERROR)

diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample
index 703f5cbaa3324b01fae40dd6d8ffa35cf712fc62..77a86f0020b3b5551cb7c0a5aa61c46c23ffbb70 100644 (file)
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -262,7 +262,7 @@
 
 # - When to Log -
 
-#client_min_messages = notice      # Values, in order of decreasing detail:
+#client_min_messages = notice      # Values in order of decreasing detail:
                    #   debug5
                    #   debug4
                    #   debug3
@@ -273,7 +273,7 @@
                    #   warning
                    #   error
 
-#log_min_messages = notice     # Values, in order of decreasing detail:
+#log_min_messages = notice     # Values in order of decreasing detail:
                    #   debug5
                    #   debug4
                    #   debug3
@@ -289,7 +289,7 @@
 
 #log_error_verbosity = default     # terse, default, or verbose messages
 
-#log_min_error_statement = error   # Values in order of increasing severity:
+#log_min_error_statement = error   # Values in order of decreasing detail:
                    #   debug5
                    #   debug4
                    #   debug3
@@ -299,11 +299,14 @@
                    #   notice
                    #   warning
                    #   error
+                   #   log
                    #   fatal
                    #   panic (effectively off)
 
 #log_min_duration_statement = -1   # -1 is disabled, 0 logs all statements
-                   # and their durations.
+                   # and their durations, > 0 logs only
+                   # statements running at least N msec.
+
 
 #silent_mode = off         # DO NOT USE without syslog or 
                    # redirect_stderr

diff --git a/src/include/utils/elog.h b/src/include/utils/elog.h
index 8d835d30ef5c8bf5e148a3a9754145a14efb5d48..86fd4deb9eab74a5a5481ca3a0decd6d122784f4 100644 (file)
--- a/src/include/utils/elog.h
+++ b/src/include/utils/elog.h
@@ -7,7 +7,7 @@
  * Portions Copyright (c) 1996-2007, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/include/utils/elog.h,v 1.83 2007/01/05 22:19:59 momjian Exp $
+ * $PostgreSQL: pgsql/src/include/utils/elog.h,v 1.84 2007/03/02 23:37:23 tgl Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -137,6 +137,8 @@ errcontext(const char *fmt,...)
    the supplied arguments. */
 __attribute__((format(printf, 1, 2)));
 
+extern int errhidestmt(bool hide_stmt);
+
 extern int errfunction(const char *funcname);
 extern int errposition(int cursorpos);
 
@@ -240,6 +242,7 @@ typedef struct ErrorData
    bool        output_to_server;       /* will report to server log? */
    bool        output_to_client;       /* will report to client? */
    bool        show_funcname;  /* true to force funcname inclusion */
+   bool        hide_stmt;      /* true to prevent STATEMENT: inclusion */
    const char *filename;       /* __FILE__ of ereport() call */
    int         lineno;         /* __LINE__ of ereport() call */
    const char *funcname;       /* __func__ of ereport() call */