Add log_duration to GUC/postgresql.conf.

Rename debug_print_query to log_statement and rename show_query_stats to
show_statement_stats.

Author: bmomjian

doc/src/sgml/func.sgml

@@ -1,5 +1,5 @@
 <!--
-$Header: /cvsroot/pgsql/doc/src/sgml/func.sgml,v 1.118 2002/08/29 05:17:55 tgl Exp $
+$Header: /cvsroot/pgsql/doc/src/sgml/func.sgml,v 1.119 2002/09/01 23:26:05 momjian Exp $
 PostgreSQL documentation
 -->
 
@@ -5241,7 +5241,7 @@ select current_setting('DateStyle');
     <literal>false</literal> instead. It is the equivalent to the SQL
     <command>SET</command> command. For example:
 <programlisting>
-select set_config('show_query_stats','off','f');
+select set_config('show_statement_stats','off','f');
  set_config
 ------------
  off

doc/src/sgml/runtime.sgml

@@ -1,5 +1,5 @@
 <!--
-$Header: /cvsroot/pgsql/doc/src/sgml/runtime.sgml,v 1.131 2002/08/30 22:18:05 tgl Exp $
+$Header: /cvsroot/pgsql/doc/src/sgml/runtime.sgml,v 1.132 2002/09/01 23:26:06 momjian Exp $
 -->
 
 <Chapter Id="runtime">
@@ -928,7 +928,6 @@ env PGOPTIONS='-c geqo=off' psql
      </varlistentry>
 
      <varlistentry>
-      <term><varname>DEBUG_PRINT_QUERY</varname> (<type>boolean</type>)</term>
       <term><varname>DEBUG_PRINT_PARSE</varname> (<type>boolean</type>)</term>
       <term><varname>DEBUG_PRINT_REWRITTEN</varname> (<type>boolean</type>)</term>
       <term><varname>DEBUG_PRINT_PLAN</varname> (<type>boolean</type>)</term>
@@ -992,6 +991,26 @@ env PGOPTIONS='-c geqo=off' psql
       </listitem>
      </varlistentry>
 
+     <varlistentry>
+      <term><varname>LOG_STATEMENT</varname> (<type>boolean</type>)</term>
+      <listitem>
+       <para>
+        Prints each query received.
+       </para>
+      </listitem>
+     </varlistentry>
+
+     <varlistentry>
+      <term><varname>LOG_DURATION</varname> (<type>boolean</type>)</term>
+      <listitem>
+       <para>
+        Prints the duration of every completed query.  To use this option, 
+        enable LOG_STATEMENT and LOG_PID so you can link the original query
+        to the duration using the process id.
+       </para>
+      </listitem>
+     </varlistentry>
+
      <varlistentry>
       <term><varname>LOG_TIMESTAMP</varname> (<type>boolean</type>)</term>
       <listitem>
@@ -1003,7 +1022,7 @@ env PGOPTIONS='-c geqo=off' psql
      </varlistentry>
 
      <varlistentry>
-      <term><varname>SHOW_QUERY_STATS</varname> (<type>boolean</type>)</term>
+      <term><varname>SHOW_STATEMENT_STATS</varname> (<type>boolean</type>)</term>
       <term><varname>SHOW_PARSER_STATS</varname> (<type>boolean</type>)</term>
       <term><varname>SHOW_PLANNER_STATS</varname> (<type>boolean</type>)</term>
       <term><varname>SHOW_EXECUTOR_STATS</varname> (<type>boolean</type>)</term>
@@ -2072,7 +2091,7 @@ dynamic_library_path = '/usr/local/lib/postgresql:/home/my_project/lib:$libdir'
        </row>
        <row>
         <entry><option>-s</option></entry>
-        <entry><literal>show_query_stats = on</></entry>
+        <entry><literal>show_statement_stats = on</></entry>
         <entry>*</entry>
        </row>
        <row>

src/backend/tcop/postgres.c

@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *	  $Header: /cvsroot/pgsql/src/backend/tcop/postgres.c,v 1.287 2002/08/30 22:18:06 tgl Exp $
+ *	  $Header: /cvsroot/pgsql/src/backend/tcop/postgres.c,v 1.288 2002/09/01 23:26:06 momjian Exp $
  *
  * NOTES
  *	  this is the "main" module of the postgres backend and
@@ -220,7 +220,7 @@ InteractiveBackend(StringInfo inBuf)
 	 * if the query echo flag was given, print the query..
 	 */
 	if (EchoQuery)
-		printf("query: %s\n", inBuf->data);
+		printf("statement: %s\n", inBuf->data);
 	fflush(stdout);
 
 	return 'Q';
