The second cut of QLOG renewal.
authorHiroshi Inoue <h-inoue@dream.email.ne.jp>
Wed, 23 Aug 2017 05:47:39 +0000 (14:47 +0900)
committerHiroshi Inoue <h-inoue@dream.email.ne.jp>
Wed, 23 Aug 2017 05:47:39 +0000 (14:47 +0900)
connection.c
mylog.h
qresult.c
statement.c

index 4305e4cd96c3d5441b0cc2b31c2bbb86db95c850..a901d12bad31c4acdc123da67863ae528e089e61 100644 (file)
@@ -45,6 +45,8 @@
 
 #include "pgapifunc.h"
 
+#define    SAFE_STR(s) (NULL != (s) ? (s) : "(null)")
+
 #define STMT_INCREMENT 16      /* how many statement holders to allocate
                                 * at a time */
 
@@ -208,8 +210,6 @@ PGAPI_Disconnect(HDBC hdbc)
        return SQL_INVALID_HANDLE;
    }
 
-   QLOG(0, "conn=%p, %s\n", conn, func);
-
    if (conn->status == CONN_EXECUTING)
    {
        CC_set_error(conn, CONN_IN_USE, "A transaction is currently being executed", func);
@@ -662,6 +662,7 @@ CC_cleanup(ConnectionClass *self, BOOL keepCommunication)
    /* even if we are in auto commit. */
    if (self->pqconn)
    {
+       QLOG(0, "PQfinish: %p\n", self->pqconn);
        PQfinish(self->pqconn);
        self->pqconn = NULL;
    }
@@ -805,12 +806,14 @@ handle_pgres_error(ConnectionClass *self, const PGresult *pgres,
    char       *errprimary = NULL;
    char       *errmsg = NULL;
    size_t      errmsglen;
+   char    *sqlstate = NULL;
+   int level = 0;
 
    MYLOG(1, "handle_pgres_error\n");
 
+   sqlstate = PQresultErrorField(pgres, PG_DIAG_SQLSTATE);
    if (res && pgres)
    {
-       char *sqlstate = PQresultErrorField(pgres, PG_DIAG_SQLSTATE);
        if (sqlstate)
            STRCPY_FIXED(res->sqlstate, sqlstate);
    }
@@ -821,6 +824,7 @@ handle_pgres_error(ConnectionClass *self, const PGresult *pgres,
        const char *errmsg = "The connection has been lost";
 
        MYLOG(0, "%s setting error message=%s\n", __FUNCTION__, errmsg);
+       QLOG(0, "\t%ssetting error message=%s\n", __FUNCTION__, errmsg);
        if (CC_get_errornumber(self) <= 0)
            CC_set_error(self, CONNECTION_COMMUNICATION_ERROR, errmsg, comment);
        if (res)
@@ -840,9 +844,26 @@ handle_pgres_error(ConnectionClass *self, const PGresult *pgres,
    if (PG_VERSION_GE(self, 9.6))
    {
        errseverity_nonloc = PQresultErrorField(pgres, PG_DIAG_SEVERITY_NONLOCALIZED);
-       MYLOG(0, "PG_DIAG_SEVERITY_NONLOCALIZED=%s\n", errseverity_nonloc ? errseverity_nonloc : "(null)");
+       MYLOG(0, "PG_DIAG_SEVERITY_NONLOCALIZED=%s\n", SAFE_STR(errseverity_nonloc));
+   }
+   if (!error_not_a_notice)
+   {
+       if (errseverity_nonloc)
+       {
+           if (stricmp(errseverity_nonloc, "NOTICE") != 0)
+               level = 1;
+       }
+       else if (errseverity)
+       {
+           if (stricmp(errseverity, "NOTICE") != 0)
+               level = 1;
+       }
    }
    errprimary = PQresultErrorField(pgres, PG_DIAG_MESSAGE_PRIMARY);
+   if (errseverity_nonloc)
+       QLOG(level, "\t%s(%s) %s '%s'\n", errseverity_nonloc, SAFE_STR(errseverity), SAFE_STR(sqlstate), SAFE_STR(errprimary));
+   else
+       QLOG(level, "\t(%s) %s '%s'\n", SAFE_STR(errseverity), SAFE_STR(sqlstate), SAFE_STR(errprimary));
    if (errprimary == NULL)
    {
        /* Hmm. got no primary message. Check if there's a connection error */
@@ -874,8 +895,7 @@ handle_pgres_error(ConnectionClass *self, const PGresult *pgres,
        goto cleanup;
    }
 
-   if (get_mylog() > 0)
-       MYLOG(0, "error message=%s(" FORMAT_SIZE_T ")\n", errmsg, strlen(errmsg));
+   MYLOG(0, "error message=%s(" FORMAT_SIZE_T ")\n", errmsg, strlen(errmsg));
 
    if (res)
    {
@@ -1523,6 +1543,7 @@ MYLOG(0, "CC_on_abort in opt=%x\n", opt);
        if (conn->pqconn)
        {
            CONNLOCK_RELEASE(conn);
+           QLOG(0, "PQfinish: %p\n", conn->pqconn);
            PQfinish(conn->pqconn);
            CONNLOCK_ACQUIRE(conn);
            conn->pqconn = NULL;
@@ -1578,7 +1599,7 @@ CC_from_PGresult(QResultClass *res, StatementClass *stmt,
 
    if (!QR_from_PGresult(res, stmt, conn, cursor, pgres))
    {
-       QLOG(0, "getting result from PGresult failed\n");
+       QLOG(0, "\tGetting result from PGresult failed\n");
        success = FALSE;
        if (0 >= CC_get_errornumber(conn))
        {
@@ -1613,10 +1634,12 @@ CC_internal_rollback(ConnectionClass *self, int rollback_type, BOOL ignore_abort
        case PER_STATEMENT_ROLLBACK:
            GenerateSvpCommand(self, INTERNAL_ROLLBACK_OPERATION, cmd, sizeof(cmd));
            MYLOG(0, " %s:rollback_type=%d %s\n", __FUNCTION__, rollback_type, cmd);
+           QLOG(0, "PQexec: %p '%s'\n", self->pqconn, cmd);
            pgres = PQexec(self->pqconn, cmd);
            switch (PQresultStatus(pgres))
            {
                case PGRES_COMMAND_OK:
+                   QLOG(0, "\tok: - 'C' - %s\n", PQcmdStatus(pgres));
                case PGRES_NONFATAL_ERROR:
                    ret = 1;
                    if (ignore_abort)
@@ -1624,6 +1647,7 @@ CC_internal_rollback(ConnectionClass *self, int rollback_type, BOOL ignore_abort
                    LIBPQ_update_transaction_status(self);
                    break;
                default:
+                   handle_pgres_error(self, pgres, __FUNCTION__, NULL, TRUE);
                    break;
            }
            break;
@@ -1631,26 +1655,30 @@ CC_internal_rollback(ConnectionClass *self, int rollback_type, BOOL ignore_abort
            SPRINTF_FIXED(cmd, "%s TO %s;%s %s"
                , rbkcmd, per_query_svp , rlscmd, per_query_svp);
            MYLOG(0, " %s:query_rollback PQsendQuery %s\n", __FUNCTION__, cmd);
+           QLOG(0, "PQsendQuery: %p '%s'\n", self->pqconn, cmd);
            PQsendQuery(self->pqconn, cmd);
-           ret = 1;
+           ret = 0;
            while (self->pqconn && (pgres = PQgetResult(self->pqconn)) != NULL)
            {
                switch (PQresultStatus(pgres))
                {
                    case PGRES_COMMAND_OK:
-                   case PGRES_NONFATAL_ERROR:
+                       QLOG(0, "\tok: - 'C' - %s\n", PQcmdTuples(pgres));
+                       ret = 1;
                        break;
+                   case PGRES_NONFATAL_ERROR:
+                       ret = 1;
                    default:
-                       ret = 0;
+                       handle_pgres_error(self, pgres, __FUNCTION__, NULL, !ret);
                }
            }
-           if (ret)
+           if (!ret)
            {
                if (ignore_abort)
                    CC_set_no_error_trans(self);
+               else
+                   MYLOG(0, " %s:return error\n", __FUNCTION__);
            }
-           else
-               MYLOG(0, " %s:return error\n", __FUNCTION__);
            LIBPQ_update_transaction_status(self);
            break;
    }
@@ -1834,11 +1862,11 @@ MYLOG(1, "!!!! %s:query_buf=%s(" FORMAT_SIZE_T ")\n", __FUNCTION__, query_buf.da
    nrarg.res = NULL;
    PQsetNoticeReceiver(self->pqconn, receive_libpq_notice, &nrarg);
 
-   QLOG(0, "PQsendQuery query=%s\n", query_buf.data);
+   QLOG(0, "PQsendQuery: %p '%s'\n", self->pqconn, query_buf.data);
    if (!PQsendQuery(self->pqconn, query_buf.data))
    {
        char *errmsg = PQerrorMessage(self->pqconn);
-       QLOG(0, "\nComunication Error: %s\n", errmsg ? errmsg : "(null)");
+       QLOG(0, "\nCommunication Error: %s\n", SAFE_STR(errmsg));
        CC_set_error(self, CONNECTION_COMMUNICATION_ERROR, errmsg, func);
        goto cleanup;
    }
@@ -1875,7 +1903,7 @@ MYLOG(1, "!!!! %s:query_buf=%s(" FORMAT_SIZE_T ")\n", __FUNCTION__, query_buf.da
                /* read in the return message from the backend */
                cmdbuffer = PQcmdStatus(pgres);
                MYLOG(0, "send_query: ok - 'C' - %s\n", cmdbuffer);
-
+               QLOG(0, "\tok: - 'C' - %s\n", cmdbuffer);
 
                if (query_completed)    /* allow for "show" style notices */
                {
@@ -1996,6 +2024,7 @@ MYLOG(1, "Discarded a RELEASE result\n");
                query_completed = TRUE;
                break;
            case PGRES_TUPLES_OK:
+               QLOG(0, "\tok: - 'T' - %s\n", PQcmdStatus(pgres));
            case PGRES_SINGLE_TUPLE:
                if (query_completed)
                {
@@ -2088,6 +2117,7 @@ MYLOG(1, "Discarded a RELEASE result\n");
            default:
                /* skip the unexpected response if possible */
                CC_set_error(self, CONNECTION_BACKEND_CRAZY, "Unexpected result status (send_query)", func);
+               handle_pgres_error(self, pgres, "send_query", res, TRUE);
                CC_on_abort(self, CONN_DEAD);
 
                MYLOG(0, "send_query: error - %s\n", CC_get_errormsg(self));
@@ -2307,13 +2337,16 @@ CC_send_function(ConnectionClass *self, const char *fn_name, void *result_buf, i
        }
    }
 
+   QLOG(0, "PQexecParams: %p '%s' nargs=%d\n", self->pqconn, sqlbuffer, nargs);
    pgres = PQexecParams(self->pqconn, sqlbuffer, nargs,
                         paramTypes, (const char * const *) paramValues,
                         paramLengths, paramFormats, 1);
 
    MYLOG(0, "send_function: done sending function\n");
 
-   if (PQresultStatus(pgres) != PGRES_TUPLES_OK)
+   if (PQresultStatus(pgres) == PGRES_TUPLES_OK)
+       QLOG(0, "\tok: - 'T' - %s\n", PQcmdStatus(pgres));
+   else
    {
        handle_pgres_error(self, pgres, "send_query", NULL, TRUE);
        goto cleanup;
@@ -2327,6 +2360,7 @@ CC_send_function(ConnectionClass *self, const char *fn_name, void *result_buf, i
 
    *actual_result_len = PQgetlength(pgres, 0, 0);
 
+   QLOG(0, "\tgot result with length: %d\n", *actual_result_len);
    MYLOG(0, "send_function(): got result with length %d\n", *actual_result_len);
 
    if (*actual_result_len > 0)
@@ -2733,6 +2767,15 @@ LIBPQ_connect(ConnectionClass *self)
    opts[cnt] = vals[cnt] = NULL;
    /* Ok, we're all set to connect */
 
+   if (get_qlog() > 0)
+   {
+       const char **popt, **pval;
+
+       QLOG(0, "PQconnectdbParams:");
+       for (popt = opts, pval = vals; *popt; popt++, pval++)
+           QPRINTF(0, " %s='%s'", *popt, *pval);
+       QPRINTF(0, "\n"); 
+   }
    pqconn = PQconnectdbParams(opts, vals, FALSE);
    if (!pqconn)
    {
@@ -2749,6 +2792,7 @@ LIBPQ_connect(ConnectionClass *self)
        MYLOG(0, "password retry\n");
        errmsg = PQerrorMessage(pqconn);
        CC_set_error(self, CONNECTION_SERVER_NOT_REACHED, errmsg, func);
+       QLOG(0, "PQfinish: %p\n", pqconn);
        PQfinish(pqconn);
        self->pqconn = NULL;
        self->connInfo.password_required = TRUE;
@@ -2797,7 +2841,10 @@ cleanup:
    if (ret != 1)
    {
        if (self->pqconn)
+       {
+           QLOG(0, "PQfinish: %p\n", self->pqconn);
            PQfinish(self->pqconn);
+       }
        self->pqconn = NULL;
    }
 
diff --git a/mylog.h b/mylog.h
index eb5b217f4a5624f8918cf604fa7fe6f3e7867c1a..cd2a1b0c38fa4f2c0fbe2428a81b756d8bd7350b 100644 (file)
--- a/mylog.h
+++ b/mylog.h
@@ -41,6 +41,7 @@ DLL_DECLARE int mylog(const char *fmt,...) __attribute__((format(printf, 1, 2)))
 DLL_DECLARE int myprintf(const char *fmt,...) __attribute__((format(printf, 1, 2)));
 
 extern int qlog(char *fmt,...) __attribute__((format(printf, 1, 2)));
+extern int qprintf(char *fmt,...) __attribute__((format(printf, 1, 2)));
 
 const char *po_basename(const char *path);
 
index e72c411a774e1b821a076bfff053dec04ca0b721..132d546a03447cb919d6593601c0cf624567ea8c 100644 (file)
--- a/qresult.c
+++ b/qresult.c
@@ -603,6 +603,7 @@ QR_from_PGresult(QResultClass *self, StatementClass *stmt, ConnectionClass *conn
    /* at first read in the number of fields that are in the query */
    new_num_fields = PQnfields(*pgres);
    MYLOG(0, "num_fields = %d\n", new_num_fields);
+   QLOG(0, "\tnum_fields: %d\n", new_num_fields);
 
    /* according to that allocate memory */
    QR_set_num_fields(self, new_num_fields);
@@ -634,6 +635,7 @@ QR_from_PGresult(QResultClass *self, StatementClass *stmt, ConnectionClass *conn
            new_atttypmod = -1;
 
        MYLOG(0, "%s: fieldname='%s', adtid=%d, adtsize=%d, atttypmod=%d (rel,att)=(%d,%d)\n", func, new_field_name, new_adtid, new_adtsize, new_atttypmod, new_relid, new_attid);
+       QLOG(1, "\tfieldname='%s', adtid=%d, adtsize=%d, atttypmod=%d (rel,att)=(%d,%d)\n", new_field_name, new_adtid, new_adtsize, new_atttypmod, new_relid, new_attid);
 
        CI_set_field_info(QR_get_fields(self), lf, new_field_name, new_adtid, new_adtsize, new_atttypmod, new_relid, new_attid);
 
@@ -1327,6 +1329,7 @@ QR_read_tuples_from_pgres(QResultClass *self, PGresult **pgres)
    int         rowno;
    int         nrows;
    int         resStatus;
+   int     numTotalRows = 0;
 
    /* set the current row to read the fields into */
    effective_cols = QR_NumPublicResultCols(self);
@@ -1338,6 +1341,8 @@ nextrow:
    switch (resStatus)
    {
        case PGRES_TUPLES_OK:
+           QLOG(0, "\tok: - 'T' - %s\n", PQcmdStatus(*pgres));
+           break;
        case PGRES_SINGLE_TUPLE:
            break;
 
@@ -1351,6 +1356,7 @@ nextrow:
    }
 
    nrows = PQntuples(*pgres);
+   numTotalRows += nrows;
 
    for (rowno = 0; rowno < nrows; rowno++)
    {
index 1762fa6269b3b171d41dcf49de59a6966ed6da8d..cec01c03826b3a1a617a246209b7a788de2907d4 100644 (file)
@@ -2340,6 +2340,7 @@ SC_log_error(const char *func, const char *desc, const StatementClass *self)
        const ARDFields *opts = SC_get_ARDF(self);
        const APDFields *apdopts = SC_get_APDF(self);
        SQLLEN  rowsetSize;
+       const int level = 9;
 
        rowsetSize = (STMT_TRANSITION_EXTENDED_FETCH == self->transition_status ? opts->size_of_rowset_odbc2 : opts->size_of_rowset);
        if (SC_get_errornumber(self) <= 0)
@@ -2347,31 +2348,31 @@ SC_log_error(const char *func, const char *desc, const StatementClass *self)
        else
        {
            head = "STATEMENT ERROR";
-           QLOG(0, "%s: func=%s, desc='%s', errnum=%d, errmsg='%s'\n",head, func, desc, self->__error_number, NULLCHECK(self->__error_message));
+           QLOG(level, "%s: func=%s, desc='%s', errnum=%d, errmsg='%s'\n",head, func, desc, self->__error_number, NULLCHECK(self->__error_message));
        }
        MYLOG(0, "%s: func=%s, desc='%s', errnum=%d, errmsg='%s'\n", head, func, desc, self->__error_number, NULLCHECK(self->__error_message));
        if (SC_get_errornumber(self) > 0)
        {
-           QLOG(0, "                 ------------------------------------------------------------\n");
-           QLOG(0, "                 hdbc=%p, stmt=%p, result=%p\n", self->hdbc, self, res);
-           QLOG(0, "                 prepare=%d, external=%d\n", self->prepare, self->external);
-           QLOG(0, "                 bindings=%p, bindings_allocated=%d\n", opts->bindings, opts->allocated);
-           QLOG(0, "                 parameters=%p, parameters_allocated=%d\n", apdopts->parameters, apdopts->allocated);
-           QLOG(0, "                 statement_type=%d, statement='%s'\n", self->statement_type, NULLCHECK(self->statement));
-           QLOG(0, "                 stmt_with_params='%s'\n", NULLCHECK(self->stmt_with_params));
-           QLOG(0, "                 data_at_exec=%d, current_exec_param=%d, put_data=%d\n", self->data_at_exec, self->current_exec_param, self->put_data);
-           QLOG(0, "                 currTuple=" FORMAT_LEN ", current_col=%d, lobj_fd=%d\n", self->currTuple, self->current_col, self->lobj_fd);
-           QLOG(0, "                 maxRows=" FORMAT_LEN ", rowset_size=" FORMAT_LEN ", keyset_size=" FORMAT_LEN ", cursor_type=%u, scroll_concurrency=%d\n", self->options.maxRows, rowsetSize, self->options.keyset_size, self->options.cursor_type, self->options.scroll_concurrency);
-           QLOG(0, "                 cursor_name='%s'\n", SC_cursor_name(self));
-
-           QLOG(0, "                 ----------------QResult Info -------------------------------\n");
+           QLOG(level, "                 ------------------------------------------------------------\n");
+           QLOG(level, "                 hdbc=%p, stmt=%p, result=%p\n", self->hdbc, self, res);
+           QLOG(level, "                 prepare=%d, external=%d\n", self->prepare, self->external);
+           QLOG(level, "                 bindings=%p, bindings_allocated=%d\n", opts->bindings, opts->allocated);
+           QLOG(level, "                 parameters=%p, parameters_allocated=%d\n", apdopts->parameters, apdopts->allocated);
+           QLOG(level, "                 statement_type=%d, statement='%s'\n", self->statement_type, NULLCHECK(self->statement));
+           QLOG(level, "                 stmt_with_params='%s'\n", NULLCHECK(self->stmt_with_params));
+           QLOG(level, "                 data_at_exec=%d, current_exec_param=%d, put_data=%d\n", self->data_at_exec, self->current_exec_param, self->put_data);
+           QLOG(level, "                 currTuple=" FORMAT_LEN ", current_col=%d, lobj_fd=%d\n", self->currTuple, self->current_col, self->lobj_fd);
+           QLOG(level, "                 maxRows=" FORMAT_LEN ", rowset_size=" FORMAT_LEN ", keyset_size=" FORMAT_LEN ", cursor_type=%u, scroll_concurrency=%d\n", self->options.maxRows, rowsetSize, self->options.keyset_size, self->options.cursor_type, self->options.scroll_concurrency);
+           QLOG(level, "                 cursor_name='%s'\n", SC_cursor_name(self));
+
+           QLOG(level, "                 ----------------QResult Info -------------------------------\n");
 
            if (res)
            {
-               QLOG(0, "                 fields=%p, backend_tuples=%p, tupleField=%p, conn=%p\n", QR_get_fields(res), res->backend_tuples, res->tupleField, res->conn);
-               QLOG(0, "                 fetch_count=" FORMAT_LEN ", num_total_rows=" FORMAT_ULEN ", num_fields=%d, cursor='%s'\n", res->fetch_number, QR_get_num_total_tuples(res), res->num_fields, NULLCHECK(QR_get_cursor(res)));
-               QLOG(0, "                 message='%s', command='%s', notice='%s'\n", NULLCHECK(QR_get_message(res)), NULLCHECK(res->command), NULLCHECK(res->notice));
-               QLOG(0, "                 status=%d\n", QR_get_rstatus(res));
+               QLOG(level, "                 fields=%p, backend_tuples=%p, tupleField=%p, conn=%p\n", QR_get_fields(res), res->backend_tuples, res->tupleField, res->conn);
+               QLOG(level, "                 fetch_count=" FORMAT_LEN ", num_total_rows=" FORMAT_ULEN ", num_fields=%d, cursor='%s'\n", res->fetch_number, QR_get_num_total_tuples(res), res->num_fields, NULLCHECK(QR_get_cursor(res)));
+               QLOG(level, "                 message='%s', command='%s', notice='%s'\n", NULLCHECK(QR_get_message(res)), NULLCHECK(res->command), NULLCHECK(res->notice));
+               QLOG(level, "                 status=%d\n", QR_get_rstatus(res));
            }
 
            /* Log the connection error if there is one */
@@ -2380,7 +2381,6 @@ SC_log_error(const char *func, const char *desc, const StatementClass *self)
    }
    else
    {
-       QLOG(0, "INVALID STATEMENT HANDLE ERROR: func=%s, desc='%s'\n", func, desc);
        MYLOG(0, "INVALID STATEMENT HANDLE ERROR: func=%s, desc='%s'\n", func, desc);
    }
 }
@@ -2503,7 +2503,7 @@ libpq_bind_and_exec(StatementClass *stmt)
 
        pstmt = stmt->processed_statements;
        MYLOG(0, "%s execParams query=%s nParams=%d\n", __FUNCTION__, pstmt->query, nParams);
-       QLOG(0, "PQexecParams query='%s' nParams=%d\n", pstmt->query, nParams);
+       QLOG(0, "PQexecParams: %p '%s' nParams=%d\n", conn->pqconn, pstmt->query, nParams);
        pgres = PQexecParams(conn->pqconn,
                             pstmt->query,
                             nParams,
@@ -2528,7 +2528,7 @@ libpq_bind_and_exec(StatementClass *stmt)
 
        /* already prepared */
        MYLOG(0, "%s execPrepared plan=%s nParams=%d\n", __FUNCTION__, plan_name, nParams);
-       QLOG(0, "PQexecPrepared plan=%s nParams=%d\n", plan_name, nParams);
+       QLOG(0, "PQexecPrepared: %p plan=%s nParams=%d\n", conn->pqconn, plan_name, nParams);
        pgres = PQexecPrepared(conn->pqconn,
                               plan_name,   /* portal name == plan name */
                               nParams,
@@ -2562,7 +2562,7 @@ MYLOG(1, "get_Result=%p %p %d\n", res, SC_get_Result(stmt), stmt->curr_param_res
            /* read in the return message from the backend */
            cmdtag = PQcmdStatus(pgres);
            MYLOG(0, "command response: %s\n", cmdtag);
-           QLOG(0, "ok: %s\n", cmdtag);
+           QLOG(0, "\tok: - 'C' - %s\n", cmdtag);
            QR_set_command(res, cmdtag);
            if (QR_command_successful(res))
                QR_set_rstatus(res, PORES_COMMAND_OK);
@@ -2603,7 +2603,7 @@ MYLOG(1, "get_Result=%p %p %d\n", res, SC_get_Result(stmt), stmt->curr_param_res
            CC_on_abort(conn, CONN_DEAD);
 
            MYLOG(0, "send_query: error - %s\n", CC_get_errormsg(conn));
-           QLOG(0, "error: - %s\n", CC_get_errormsg(conn));
+           QLOG(0, "error: - (%d) - %s\n", pgresstatus, CC_get_errormsg(conn));
            break;
    }
 
@@ -2652,7 +2652,6 @@ ParseWithLibpq(StatementClass *stmt, const char *plan_name,
    PGresult   *pgres = NULL;
 
    MYLOG(0, "%s: plan_name=%s query=%s\n", func, plan_name, query);
-   QLOG(0, "%s: plan_name=%s query=%s\n", func, plan_name, query);
    if (!RequestStart(stmt, conn, func))
        return FALSE;
 
@@ -2734,13 +2733,14 @@ MYLOG(0, "sta_pidx=%d end_pidx=%d num_p=%d\n", sta_pidx, end_pidx, num_params);
        conn->unnamed_prepared_stmt = NULL;
 
    /* Prepare */
-   QLOG(0, "PQprepare query='%s' plan=%s num_params=%d\n", query, plan_name, num_params);
+   QLOG(0, "PQprepare: %p '%s' plan=%s num_params=%d\n", conn->pqconn, query, plan_name, num_params);
    pgres = PQprepare(conn->pqconn, plan_name, query, num_params, paramTypes);
    if (PQresultStatus(pgres) != PGRES_COMMAND_OK)
    {
        handle_pgres_error(conn, pgres, "ParseWithlibpq", res, TRUE);
        goto cleanup;
    }
+   QLOG(0, "\tok: - 'C' - %s\n", PQcmdStatus(pgres));
 MYLOG(0, "PQprepare was successful, plan=%s\n", plan_name ? plan_name : "");
    if (stmt->plan_name)
        SC_set_prepared(stmt, PREPARED_PERMANENTLY);
@@ -2791,7 +2791,6 @@ ParseAndDescribeWithLibpq(StatementClass *stmt, const char *plan_name,
    SQLSMALLINT paramType;
 
    MYLOG(0, "%s: plan_name=%s query=%s\n", func, plan_name, query_param);
-   QLOG(0, "%s: plan_name=%s query=%s\n", func, plan_name, query_param);
    if (!RequestStart(stmt, conn, func))
        return NULL;
 
@@ -2813,12 +2812,13 @@ ParseAndDescribeWithLibpq(StatementClass *stmt, const char *plan_name,
 
    /* Describe */
    MYLOG(0, "%s: describing plan_name=%s\n", func, plan_name);
-   QLOG(0, "\tPQdescribePrepared: plan_name=%s\n", plan_name);
+   QLOG(0, "\tPQdescribePrepared: %p plan_name=%s\n", conn->pqconn, plan_name);
 
    pgres = PQdescribePrepared(conn->pqconn, plan_name);
    switch (PQresultStatus(pgres))
    {
        case PGRES_COMMAND_OK:
+           QLOG(0, "\tok: - 'C' - %s\n", PQcmdStatus(pgres));
            /* expected */
            break;
        case PGRES_NONFATAL_ERROR: