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.

4 files changed, 60 insertions, 18 deletions

diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 1c40a8752e9..afb6b4db0a1 100644
--- 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 3700c4ecdc0..c76d817bb14 100644
--- 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 $
  *
  *-------------------------------------------------------------------------
  */
@@ -732,6 +732,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
  *
  * This is used when backwards compatibility demands that the function
@@ -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 703f5cbaa33..77a86f0020b 100644
--- 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 8d835d30ef5..86fd4deb9ea 100644
--- 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 */