@@ -372,7 +372,7 @@ pg_parse_query(StringInfo query_string, Oid *typev, int nargs)
 {
 	List	   *raw_parsetree_list;
 
-	if (Debug_print_query)
+	if (Log_statement)
 		elog(LOG, "query: %s", query_string->data);
 
 	if (Show_parser_stats)
@@ -561,9 +561,19 @@ pg_exec_query_string(StringInfo query_string,		/* string to execute */
 	MemoryContext oldcontext;
 	List	   *parsetree_list,
 			   *parsetree_item;
-
+	struct timezone tz;
+	struct timeval start_t, stop_t;
+	bool		save_Log_duration = Log_duration;
+	
 	debug_query_string = query_string->data;	/* used by pgmonitor */
 
+	/*
+	 *	We use save_Log_duration so setting Log_duration to true doesn't
+	 * 	report incorrect time because gettimeofday() wasn't called.
+	 */
+	if (save_Log_duration)
+		gettimeofday(&start_t, &tz);
+
 	/*
 	 * Start up a transaction command.	All queries generated by the
 	 * query_string will be in this same command block, *unless* we find a
@@ -850,6 +860,19 @@ pg_exec_query_string(StringInfo query_string,		/* string to execute */
 	if (xact_started)
 		finish_xact_command();
 
+	if (save_Log_duration)
+	{
+		gettimeofday(&stop_t, &tz);
+		if (stop_t.tv_usec < start_t.tv_usec)
+		{
+			stop_t.tv_sec--;
+			stop_t.tv_usec += 1000000;
+		}
+		elog(LOG, "duration: %ld.%06ld sec",
+			(long int) stop_t.tv_sec - start_t.tv_sec,
+			(long int) stop_t.tv_usec - start_t.tv_usec);
+	}
+		
 	debug_query_string = NULL;	/* used by pgmonitor */
 }
 
@@ -1234,7 +1257,7 @@ PostgresMain(int argc, char *argv[], const char *username)
 						if (atoi(optarg) >= 1)
 							SetConfigOption("log_connections", "true", ctx, gucsource);
 						if (atoi(optarg) >= 2)
-							SetConfigOption("debug_print_query", "true", ctx, gucsource);
+							SetConfigOption("log_statement", "true", ctx, gucsource);
 						if (atoi(optarg) >= 3)
 							SetConfigOption("debug_print_parse", "true", ctx, gucsource);
 						if (atoi(optarg) >= 4)
@@ -1377,7 +1400,7 @@ PostgresMain(int argc, char *argv[], const char *username)
 				/*
 				 * s - report usage statistics (timings) after each query
 				 */
-				SetConfigOption("show_query_stats", "true", ctx, gucsource);
+				SetConfigOption("show_statement_stats", "true", ctx, gucsource);
 				break;
 
 			case 't':
@@ -1489,11 +1512,11 @@ PostgresMain(int argc, char *argv[], const char *username)
 	/*
 	 * Post-processing for command line options.
 	 */
-	if (Show_query_stats &&
+	if (Show_statement_stats &&
 		(Show_parser_stats || Show_planner_stats || Show_executor_stats))
 	{
 		elog(WARNING, "Query statistics are disabled because parser, planner, or executor statistics are on.");
-		SetConfigOption("show_query_stats", "false", ctx, gucsource);
+		SetConfigOption("show_statement_stats", "false", ctx, gucsource);
 	}
 
 	if (!IsUnderPostmaster)
@@ -1664,7 +1687,7 @@ PostgresMain(int argc, char *argv[], const char *username)
 	if (!IsUnderPostmaster)
 	{
 		puts("\nPOSTGRES backend interactive interface ");
-		puts("$Revision: 1.287 $ $Date: 2002/08/30 22:18:06 $\n");
+		puts("$Revision: 1.288 $ $Date: 2002/09/01 23:26:06 $\n");
 	}
 
 	/*
@@ -1887,7 +1910,7 @@ PostgresMain(int argc, char *argv[], const char *username)
 					 * Note: transaction command start/end is now done within
 					 * pg_exec_query_string(), not here.
 					 */
-					if (Show_query_stats)
+					if (Show_statement_stats)
 						ResetUsage();
 
 					pgstat_report_activity(parser_input->data);
@@ -1896,7 +1919,7 @@ PostgresMain(int argc, char *argv[], const char *username)
 										 whereToSendOutput,
 										 QueryContext);
 
-					if (Show_query_stats)
+					if (Show_statement_stats)
 						ShowUsage("QUERY STATISTICS");
 				}
 				break;

src/backend/utils/misc/guc.c

@@ -5,7 +5,7 @@
  * command, configuration file, and command line options.
  * See src/backend/utils/misc/README for more information.
  *
- * $Header: /cvsroot/pgsql/src/backend/utils/misc/guc.c,v 1.89 2002/08/30 22:18:07 tgl Exp $
+ * $Header: /cvsroot/pgsql/src/backend/utils/misc/guc.c,v 1.90 2002/09/01 23:26:06 momjian Exp $
  *
  * Copyright 2000 by PostgreSQL Global Development Group
  * Written by Peter Eisentraut <peter_e@gmx.net>.
