Now bind displays prepare as detail, and execute displays prepare and

optionally bind.  I re-added the "statement:" label so people will
understand why the line is being printed (it is log_*statement
behavior).

Use single quotes for bind values, instead of double quotes, and double
literal single quotes in bind values (and document that).  I also made
use of the DETAIL line to have much cleaner output.

doc/src/sgml/config.sgml

@@ -1,4 +1,4 @@
-<!-- $PostgreSQL: pgsql/doc/src/sgml/config.sgml,v 1.76 2006/08/28 13:37:18 petere Exp $ -->
+<!-- $PostgreSQL: pgsql/doc/src/sgml/config.sgml,v 1.77 2006/08/29 02:11:29 momjian Exp $ -->
 
 <chapter Id="runtime-config">
   <title>Server Configuration</title>
@@ -2839,7 +2839,7 @@ SELECT * FROM parent WHERE key = 2400;
         prepare, bind, and execute commands are logged only if
         <varname>log_statement</> is <literal>all</>.  Bind parameter 
         values are also logged if they are supplied in <literal>text</>
-        format.
+        format (literal single quotes are doubled).
        </para>
        <para>
         The default is <literal>none</>. Only superusers can change this

src/backend/commands/portalcmds.c

@@ -14,7 +14,7 @@
  *
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/commands/portalcmds.c,v 1.50 2006/08/12 20:05:54 tgl Exp $
+ *	  $PostgreSQL: pgsql/src/backend/commands/portalcmds.c,v 1.51 2006/08/29 02:11:29 momjian Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -114,6 +114,7 @@ PerformCursorOpen(DeclareCursorStmt *stmt, ParamListInfo params)
 	PortalDefineQuery(portal,
 					  NULL,
 					  pstrdup(debug_query_string),
+					  NULL,
 					  "SELECT", /* cursor's query is always a SELECT */
 					  list_make1(query),
 					  list_make1(plan),

src/backend/commands/prepare.c

@@ -10,7 +10,7 @@
  * Copyright (c) 2002-2006, PostgreSQL Global Development Group
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/commands/prepare.c,v 1.61 2006/08/14 22:57:15 tgl Exp $
+ *	  $PostgreSQL: pgsql/src/backend/commands/prepare.c,v 1.62 2006/08/29 02:11:29 momjian Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -203,6 +203,7 @@ ExecuteQuery(ExecuteStmt *stmt, ParamListInfo params,
 	PortalDefineQuery(portal,
 					  NULL,
 					  query_string,
+					  NULL,
 					  entry->commandTag,
 					  query_list,
 					  plan_list,

src/backend/executor/spi.c

@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/executor/spi.c,v 1.158 2006/08/27 23:47:57 tgl Exp $
+ *	  $PostgreSQL: pgsql/src/backend/executor/spi.c,v 1.159 2006/08/29 02:11:29 momjian Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -920,6 +920,7 @@ SPI_cursor_open(const char *name, void *plan,
 	PortalDefineQuery(portal,
 					  NULL,		/* no statement name */
 					  spiplan->query,
+					  NULL,
 					  CreateQueryTag(PortalListGetPrimaryQuery(qtlist)),
 					  qtlist,
 					  ptlist,

src/backend/tcop/postgres.c

@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/tcop/postgres.c,v 1.499 2006/08/15 18:26:58 tgl Exp $
+ *	  $PostgreSQL: pgsql/src/backend/tcop/postgres.c,v 1.500 2006/08/29 02:11:29 momjian Exp $
  *
  * NOTES
  *	  this is the "main" module of the postgres backend and
@@ -583,6 +583,7 @@ log_after_parse(List *raw_parsetree_list, const char *query_string,
 		 * For the first EXECUTE we find, record the client statement used by
 		 * the PREPARE.  PREPARE doesn't save the parse tree so we have no
 		 * way to conditionally output based on the type of query prepared.
+		 * Parse does save the command tag, so perhaps we can use that.
 		 */
 		if (IsA(parsetree, ExecuteStmt))
 		{
@@ -592,20 +593,16 @@ log_after_parse(List *raw_parsetree_list, const char *query_string,
 			if (*prepare_string == NULL &&
 				(entry = FetchPreparedStatement(stmt->name, false)) != NULL &&
 				entry->query_string)
-			{
+				*prepare_string = pstrdup(entry->query_string);
-				*prepare_string = palloc(strlen(entry->query_string) +
-									  strlen("  [PREPARE:  %s]") - 2 + 1);
-				sprintf(*prepare_string, "  [PREPARE:  %s]",
-						entry->query_string);
-			}
 		}
 	}
 
 	if (log_this_statement)
 	{
 		ereport(LOG,
-				(errmsg("statement: %s%s", query_string,
+				(errmsg("statement: %s", query_string),
-						*prepare_string ? *prepare_string : "")));
+						*prepare_string ? errdetail("prepare: %s",
+						*prepare_string) : 0));
 		return true;
 	}
 	else
@@ -874,9 +871,7 @@ exec_simple_query(const char *query_string)
 	parsetree_list = pg_parse_query(query_string);
 
 	/* Log immediately if dictated by log_statement */
-	if (log_statement != LOGSTMT_NONE)
+	was_logged = log_after_parse(parsetree_list, query_string, &prepare_string);
-		was_logged = log_after_parse(parsetree_list, query_string,
-									 &prepare_string);
 
 	/*
 	 * Switch back to transaction context to enter the loop.
@@ -957,6 +952,7 @@ exec_simple_query(const char *query_string)
 		PortalDefineQuery(portal,
 						  NULL,
 						  query_string,
+						  NULL,
 						  commandTag,
 						  querytree_list,
 						  plantree_list,
@@ -1097,10 +1093,11 @@ exec_simple_query(const char *query_string)
 								secs * 1000 + msecs, usecs % 1000)));
 			else
 				ereport(LOG,
-						(errmsg("duration: %ld.%03d ms  statement: %s%s",
+						(errmsg("duration: %ld.%03d ms  statement: %s",
 								secs * 1000 + msecs, usecs % 1000,
-								query_string,
+								query_string),
-								prepare_string ? prepare_string : "")));
+						 		prepare_string ? errdetail("prepare: %s",
+								prepare_string) : 0));
 		}
 	}
 
@@ -1147,7 +1144,7 @@ exec_parse_message(const char *query_string,	/* string to execute */
 
 	if (log_statement == LOGSTMT_ALL)
 		ereport(LOG,
-				(errmsg("prepare %s:  %s",
+				(errmsg("statement: prepare %s, %s",
 						*stmt_name ? stmt_name : "<unnamed>",
 						query_string)));
 
@@ -1384,8 +1381,7 @@ exec_bind_message(StringInfo input_message)
 	/* Switch back to message context */
 	MemoryContextSwitchTo(MessageContext);
 
-	if (log_statement == LOGSTMT_ALL)
+	initStringInfo(&bind_values_str);
-		initStringInfo(&bind_values_str);
 
 	/* Get the fixed part of the message */
 	portal_name = pq_getmsgstring(input_message);
@@ -1521,7 +1517,7 @@ exec_bind_message(StringInfo input_message)
 			{
 				Oid			typinput;
 				Oid			typioparam;
-				char	   *pstring;
+				char	   *pstring, *p;
 
 				getTypeInputInfo(ptype, &typinput, &typioparam);
 
@@ -1540,12 +1536,17 @@ exec_bind_message(StringInfo input_message)
 										 typioparam,
 										 -1);
 
-				/* Log the parameter value if needed */
+				/* Save the parameter values */
-				if (log_statement == LOGSTMT_ALL)
+				appendStringInfo(&bind_values_str, "%s$%d = '",
-					appendStringInfo(&bind_values_str, "%s$%d = \"%s\"",
+								 bind_values_str.len ? ", " : "",
-									 bind_values_str.len ? ", " : "",
+								 paramno + 1);
-									 paramno + 1,
+				for (p = pstring; *p; p++)
-									 pstring);
+				{
+					if (*p == '\'')	/* double single quotes */
+						appendStringInfoChar(&bind_values_str, *p);
+					appendStringInfoChar(&bind_values_str, *p);
+				}
+				appendStringInfoChar(&bind_values_str, '\'');
 
 				/* Free result of encoding conversion, if any */
 				if (pstring && pstring != pbuf.data)
@@ -1607,13 +1608,14 @@ exec_bind_message(StringInfo input_message)
 	if (log_statement == LOGSTMT_ALL)
 	{
 		ereport(LOG,
-				(errmsg("bind %s%s%s:  %s",
+				(errmsg("statement: bind %s%s%s%s%s",
 						*stmt_name ? stmt_name : "<unnamed>",
 						*portal->name ? "/" : "",
 						*portal->name ? portal->name : "",
-						pstmt->query_string ? pstmt->query_string : ""),
+						/* print bind parameters if we have them */
-				 bind_values_str.len ? errdetail(bind_values_str.data) : 0));
+						bind_values_str.len ? ", " : "",
-		pfree(bind_values_str.data);
+						bind_values_str.len ? bind_values_str.data : ""),
+						errdetail("prepare: %s", pstmt->query_string)));
 	}
 
 	/* Get the result format codes */
@@ -1651,6 +1653,7 @@ exec_bind_message(StringInfo input_message)
 	PortalDefineQuery(portal,
 					  *stmt_name ? pstrdup(stmt_name) : NULL,
 					  pstmt->query_string,
+					  bind_values_str.len ? pstrdup(bind_values_str.data) : NULL,
 					  pstmt->commandTag,
 					  pstmt->query_list,
 					  pstmt->plan_list,
@@ -1684,6 +1687,7 @@ exec_execute_message(const char *portal_name, long max_rows)
 	bool		completed;
 	char		completionTag[COMPLETION_TAG_BUFSIZE];
 	const char *sourceText = NULL;
+	const char *bindText = NULL;
 	const char *prepStmtName;
 	bool		save_log_statement_stats = log_statement_stats;
 	bool		is_xact_command;
@@ -1728,21 +1732,6 @@ exec_execute_message(const char *portal_name, long max_rows)
 		debug_query_string = "fetch message";
 		pgstat_report_activity("<FETCH>");
 	}
-	else if (portal->sourceText)
-	{
-		/*
-		 * We must copy the sourceText into MessageContext in case the
-		 * portal is destroyed during finish_xact_command.  Can avoid
-		 * the copy if it's not an xact command, though.
-		 */
-		if (is_xact_command)
-			sourceText = pstrdup(portal->sourceText);
-		else
-			sourceText = portal->sourceText;
-
-		debug_query_string = sourceText;
-		pgstat_report_activity(sourceText);
-	}
 	else
 	{
 		debug_query_string = "execute message";
@@ -1757,6 +1746,24 @@ exec_execute_message(const char *portal_name, long max_rows)
 	else
 		prepStmtName = "<unnamed>";
 
+	/*
+	 * We must copy the sourceText and bindText into MessageContext
+	 * in case the portal is destroyed during finish_xact_command.
+	 * Can avoid the copy if it's not an xact command, though.
+	 */
+	if (is_xact_command)
+		sourceText = pstrdup(portal->sourceText);
+	else
+		sourceText = portal->sourceText;
+
+	if (portal->bindText)
+	{
+		if (is_xact_command)
+			bindText = pstrdup(portal->bindText);
+		else
+			bindText = portal->bindText;
+	}
+	
 	/*
 	 * We use save_log_statement_stats so ShowUsage doesn't report incorrect
 	 * results because ResetUsage wasn't called.
@@ -1766,12 +1773,15 @@ exec_execute_message(const char *portal_name, long max_rows)
 
 	if (log_statement == LOGSTMT_ALL)
 		ereport(LOG,
-				(errmsg("execute %s%s%s%s:  %s",
+				(errmsg("statement: execute %s%s%s%s",
 						execute_is_fetch ? "fetch from " : "",
 						prepStmtName,
 						*portal_name ? "/" : "",
-						*portal_name ? portal_name : "",
+						*portal_name ? portal_name : ""),
-						sourceText ? sourceText : "")));
+						errdetail("prepare: %s%s%s", sourceText,
+						/* optionally print bind parameters */
+						bindText ? "  bind: " : "",
+						bindText ? bindText : "")));
 
 	BeginCommand(portal->commandTag, dest);
 
@@ -1876,13 +1886,16 @@ exec_execute_message(const char *portal_name, long max_rows)
 								secs * 1000 + msecs, usecs % 1000)));
 			else
 				ereport(LOG,
-						(errmsg("duration: %ld.%03d ms  execute %s%s%s%s:  %s",
+						(errmsg("duration: %ld.%03d ms  execute %s%s%s%s",
 								secs * 1000 + msecs, usecs % 1000,
 								execute_is_fetch ? "fetch from " : "",
 								prepStmtName,
 								*portal_name ? "/" : "",
-	    	                    *portal_name ? portal_name : "",
+								*portal_name ? portal_name : ""),
-								sourceText ? sourceText : "")));
+								errdetail("prepare: %s%s%s", sourceText,
+								/* optionally print bind parameters */
+								bindText ? "  bind: " : "",
+								bindText ? bindText : "")));
 		}
 	}
 

src/backend/utils/mmgr/portalmem.c

@@ -12,7 +12,7 @@
  * Portions Copyright (c) 1994, Regents of the University of California
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/utils/mmgr/portalmem.c,v 1.92 2006/08/14 22:57:15 tgl Exp $
+ *	  $PostgreSQL: pgsql/src/backend/utils/mmgr/portalmem.c,v 1.93 2006/08/29 02:11:30 momjian Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -274,6 +274,7 @@ void
 PortalDefineQuery(Portal portal,
 				  const char *prepStmtName,
 				  const char *sourceText,
+				  const char *bindText,
 				  const char *commandTag,
 				  List *parseTrees,
 				  List *planTrees,
@@ -288,6 +289,7 @@ PortalDefineQuery(Portal portal,
 
 	portal->prepStmtName = prepStmtName;
 	portal->sourceText = sourceText;
+	portal->bindText = bindText;
 	portal->commandTag = commandTag;
 	portal->parseTrees = parseTrees;
 	portal->planTrees = planTrees;

src/include/utils/portal.h

@@ -39,7 +39,7 @@
  * Portions Copyright (c) 1996-2006, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/include/utils/portal.h,v 1.66 2006/08/14 22:57:15 tgl Exp $
+ * $PostgreSQL: pgsql/src/include/utils/portal.h,v 1.67 2006/08/29 02:11:30 momjian Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -122,7 +122,8 @@ typedef struct PortalData
 	 */
 
 	/* The query or queries the portal will execute */
-	const char *sourceText;		/* text of query, if known (may be NULL) */
+	const char *sourceText;		/* text of query, if known, might be NULL */
+	const char *bindText;		/* text of bind parameters, might be NULL */
 	const char *commandTag;		/* command tag for original query */
 	List	   *parseTrees;		/* parse tree(s) */
 	List	   *planTrees;		/* plan tree(s) */
@@ -215,6 +216,7 @@ extern Portal GetPortalByName(const char *name);
 extern void PortalDefineQuery(Portal portal,
 				  const char *prepStmtName,
 				  const char *sourceText,
+				  const char *bindText,
 				  const char *commandTag,
 				  List *parseTrees,
 				  List *planTrees,