libpq: Trace frontend authentication challenges

If tracing was enabled during connection startup, these messages would
previously be listed in the trace output as something like this:

F	54	Unknown message: 70
mismatched message length: consumed 4, expected 54

With this commit their type and contents are now correctly listed:

F	36	StartupMessage	 3 0 "user" "foo" "database" "alvherre"
F	54	SASLInitialResponse	 "SCRAM-SHA-256" 32 'n,,n=,r=nq5zEPR/VREHEpOAZzH8Rujm'
F	108	SASLResponse	 'c=biws,r=nq5zEPR/VREHEpOAZzH8RujmVtWZDQ8glcrvy9OMNw7ZqFUn,p=BBwAKe0WjSvigB6RsmmArAC+hwucLeuwJrR5C/HQD5M='

Author: Jelte Fennema-Nio <[email protected]>
Reviewed-by: Michael Paquier <[email protected]>
Discussion: https://postgr.es/m/CAGECzQSoPHtZ4xe0raJ6FYSEiPPS+YWXBhOGo+Y1YecLgknF3g@mail.gmail.com

diff --git a/src/interfaces/libpq/fe-auth.c b/src/interfaces/libpq/fe-auth.c
index 3b25d8afda475d01a16471370c97647ee1cca25c..4da07c1f9864831ab0be375bb4cbabe1a99a56c4 100644 (file)
--- a/src/interfaces/libpq/fe-auth.c
+++ b/src/interfaces/libpq/fe-auth.c
@@ -124,6 +124,7 @@ pg_GSS_continue(PGconn *conn, int payloadlen)
                 * first or subsequent packet, just send the same kind of password
                 * packet.
                 */
+               conn->current_auth_response = AUTH_RESPONSE_GSS;
                if (pqPacketSend(conn, PqMsg_GSSResponse,
                                                 goutbuf.value, goutbuf.length) != STATUS_OK)
                {
@@ -324,6 +325,7 @@ pg_SSPI_continue(PGconn *conn, int payloadlen)
                 */
                if (outbuf.pBuffers[0].cbBuffer > 0)
                {
+                       conn->current_auth_response = AUTH_RESPONSE_GSS;
                        if (pqPacketSend(conn, PqMsg_GSSResponse,
                                                         outbuf.pBuffers[0].pvBuffer, outbuf.pBuffers[0].cbBuffer))
                        {
@@ -597,8 +599,10 @@ pg_SASL_init(PGconn *conn, int payloadlen)
                if (pqPutnchar(initialresponse, initialresponselen, conn))
                        goto error;
        }
+       conn->current_auth_response = AUTH_RESPONSE_SASL_INITIAL;
        if (pqPutMsgEnd(conn))
                goto error;
+
        if (pqFlush(conn))
                goto error;
 
@@ -683,6 +687,7 @@ pg_SASL_continue(PGconn *conn, int payloadlen, bool final)
                /*
                 * Send the SASL response to the server.
                 */
+               conn->current_auth_response = AUTH_RESPONSE_SASL;
                res = pqPacketSend(conn, PqMsg_SASLResponse, output, outputlen);
                free(output);
 
@@ -754,6 +759,7 @@ pg_password_sendauth(PGconn *conn, const char *password, AuthRequest areq)
                default:
                        return STATUS_ERROR;
        }
+       conn->current_auth_response = AUTH_RESPONSE_PASSWORD;
        ret = pqPacketSend(conn, PqMsg_PasswordMessage,
                                           pwd_to_send, strlen(pwd_to_send) + 1);
        free(crypt_pwd);

diff --git a/src/interfaces/libpq/fe-trace.c b/src/interfaces/libpq/fe-trace.c
index c34047a6e46245aae7ae31deba86940d83d9d184..367b322b992f0ef34de45e1f47ebe43e59b6f547 100644 (file)
--- a/src/interfaces/libpq/fe-trace.c
+++ b/src/interfaces/libpq/fe-trace.c
@@ -354,6 +354,42 @@ pqTraceOutput_CopyFail(FILE *f, const char *message, int *cursor)
        pqTraceOutputString(f, message, cursor, false);
 }
 