@@ -77,7 +77,8 @@ static const char *assign_facility(const char *facility,
 #ifdef USE_ASSERT_CHECKING
 bool		assert_enabled = true;
 #endif
-bool		Debug_print_query = false;
+bool		Log_statement = false;
+bool		Log_duration = false;
 bool		Debug_print_plan = false;
 bool		Debug_print_parse = false;
 bool		Debug_print_rewritten = false;
@@ -86,7 +87,7 @@ bool		Debug_pretty_print = false;
 bool		Show_parser_stats = false;
 bool		Show_planner_stats = false;
 bool		Show_executor_stats = false;
-bool		Show_query_stats = false;	/* this is sort of all three above
+bool		Show_statement_stats = false;	/* this is sort of all three above
 										 * together */
 bool		Show_btree_build_stats = false;
 
@@ -362,7 +363,11 @@ static struct config_bool
 #endif
 
 	{
-		{ "debug_print_query", PGC_USERSET }, &Debug_print_query,
+		{ "log_statement", PGC_USERSET }, &Log_statement,
+		false, NULL, NULL
+	},
+	{
+		{ "log_duration", PGC_USERSET }, &Log_duration,
 		false, NULL, NULL
 	},
 	{
@@ -395,7 +400,7 @@ static struct config_bool
 		false, NULL, NULL
 	},
 	{
-		{ "show_query_stats", PGC_USERSET }, &Show_query_stats,
+		{ "show_statement_stats", PGC_USERSET }, &Show_statement_stats,
 		false, NULL, NULL
 	},
 #ifdef BTREE_BUILD_STATS

src/backend/utils/misc/postgresql.conf.sample

@@ -102,7 +102,7 @@
 #geqo = true
 #geqo_selection_bias = 2.0	# range 1.5-2.0
 #geqo_threshold = 11
-#geqo_pool_size = 0		# default based on tables in query, 
+#geqo_pool_size = 0		# default based on tables in statement, 
 				# range 128-1024
 #geqo_effort = 1
 #geqo_generations = 0
@@ -122,10 +122,11 @@
 #silent_mode = false
 
 #log_connections = false
-#log_timestamp = false
 #log_pid = false
+#log_statement = false
+#log_duration = false
+#log_timestamp = false
 
-#debug_print_query = false
 #debug_print_parse = false
 #debug_print_rewritten = false
 #debug_print_plan = false
@@ -151,7 +152,7 @@
 #show_parser_stats = false
 #show_planner_stats = false
 #show_executor_stats = false
-#show_query_stats = false
+#show_statement_stats = false
 
 # requires BTREE_BUILD_STATS
 #show_btree_build_stats = false

src/bin/psql/tab-complete.c

@@ -3,7 +3,7 @@
  *
  * Copyright 2000-2002 by PostgreSQL Global Development Group
  *
- * $Header: /cvsroot/pgsql/src/bin/psql/tab-complete.c,v 1.60 2002/08/30 22:18:07 tgl Exp $
+ * $Header: /cvsroot/pgsql/src/bin/psql/tab-complete.c,v 1.61 2002/09/01 23:26:06 momjian Exp $
  */
 
 /*----------------------------------------------------------------------
@@ -231,15 +231,16 @@ psql_completion(char *text, int start, int end)
 		"server_min_messages",
 		"client_min_messages",
 		"debug_assertions",
-		"debug_print_query",
+		"log_statement",
+		"log_duration",
 		"debug_print_parse",
 		"debug_print_rewritten",
 		"debug_print_plan",
 		"debug_pretty_print",
 		"show_parser_stats",
 		"show_planner_stats",
 		"show_executor_stats",
-		"show_query_stats",
+		"show_statement_stats",
 		"trace_notify",
 		"explain_pretty_print",
 		"sql_inheritance",

src/include/utils/guc.h

@@ -4,7 +4,7 @@
  * External declarations pertaining to backend/utils/misc/guc.c and
  * backend/utils/misc/guc-file.l
  *
- * $Id: guc.h,v 1.20 2002/07/30 16:20:03 momjian Exp $
+ * $Id: guc.h,v 1.21 2002/09/01 23:26:06 momjian Exp $
  */
 #ifndef GUC_H
 #define GUC_H
@@ -100,7 +100,8 @@ extern void ProcessGUCArray(ArrayType *array, GucSource source);
 extern ArrayType *GUCArrayAdd(ArrayType *array, const char *name, const char *value);
 extern ArrayType *GUCArrayDelete(ArrayType *array, const char *name);
 
-extern bool Debug_print_query;
+extern bool Log_statement;
+extern bool Log_duration;
 extern bool Debug_print_plan;
 extern bool Debug_print_parse;
 extern bool Debug_print_rewritten;
@@ -109,7 +110,7 @@ extern bool Debug_pretty_print;
 extern bool Show_parser_stats;
 extern bool Show_planner_stats;
 extern bool Show_executor_stats;
-extern bool Show_query_stats;
+extern bool Show_statement_stats;
 extern bool Show_btree_build_stats;
 
 extern bool Explain_pretty_print;