Fix core dump in duration logging for a V3-protocol Execute message

when what's being executed is a COMMIT or ROLLBACK.  Per report from
Sergey Koposov.  Backpatch to 8.1; 8.0 and before don't have the bug
due to lack of any logging at all here.

diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 20b0f68fc11926d42340c28648d53f1f4f31fb76..9cb61c16cb578c9efd643be36b8a9782557ce476 100644 (file)
--- 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.497 2006/08/10 00:44:01 momjian Exp $
+ *   $PostgreSQL: pgsql/src/backend/tcop/postgres.c,v 1.498 2006/08/13 22:18:08 tgl Exp $
  *
  * NOTES
  *   this is the "main" module of the postgres backend and
@@ -1368,7 +1368,7 @@ exec_bind_message(StringInfo input_message)
    PreparedStatement *pstmt;
    Portal      portal;
    ParamListInfo params;
-   StringInfoData str;
+   StringInfoData bind_values_str;
 
    pgstat_report_activity("");
 
@@ -1385,7 +1385,7 @@ exec_bind_message(StringInfo input_message)
    MemoryContextSwitchTo(MessageContext);
 
    if (log_statement == LOGSTMT_ALL)
-       initStringInfo(&str);
+       initStringInfo(&bind_values_str);
 
    /* Get the fixed part of the message */
    portal_name = pq_getmsgstring(input_message);
@@ -1534,14 +1534,18 @@ exec_bind_message(StringInfo input_message)
                else
                    pstring = pg_client_to_server(pbuf.data, plength);
 
-               params->params[paramno].value = OidInputFunctionCall(typinput,
-                                                              pstring,
-                                                              typioparam,
-                                                              -1);
+               params->params[paramno].value =
+                   OidInputFunctionCall(typinput,
+                                        pstring,
+                                        typioparam,
+                                        -1);
 
+               /* Log the parameter value if needed */
                if (log_statement == LOGSTMT_ALL)
-                   appendStringInfo(&str, "%s$%d = \"%s\"",
-                       *str.data ? ", " : "", paramno + 1, pstring);
+                   appendStringInfo(&bind_values_str, "%s$%d = \"%s\"",
+                                    bind_values_str.len ? ", " : "",
+                                    paramno + 1,
+                                    pstring);
 
                /* Free result of encoding conversion, if any */
                if (pstring && pstring != pbuf.data)
@@ -1574,6 +1578,8 @@ exec_bind_message(StringInfo input_message)
                            (errcode(ERRCODE_INVALID_BINARY_REPRESENTATION),
                             errmsg("incorrect binary data format in bind parameter %d",
                                    paramno + 1)));