+static void
+pqTraceOutput_GSSResponse(FILE *f, const char *message, int *cursor,
+                                                 int length, bool regress)
+{
+       fprintf(f, "GSSResponse\t");
+       pqTraceOutputNchar(f, length - *cursor + 1, message, cursor, regress);
+}
+
+static void
+pqTraceOutput_PasswordMessage(FILE *f, const char *message, int *cursor)
+{
+       fprintf(f, "PasswordMessage\t");
+       pqTraceOutputString(f, message, cursor, false);
+}
+
+static void
+pqTraceOutput_SASLInitialResponse(FILE *f, const char *message, int *cursor,
+                                                                 bool regress)
+{
+       int                     initialResponse;
+
+       fprintf(f, "SASLInitialResponse\t");
+       pqTraceOutputString(f, message, cursor, false);
+       initialResponse = pqTraceOutputInt32(f, message, cursor, false);
+       if (initialResponse != -1)
+               pqTraceOutputNchar(f, initialResponse, message, cursor, regress);
+}
+
+static void
+pqTraceOutput_SASLResponse(FILE *f, const char *message, int *cursor,
+                                                  int length, bool regress)
+{
+       fprintf(f, "SASLResponse\t");
+       pqTraceOutputNchar(f, length - *cursor + 1, message, cursor, regress);
+}
+
 static void
 pqTraceOutput_FunctionCall(FILE *f, const char *message, int *cursor, bool regress)
 {
@@ -610,6 +646,39 @@ pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer)
                case PqMsg_CopyFail:
                        pqTraceOutput_CopyFail(conn->Pfdebug, message, &logCursor);
                        break;
+               case PqMsg_GSSResponse:
+                       Assert(PqMsg_GSSResponse == PqMsg_PasswordMessage);
+                       Assert(PqMsg_GSSResponse == PqMsg_SASLInitialResponse);
+                       Assert(PqMsg_GSSResponse == PqMsg_SASLResponse);
+
+                       /*
+                        * These messages share a common type byte, so we discriminate by
+                        * having the code store the auth type separately.
+                        */
+                       switch (conn->current_auth_response)
+                       {
+                               case AUTH_RESPONSE_GSS:
+                                       pqTraceOutput_GSSResponse(conn->Pfdebug, message,
+                                                                                         &logCursor, length, regress);
+                                       break;
+                               case AUTH_RESPONSE_PASSWORD:
+                                       pqTraceOutput_PasswordMessage(conn->Pfdebug, message,
+                                                                                                 &logCursor);
+                                       break;
+                               case AUTH_RESPONSE_SASL_INITIAL:
+                                       pqTraceOutput_SASLInitialResponse(conn->Pfdebug, message,
+                                                                                                         &logCursor, regress);
+                                       break;
+                               case AUTH_RESPONSE_SASL:
+                                       pqTraceOutput_SASLResponse(conn->Pfdebug, message,
+                                                                                          &logCursor, length, regress);
+                                       break;
+                               default:
+                                       fprintf(conn->Pfdebug, "UnknownAuthenticationResponse");
+                                       break;
+                       }
+                       conn->current_auth_response = '\0';
+                       break;
                case PqMsg_FunctionCall:
                        pqTraceOutput_FunctionCall(conn->Pfdebug, message, &logCursor, regress);
                        break;

diff --git a/src/interfaces/libpq/libpq-int.h b/src/interfaces/libpq/libpq-int.h
index f36d76bf3fedfdf8bdd387ec480e420d7dd37d1a..03e4da40ba1d98c79c77e3c7fc2e29aaf29c3f48 100644 (file)
--- a/src/interfaces/libpq/libpq-int.h
+++ b/src/interfaces/libpq/libpq-int.h
@@ -331,6 +331,18 @@ typedef enum
        PGQUERY_CLOSE                           /* Close Statement or Portal */
 } PGQueryClass;
 
+
+/*
+ * valid values for pg_conn->current_auth_response.  These are just for
+ * libpq internal use: since authentication response types all use the
+ * protocol byte 'p', fe-trace.c needs a way to distinguish them in order
+ * to print them correctly.
+ */
+#define AUTH_RESPONSE_GSS                      'G'
+#define AUTH_RESPONSE_PASSWORD         'P'
+#define AUTH_RESPONSE_SASL_INITIAL     'I'
+#define AUTH_RESPONSE_SASL                     'S'
+
 /*
  * An entry in the pending command queue.
  */
@@ -490,7 +502,9 @@ struct pg_conn
                                                                                 * codes */
        bool            client_finished_auth;   /* have we finished our half of the
                                                                                 * authentication exchange? */
-
+       char            current_auth_response;  /* used by pqTraceOutputMessage to
+                                                                                * know which auth response we're
+                                                                                * sending */
 
        /* Transient state needed while establishing connection */
        PGTargetServerType target_server_type;  /* desired session properties */