From bc24d5b97673c365f19be21f83acca3c184cf1a7 Mon Sep 17 00:00:00 2001
From: Bruce Momjian <bruce@momjian.us>
Date: Tue, 29 Aug 2006 02:11:30 +0000
Subject: [PATCH] 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 | 4 +-
src/backend/commands/portalcmds.c | 3 +-
src/backend/commands/prepare.c | 3 +-
src/backend/executor/spi.c | 3 +-
src/backend/tcop/postgres.c | 113 ++++++++++++++++-------------
src/backend/utils/mmgr/portalmem.c | 4 +-
src/include/utils/portal.h | 6 +-
7 files changed, 78 insertions(+), 58 deletions(-)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 082efc9e7b7..22de6b746af 100644
--- a/doc/src/sgml/config.sgml
+++ b/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
diff --git a/src/backend/commands/portalcmds.c b/src/backend/commands/portalcmds.c
index 0685426a2f2..47e2829b7b3 100644
--- a/src/backend/commands/portalcmds.c
+++ b/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),
diff --git a/src/backend/commands/prepare.c b/src/backend/commands/prepare.c
index 82ad85a410a..04445cd33ef 100644
--- a/src/backend/commands/prepare.c
+++ b/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,
diff --git a/src/backend/executor/spi.c b/src/backend/executor/spi.c
index dd22a2dd5f2..3db05898871 100644
--- a/src/backend/executor/spi.c
+++ b/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,
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index af9578b15ac..58ec9a2f7ba 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.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 = palloc(strlen(entry->query_string) +
- strlen(" [PREPARE: %s]") - 2 + 1);
- sprintf(*prepare_string, " [PREPARE: %s]",
- entry->query_string);
- }
+ *prepare_string = pstrdup(entry->query_string);
}
}
if (log_this_statement)
{
ereport(LOG,
- (errmsg("statement: %s%s", query_string,
- *prepare_string ? *prepare_string : "")));
+ (errmsg("statement: %s", query_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,
- prepare_string ? prepare_string : "")));
+ query_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 */
- if (log_statement == LOGSTMT_ALL)
- appendStringInfo(&bind_values_str, "%s$%d = \"%s\"",
- bind_values_str.len ? ", " : "",
- paramno + 1,
- pstring);
+ /* Save the parameter values */
+ appendStringInfo(&bind_values_str, "%s$%d = '",
+ bind_values_str.len ? ", " : "",
+ paramno + 1);
+ for (p = pstring; *p; p++)
+ {
+ 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 : ""),
- bind_values_str.len ? errdetail(bind_values_str.data) : 0));
- pfree(bind_values_str.data);
+ /* print bind parameters if we have them */
+ bind_values_str.len ? ", " : "",
+ 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 : "",
- sourceText ? sourceText : "")));
+ *portal_name ? portal_name : ""),
+ 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 : "",
- sourceText ? sourceText : "")));
+ *portal_name ? portal_name : ""),
+ errdetail("prepare: %s%s%s", sourceText,
+ /* optionally print bind parameters */
+ bindText ? " bind: " : "",
+ bindText ? bindText : "")));
}
}
diff --git a/src/backend/utils/mmgr/portalmem.c b/src/backend/utils/mmgr/portalmem.c
index 85a6711d1cd..cae91572cc7 100644
--- a/src/backend/utils/mmgr/portalmem.c
+++ b/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;
diff --git a/src/include/utils/portal.h b/src/include/utils/portal.h
index 92cc55189ed..bf3d503004c 100644
--- a/src/include/utils/portal.h
+++ b/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,
--
GitLab