From a1ce88a59c05ac63c92f36c219f714e5552e9ba3 Mon Sep 17 00:00:00 2001
From: Bruce Momjian <bruce@momjian.us>
Date: Fri, 15 Oct 2004 16:50:31 +0000
Subject: [PATCH] Have log_duration only output when log_statement has printed
 the query. This handles the new multiple log_statement values.

Ed L.
---
 doc/src/sgml/runtime.sgml   | 17 +++++++++--------
 src/backend/tcop/postgres.c | 14 ++++++++++++--
 2 files changed, 21 insertions(+), 10 deletions(-)

diff --git a/doc/src/sgml/runtime.sgml b/doc/src/sgml/runtime.sgml
index da1d074547..f82fbc877d 100644
--- a/doc/src/sgml/runtime.sgml
+++ b/doc/src/sgml/runtime.sgml
@@ -1,5 +1,5 @@
 <!--
-$PostgreSQL: pgsql/doc/src/sgml/runtime.sgml,v 1.287 2004/10/09 23:12:53 tgl Exp $
+$PostgreSQL: pgsql/doc/src/sgml/runtime.sgml,v 1.288 2004/10/15 16:50:29 momjian Exp $
 -->
 
 <Chapter Id="runtime">
@@ -2355,13 +2355,14 @@ archive_command = 'copy "%p" /mnt/server/archivedir/"%f"'  # Win32
       <term><varname>log_duration</varname> (<type>boolean</type>)</term>
       <listitem>
        <para>
-        Causes the duration of every completed statement to be logged.
-        To use this option, it is recommended that you also enable
-        <varname>log_statement</> and if not using <application>syslog</>
-        log the PID using <varname>log_line_prefix</> so that you
-        can link the statement to the duration using the process
-        ID. The default is off.  Only superusers can turn off this
-        option if it is enabled by the administrator.
+        Causes the duration of every completed statement which satisfies
+        <varname>log_statement</> to be logged.  When using this option, 
+        if you are not using <application>syslog</>, it is recommended 
+        that you log the PID or session ID using <varname>log_line_prefix</> 
+        or log the session ID so that you can link the statement to the 
+        duration using the process ID or session ID. The default is off.  
+        Only superusers can turn off this option if it is enabled by the 
+        administrator.
        </para>
       </listitem>
      </varlistentry>
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 9f4e8b06ba..b9abf0d6b6 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.435 2004/10/12 21:54:40 petere Exp $
+ *	  $PostgreSQL: pgsql/src/backend/tcop/postgres.c,v 1.436 2004/10/15 16:50:31 momjian Exp $
  *
  * NOTES
  *	  this is the "main" module of the postgres backend and
@@ -81,6 +81,9 @@ bool		Log_disconnections = false;
 
 LogStmtLevel log_statement = LOGSTMT_NONE;
 
+/* flag indicating if the statement satisfies log_statement */
+bool		statement_logged;
+
 /* GUC variable for maximum stack depth (measured in kilobytes) */
 int			max_stack_depth = 2048;
 
@@ -463,9 +466,13 @@ pg_parse_query(const char *query_string)
 	List	   *raw_parsetree_list;
 	ListCell   *parsetree_item;
 
+	statement_logged = false;
 	if (log_statement == LOGSTMT_ALL)
+	{
 		ereport(LOG,
 				(errmsg("statement: %s", query_string)));
+		statement_logged = true;
+	}
 
 	if (log_parser_stats)
 		ResetUsage();
@@ -501,6 +508,7 @@ pg_parse_query(const char *query_string)
 			{
 				ereport(LOG,
 						(errmsg("statement: %s", query_string)));
+				statement_logged = true;
 				break;
 			}
 			commandTag = CreateCommandTag(parsetree);
@@ -512,6 +520,7 @@ pg_parse_query(const char *query_string)
 			{
 				ereport(LOG,
 						(errmsg("statement: %s", query_string)));
+				statement_logged = true;
 				break;
 			}
 		}
@@ -1003,7 +1012,8 @@ exec_simple_query(const char *query_string)
 		}
 		usecs = (long) (stop_t.tv_sec - start_t.tv_sec) * 1000000 + (long) (stop_t.tv_usec - start_t.tv_usec);
 
-		if (save_log_duration)
+		/* Only print duration if we previously printed the statement. */
+		if (statement_logged && save_log_duration)
 			ereport(LOG,
 					(errmsg("duration: %ld.%03ld ms",
 						(long) ((stop_t.tv_sec - start_t.tv_sec) * 1000 +