*** postgresql-8.0.3/src/backend/tcop/postgres.c	2005-07-13 09:42:04.997669193 +0100
--- postgresql-8.0.3/src/backend/tcop/postgres.c	2005-07-13 09:34:24.618195580 +0100
***************
*** 1370,1375 ****
--- 1370,1378 ----
  	else
  		portal = CreatePortal(portal_name, false, false);
  
+ 	if (log_statement == LOGSTMT_ALL)
+ 	  ereport(LOG, (errmsg("binding: \"%s\" with %d parameters", stmt_name, numParams)));
+ 
  	/*
  	 * Fetch parameters, if any, and store in the portal's memory context.
  	 *
***************
*** 1428,1433 ****
--- 1431,1439 ----
  					 * grotty but is a big win when dealing with very
  					 * large parameter strings.
  					 */
+ 					if (log_statement == LOGSTMT_ALL)
+ 					  ereport(LOG, (errmsg("bind \"%s\" $%d = \"%s\"", stmt_name, i+1, pvalue)));
+ 
  					pbuf.data = (char *) pvalue;
  					pbuf.maxlen = plength + 1;
  					pbuf.len = plength;
***************
*** 1578,1583 ****
--- 1584,1593 ----
  	bool		is_trans_exit = false;
  	bool		completed;
  	char		completionTag[COMPLETION_TAG_BUFSIZE];
+ 	struct timeval start_t, stop_t;
+ 	bool		save_log_duration = log_duration;
+ 	int		save_log_min_duration_statement = log_min_duration_statement;
+ 	bool		save_log_statement_stats = log_statement_stats;
  
  	/* Adjust destination to tell printtup.c what to do */
  	dest = whereToSendOutput;
***************
*** 1614,1619 ****
--- 1624,1647 ----
  
  	set_ps_display(portal->commandTag);
  
+ 	/*
+ 	 * We use save_log_* so "SET log_duration = true"  and "SET
+ 	 * log_min_duration_statement = true" don't report incorrect time
+ 	 * because gettimeofday() wasn't called. Similarly,
+ 	 * log_statement_stats has to be captured once.
+ 	 */
+ 	if (save_log_duration || save_log_min_duration_statement != -1)
+ 		gettimeofday(&start_t, NULL);
+ 
+ 	if (save_log_statement_stats)
+ 		ResetUsage();
+ 
+ 	if (log_statement == LOGSTMT_ALL)
+ 		/* We have the portal, so output the source query. */
+ 		ereport(LOG,
+ 				(errmsg("statement: EXECUTE %s  [PREPARE:  %s]", portal_name,
+ 						portal->sourceText ? portal->sourceText : "")));
+ 
  	BeginCommand(portal->commandTag, dest);
  
  	/* Check for transaction-control commands */
***************
*** 1708,1713 ****
--- 1736,1785 ----
  			pq_putemptymessage('s');
  	}
  
+ 	/*
+ 	 * Combine processing here as we need to calculate the query duration
+ 	 * in both instances.
+ 	 */
+ 	if (save_log_duration || save_log_min_duration_statement != -1)
+ 	{
+ 		long		usecs;
+ 
+ 		gettimeofday(&stop_t, NULL);
+ 		if (stop_t.tv_usec < start_t.tv_usec)
+ 		{
+ 			stop_t.tv_sec--;
+ 			stop_t.tv_usec += 1000000;
+ 		}
+ 		usecs = (long) (stop_t.tv_sec - start_t.tv_sec) * 1000000 +
+ 				(long) (stop_t.tv_usec - start_t.tv_usec);
+ 
+ 		/* Only print duration if we previously printed the statement. */
+ 		if (log_statement == LOGSTMT_ALL && save_log_duration)
+ 			ereport(LOG,
+ 					(errmsg("duration: %ld.%03ld ms",
+ 						(long) ((stop_t.tv_sec - start_t.tv_sec) * 1000 +
+ 							  (stop_t.tv_usec - start_t.tv_usec) / 1000),
+ 					 (long) (stop_t.tv_usec - start_t.tv_usec) % 1000)));
+ 
+ 		/*
+ 		 * Output a duration_statement to the log if the query has
+ 		 * exceeded the min duration, or if we are to print all durations.
+ 		 */
+ 		if (save_log_min_duration_statement == 0 ||
+ 			(save_log_min_duration_statement > 0 &&
+ 			 usecs >= save_log_min_duration_statement * 1000))
+ 			ereport(LOG,
+ 					(errmsg("duration: %ld.%03ld ms  statement: EXECUTE %s  [PREPARE:  %s]",
+ 						(long) ((stop_t.tv_sec - start_t.tv_sec) * 1000 +
+ 							  (stop_t.tv_usec - start_t.tv_usec) / 1000),
+ 						(long) (stop_t.tv_usec - start_t.tv_usec) % 1000,
+ 							portal_name,
+ 							portal->sourceText ? portal->sourceText : "")));
+ 	}
+ 
+ 	if (save_log_statement_stats)
+ 		ShowUsage("QUERY STATISTICS");
+ 
  	debug_query_string = NULL;
  }