+
+               /* XXX TODO: convert value to text and log it */
            }
            else
            {
@@ -1600,22 +1606,14 @@ exec_bind_message(StringInfo input_message)
 
    if (log_statement == LOGSTMT_ALL)
    {
-       if (*str.data)
-           ereport(LOG,
-                   (errmsg("bind %s%s%s:  %s",
-                           *stmt_name ? stmt_name : "",
-                           *portal->name ? "/" : "",
-                           *portal->name ? portal->name : "",
-                           pstmt->query_string ? pstmt->query_string : ""),
-                    errdetail(str.data)));
-       else
-           ereport(LOG,
-                   (errmsg("bind %s%s%s:  %s",
-                           *stmt_name ? stmt_name : "",
-                           *portal->name ? "/" : "",
-                           *portal->name ? portal->name : "",
-                           pstmt->query_string ? pstmt->query_string : "")));
-       pfree(str.data);
+       ereport(LOG,
+               (errmsg("bind %s%s%s:  %s",
+                       *stmt_name ? stmt_name : "",
+                       *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);
    }
 
    /* Get the result format codes */
@@ -1685,8 +1683,11 @@ exec_execute_message(const char *portal_name, long max_rows)
    Portal      portal;
    bool        completed;
    char        completionTag[COMPLETION_TAG_BUFSIZE];
+   const char *sourceText = NULL;
+   const char *prepStmtName;
    bool        save_log_statement_stats = log_statement_stats;
-   bool        execute_is_fetch = false;
+   bool        is_xact_command;
+   bool        execute_is_fetch;
 
    /* Adjust destination to tell printtup.c what to do */
    dest = whereToSendOutput;
@@ -1699,15 +1700,6 @@ exec_execute_message(const char *portal_name, long max_rows)
                (errcode(ERRCODE_UNDEFINED_CURSOR),
                 errmsg("portal \"%s\" does not exist", portal_name)));
 
-   /*
-    * If we re-issue an Execute protocol request against an existing portal,
-    * then we are only fetching more rows rather than completely re-executing
-    * the query from the start. atStart is never reset for a v3 portal, so we
-    * are safe to use this check.
-    */
-   if (!portal->atStart)
-       execute_is_fetch = true;
-
    /*
     * If the original query was a null string, just return
     * EmptyQueryResponse.
@@ -1719,6 +1711,17 @@ exec_execute_message(const char *portal_name, long max_rows)
        return;
    }
 
+   /* Does the portal contain a transaction command? */
+   is_xact_command = IsTransactionStmtList(portal->parseTrees);
+
+   /*
+    * If we re-issue an Execute protocol request against an existing portal,
+    * then we are only fetching more rows rather than completely re-executing
+    * the query from the start. atStart is never reset for a v3 portal, so we
+    * are safe to use this check.
+    */
+   execute_is_fetch = !portal->atStart;
+
    /* Should we display the portal names here? */
    if (execute_is_fetch)
    {
@@ -1727,8 +1730,18 @@ exec_execute_message(const char *portal_name, long max_rows)
    }
    else if (portal->sourceText)
    {
-       debug_query_string = portal->sourceText;
-       pgstat_report_activity(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
    {
@@ -1738,6 +1751,12 @@ exec_execute_message(const char *portal_name, long max_rows)
 
    set_ps_display(portal->commandTag, false);
 
+   /* copy prepStmtName now too, in case portal is destroyed */
+   if (portal->prepStmtName)
+       prepStmtName = pstrdup(portal->prepStmtName);
+   else
+       prepStmtName = "";
+
    /*
     * We use save_log_statement_stats so ShowUsage doesn't report incorrect
     * results because ResetUsage wasn't called.
@@ -1746,14 +1765,13 @@ exec_execute_message(const char *portal_name, long max_rows)
        ResetUsage();
 
    if (log_statement == LOGSTMT_ALL)
-       /* We have the portal, so output the source query. */
        ereport(LOG,
                (errmsg("execute %s%s%s%s:  %s",
                        execute_is_fetch ? "fetch from " : "",
-                       portal->prepStmtName ? portal->prepStmtName : "",
-                       *portal->name ? "/" : "",
-                        *portal->name ? portal->name : "",
-                       portal->sourceText ? portal->sourceText : "")));
+                       prepStmtName,
+                       *portal_name ? "/" : "",
+                       *portal_name ? portal_name : "",
+                       sourceText ? sourceText : "")));
 
    BeginCommand(portal->commandTag, dest);
 
@@ -1799,7 +1817,7 @@ exec_execute_message(const char *portal_name, long max_rows)
 
    if (completed)
    {
-       if (IsTransactionStmtList(portal->parseTrees))
+       if (is_xact_command)
        {
            /*
             * If this was a transaction control statement, commit it.  We
@@ -1861,10 +1879,10 @@ exec_execute_message(const char *portal_name, long max_rows)
                        (errmsg("duration: %ld.%03d ms  execute %s%s%s%s:  %s",
                                secs * 1000 + msecs, usecs % 1000,
                                execute_is_fetch ? "fetch from " : "",
-                               portal->prepStmtName ? portal->prepStmtName : "",
-                               *portal->name ? "/" : "",
-                               *portal->name ? portal->name : "",
-                               portal->sourceText ? portal->sourceText : "")));
+                               prepStmtName,
+                               *portal_name ? "/" : "",
+                               *portal_name ? portal_name : "",
+                               sourceText ? sourceText : "")));
        }
    }