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.

Author: tglsfdc

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.

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>
 

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

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)

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

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