Remove or reduce verbosity of some debug messages.

The debug messages that merely print StartTransactionCommand,
CommitTransactionCommand, ProcessUtilty, or ProcessQuery with no
additional details seem to be useless.  Get rid of them.

The transaction status messages produced by ShowTransactionState are
occasionally useful, but they are extremely verbose, producing
multiple lines of log output every time they fire, which can happens
multiple times per transaction.  So, reduce the level to DEBUG5; avoid
emitting an extra line just to explain which debug point is at issue;
and tighten up the rest of the message so it doesn't use quite so much
horizontal space.

With these changes, it's possible to run a somewhat busy system with a
log level even as high as DEBUG4, whereas previously anything above
DEBUG2 would flood the log with output that probably wasn't really all
that useful.

diff --git a/src/backend/access/transam/xact.c b/src/backend/access/transam/xact.c
index e11b2297921447986000d37e2f27514d8150861d..95805963af1ed89c667eb2cda4fb4f67d826b131 100644 (file)
--- a/src/backend/access/transam/xact.c
+++ b/src/backend/access/transam/xact.c
@@ -327,7 +327,7 @@ static void AtSubStart_Memory(void);
 static void AtSubStart_ResourceOwner(void);
 
 static void ShowTransactionState(const char *str);
-static void ShowTransactionStateRec(TransactionState state);
+static void ShowTransactionStateRec(const char *str, TransactionState state);
 static const char *BlockStateAsString(TBlockState blockState);
 static const char *TransStateAsString(TransState state);
 
@@ -4944,11 +4944,8 @@ static void
 ShowTransactionState(const char *str)
 {
    /* skip work if message will definitely not be printed */
-   if (log_min_messages <= DEBUG3 || client_min_messages <= DEBUG3)
-   {
-       elog(DEBUG3, "%s", str);
-       ShowTransactionStateRec(CurrentTransactionState);
-   }
+   if (log_min_messages <= DEBUG5 || client_min_messages <= DEBUG5)
+       ShowTransactionStateRec(str, CurrentTransactionState);
 }
 
 /*
@@ -4956,7 +4953,7 @@ ShowTransactionState(const char *str)
  *     Recursive subroutine for ShowTransactionState
  */
 static void
-ShowTransactionStateRec(TransactionState s)
+ShowTransactionStateRec(const char *str, TransactionState s)
 {
    StringInfoData buf;
 
@@ -4966,17 +4963,18 @@ ShowTransactionStateRec(TransactionState s)
    {
        int         i;
 
-       appendStringInfo(&buf, "%u", s->childXids[0]);
+       appendStringInfo(&buf, ", children: %u", s->childXids[0]);
        for (i = 1; i < s->nChildXids; i++)
            appendStringInfo(&buf, " %u", s->childXids[i]);
    }
 
    if (s->parent)
-       ShowTransactionStateRec(s->parent);
+       ShowTransactionStateRec(str, s->parent);
 
    /* use ereport to suppress computation if msg will not be printed */
-   ereport(DEBUG3,
-           (errmsg_internal("name: %s; blockState: %13s; state: %7s, xid/subid/cid: %u/%u/%u%s, nestlvl: %d, children: %s",
+   ereport(DEBUG5,
+           (errmsg_internal("%s(%d) name: %s; blockState: %s; state: %s, xid/subid/cid: %u/%u/%u%s%s",
+                            str, s->nestingLevel,
                             PointerIsValid(s->name) ? s->name : "unnamed",
                             BlockStateAsString(s->blockState),
                             TransStateAsString(s->state),
@@ -4984,7 +4982,7 @@ ShowTransactionStateRec(TransactionState s)
                             (unsigned int) s->subTransactionId,
                             (unsigned int) currentCommandId,
                             currentCommandIdUsed ? " (used)" : "",
-                            s->nestingLevel, buf.data)));
+                            buf.data)));
 
    pfree(buf.data);
 }

diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 3d9319d151e648773a6aa07cb70f4e2007c37ad4..cc847548a9fd4e609bbea296c7e91a8696ec4d28 100644 (file)
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -2427,8 +2427,6 @@ start_xact_command(void)
 {
    if (!xact_started)
    {
-       ereport(DEBUG3,
-               (errmsg_internal("StartTransactionCommand")));
        StartTransactionCommand();
 
        /* Set statement timeout running, if any */
@@ -2450,10 +2448,6 @@ finish_xact_command(void)
        /* Cancel any active statement timeout before committing */
        disable_timeout(STATEMENT_TIMEOUT, false);
 
-       /* Now commit the command */
-       ereport(DEBUG3,
-               (errmsg_internal("CommitTransactionCommand")));
-
        CommitTransactionCommand();
 
 #ifdef MEMORY_CONTEXT_CHECKING

diff --git a/src/backend/tcop/pquery.c b/src/backend/tcop/pquery.c
index 92d07fcb5dbd44e64fa2d2be308c0b3b3d78725a..5443d0b6110d29dae05eb44e44b26bf1eced799a 100644 (file)
--- a/src/backend/tcop/pquery.c
+++ b/src/backend/tcop/pquery.c
@@ -167,8 +167,6 @@ ProcessQuery(PlannedStmt *plan,
 {
    QueryDesc  *queryDesc;
 
-   elog(DEBUG3, "ProcessQuery");
-
    /*
     * Create the QueryDesc object
     */
@@ -1151,8 +1149,6 @@ PortalRunUtility(Portal portal, Node *utilityStmt,
 {
    Snapshot    snapshot;
 
-   elog(DEBUG3, "ProcessUtility");
-
    /*
     * Set snapshot if utility stmt needs one.  Most reliable way to do this
     * seems to be to enumerate those that do not need one; this is a short