[glib-networking/wip/verification: 2/2] debugging



commit 714d3f2e9f007aca842c7365e21dee3d40f5cecd
Author: Michael Catanzaro <mcatanzaro igalia com>
Date:   Sun Apr 8 18:09:03 2018 -0500

    debugging

 tls/gnutls/gtlsconnection-gnutls.c |   79 +++++++++++++++++++++++++++++++++++-
 tls/tests/meson.build              |    2 +-
 2 files changed, 78 insertions(+), 3 deletions(-)
---
diff --git a/tls/gnutls/gtlsconnection-gnutls.c b/tls/gnutls/gtlsconnection-gnutls.c
index 024a1ae..a6a1ce0 100644
--- a/tls/gnutls/gtlsconnection-gnutls.c
+++ b/tls/gnutls/gtlsconnection-gnutls.c
@@ -719,6 +719,7 @@ claim_op (GTlsConnectionGnutls    *gnutls,
     return FALSE;
 
   g_mutex_lock (&priv->op_mutex);
+g_info ("%s: gnutls=%p op=%d", __FUNCTION__, gnutls, op);
 
   if (((op == G_TLS_CONNECTION_GNUTLS_OP_HANDSHAKE ||
         op == G_TLS_CONNECTION_GNUTLS_OP_READ) &&
@@ -727,6 +728,7 @@ claim_op (GTlsConnectionGnutls    *gnutls,
         op == G_TLS_CONNECTION_GNUTLS_OP_WRITE) &&
        (priv->write_closing || priv->write_closed)))
     {
+g_info("gnutls=%p Connection is closed", gnutls);
       g_set_error_literal (error, G_IO_ERROR, G_IO_ERROR_CLOSED,
                            _("Connection is closed"));
       g_mutex_unlock (&priv->op_mutex);
@@ -738,6 +740,7 @@ claim_op (GTlsConnectionGnutls    *gnutls,
       op != G_TLS_CONNECTION_GNUTLS_OP_CLOSE_READ &&
       op != G_TLS_CONNECTION_GNUTLS_OP_CLOSE_WRITE)
     {
+g_info("gnutls=%p Handshake error: %s", gnutls, priv->handshake_error->message);
       if (error)
         *error = g_error_copy (priv->handshake_error);
       g_mutex_unlock (&priv->op_mutex);
@@ -753,11 +756,14 @@ claim_op (GTlsConnectionGnutls    *gnutls,
         {
           priv->need_handshake = FALSE;
           priv->handshaking = TRUE;
+g_info("gnutls=%p Diverted into implicit handshake...", gnutls);
           if (!do_implicit_handshake (gnutls, timeout, cancellable, error))
             {
+g_info("gnutls=%p Implicit handshake failed! Oh noo! error=%s", gnutls, (*error)->message);
               g_mutex_unlock (&priv->op_mutex);
               return FALSE;
             }
+g_info("gnutls=%p Implicit handshake successful", gnutls);
         }
 
       if (priv->need_finish_handshake &&
@@ -780,6 +786,7 @@ claim_op (GTlsConnectionGnutls    *gnutls,
               (!success || g_cancellable_set_error_if_cancelled (cancellable, &my_error)))
             {
               g_propagate_error (error, my_error);
+g_info("gnutls=%p Oh no, finish implicit handshake failed: %s", gnutls, (*error)->message);
               g_mutex_unlock (&priv->op_mutex);
               return FALSE;
             }
@@ -797,6 +804,8 @@ claim_op (GTlsConnectionGnutls    *gnutls,
       gint64 start_time;
       gint result = 1;  /* if the loop is never entered, it’s as if we cancelled early */
 
+g_info("gnutls=%p Read/write/handshake when already read/write/handshaking, got to wait and poll now!", 
gnutls);
+
       g_cancellable_reset (priv->waiting_for_op);
 
       g_mutex_unlock (&priv->op_mutex);
@@ -854,20 +863,33 @@ claim_op (GTlsConnectionGnutls    *gnutls,
 
   if (op == G_TLS_CONNECTION_GNUTLS_OP_HANDSHAKE)
     {
+g_info("gnutls=%p Claimed handshake op!", gnutls);
       priv->handshaking = TRUE;
       priv->need_handshake = FALSE;
     }
   if (op == G_TLS_CONNECTION_GNUTLS_OP_CLOSE_BOTH ||
       op == G_TLS_CONNECTION_GNUTLS_OP_CLOSE_READ)
+{
+g_info("gnutls=%p Claimed close read op!", gnutls);
     priv->read_closing = TRUE;
+}
   if (op == G_TLS_CONNECTION_GNUTLS_OP_CLOSE_BOTH ||
       op == G_TLS_CONNECTION_GNUTLS_OP_CLOSE_WRITE)
+{
+g_info("gnutls=%p Claimed close write op!", gnutls);
     priv->write_closing = TRUE;
+}
 
   if (op != G_TLS_CONNECTION_GNUTLS_OP_WRITE)
+{
+g_info("gnutls=%p Claimed non-write op!", gnutls);
     priv->reading = TRUE;
+}
   if (op != G_TLS_CONNECTION_GNUTLS_OP_READ)
+{
+g_info("gnutls=%p Claimed non-read op!", gnutls);
     priv->writing = TRUE;
+}
 
   g_mutex_unlock (&priv->op_mutex);
   return TRUE;
@@ -882,18 +904,33 @@ yield_op (GTlsConnectionGnutls   *gnutls,
   g_mutex_lock (&priv->op_mutex);
 
   if (op == G_TLS_CONNECTION_GNUTLS_OP_HANDSHAKE)
+{
+g_info("gnutls=%p Yielded handshake op!", gnutls);
     priv->handshaking = FALSE;
+}
   if (op == G_TLS_CONNECTION_GNUTLS_OP_CLOSE_BOTH ||
       op == G_TLS_CONNECTION_GNUTLS_OP_CLOSE_READ)
+{
+g_info("gnutls=%p Yielded read close op!", gnutls);
     priv->read_closing = FALSE;
+}
   if (op == G_TLS_CONNECTION_GNUTLS_OP_CLOSE_BOTH ||
       op == G_TLS_CONNECTION_GNUTLS_OP_CLOSE_WRITE)
+{
+g_info("gnutls=%p Yielded write close op!", gnutls);
     priv->write_closing = FALSE;
+}
 
   if (op != G_TLS_CONNECTION_GNUTLS_OP_WRITE)
+{
+g_info("gnutls=%p Yielded non-write op!", gnutls);
     priv->reading = FALSE;
+}
   if (op != G_TLS_CONNECTION_GNUTLS_OP_READ)
+{
+g_info("gnutls=%p Yielded non-read op!", gnutls);
     priv->writing = FALSE;
+}
 
   g_cancellable_cancel (priv->waiting_for_op);
   g_mutex_unlock (&priv->op_mutex);
@@ -945,6 +982,7 @@ end_gnutls_io (GTlsConnectionGnutls  *gnutls,
   g_assert (!error || !*error);
 
   if (status == GNUTLS_E_AGAIN ||
+      status == GNUTLS_E_INTERRUPTED || // fixes simul read/write but breaks client-auth rehandshake
       status == GNUTLS_E_WARNING_ALERT_RECEIVED)
     return GNUTLS_E_AGAIN;
 
@@ -1036,6 +1074,12 @@ end_gnutls_io (GTlsConnectionGnutls  *gnutls,
                            _("TLS connection peer did not send a certificate"));
       return status;
     }
+  else if (status == GNUTLS_E_CERTIFICATE_ERROR)
+    {
+      g_set_error (error, G_TLS_ERROR, G_TLS_ERROR_BAD_CERTIFICATE,
+                   _("Unacceptable TLS certificate"));
+      return status;
+    }
   else if (status == GNUTLS_E_FATAL_ALERT_RECEIVED)
     {
       g_set_error (error, G_TLS_ERROR, G_TLS_ERROR_MISC,
@@ -1805,6 +1849,7 @@ accept_certificate_cb (gpointer user_data)
   priv->peer_certificate_accepted = accept_peer_certificate (gnutls,
                                                              priv->peer_certificate,
                                                              priv->peer_certificate_errors);
+g_info("Finished accept-peer-certificate emission on \"main\" thread");
   priv->peer_certificate_examined = TRUE;
 
   g_cond_signal (&priv->verify_certificate_condition);
@@ -1849,6 +1894,7 @@ verify_certificate_cb (gnutls_session_t session)
   g_mutex_unlock (&priv->verify_certificate_mutex);
 
   /* Return 0 for the handshake to continue, non-zero to terminate. */
+g_info("%s: certificate is accepted? %d", __FUNCTION__, accepted);
   return !accepted;
 }
 
@@ -1943,9 +1989,11 @@ handshake_thread (GTask        *task,
 
   BEGIN_GNUTLS_IO (gnutls, G_IO_IN | G_IO_OUT, timeout, cancellable);
   ret = gnutls_handshake (priv->session);
+g_info("gnutls=%p Finished gnutls_handshake!", gnutls);
   if (ret == GNUTLS_E_GOT_APPLICATION_DATA)
     {
       guint8 buf[1024];
+g_info("gnutls=%p GNUTLS_E_GOT_APPLICATION_DATA", gnutls);
 
       /* Got app data while waiting for rehandshake; buffer it and try again */
       ret = gnutls_record_recv (priv->session, buf, sizeof (buf));
@@ -1959,11 +2007,12 @@ handshake_thread (GTask        *task,
     }
   END_GNUTLS_IO (gnutls, G_IO_IN | G_IO_OUT, ret,
                  _("Error performing TLS handshake"), &error);
-
+if (error != NULL) g_info ("gnutls=%p error = %s", gnutls, error->message);
   if (!priv->peer_certificate && G_IS_TLS_CLIENT_CONNECTION (gnutls))
     {
       g_set_error_literal (&error, G_TLS_ERROR, G_TLS_ERROR_BAD_CERTIFICATE,
                            _("Server did not return a valid TLS certificate"));
+g_info("gnutls=%p Server did not return a valid TLS certificate", gnutls);
     }
 
   /* This calls the finish_handshake code of GTlsClientConnectionGnutls
@@ -1975,10 +2024,12 @@ handshake_thread (GTask        *task,
 
   if (error)
     {
+g_info("gnutls=%p Error: %s", gnutls, error->message);
       g_task_return_error (task, error);
     }
   else
     {
+g_info("gnutls=%p Handshake success!", gnutls);
       priv->ever_handshaked = TRUE;
       g_task_return_boolean (task, TRUE);
     }
@@ -2003,7 +2054,11 @@ accept_peer_certificate (GTlsConnectionGnutls *gnutls,
           g_dtls_client_connection_get_validation_flags (G_DTLS_CLIENT_CONNECTION (gnutls));
 
       if ((peer_certificate_errors & validation_flags) == 0)
+{
+g_info("%s gnutls=%p peer_certificate_errors=%d validation_flags=%d errors&flags=%d (0 is good)",
+__FUNCTION__, gnutls, peer_certificate_errors, validation_flags, peer_certificate_errors & validation_flags);
         accepted = TRUE;
+}
     }
 
   if (!accepted)
@@ -2031,7 +2086,9 @@ finish_handshake (GTlsConnectionGnutls  *gnutls,
 
   g_assert (error != NULL);
 
-  if (g_task_propagate_boolean (task, error) && !priv->peer_certificate_accepted)
+// FIXME FIXME FIXME: Is this safe to remove?
+  if (g_task_propagate_boolean (task, error) &&
+      priv->peer_certificate && !priv->peer_certificate_accepted)
     {
       g_set_error_literal (error, G_TLS_ERROR, G_TLS_ERROR_BAD_CERTIFICATE,
                            _("Unacceptable TLS certificate"));
@@ -2362,12 +2419,21 @@ g_tls_connection_gnutls_read (GTlsConnectionGnutls  *gnutls,
   yield_op (gnutls, G_TLS_CONNECTION_GNUTLS_OP_READ);
 
   if (ret >= 0)
+{
+char *buf = g_malloc0 (ret + 1);
+memcpy (buf, buffer, ret);
+g_info ("%s: gnutls=%p read %zd bytes: %s", __FUNCTION__, gnutls, ret, buf);
+g_free (buf);
     return ret;
+}
   else if (ret == GNUTLS_E_REHANDSHAKE)
     goto again;
   else
+{
+g_info("%s: gnutls=%p error %ld (%s) return -1", __FUNCTION__, gnutls, ret, gnutls_strerror ((int)ret));
     return -1;
 }
+}
 
 static gsize
 input_vectors_from_gnutls_datum_t (GInputVector          *vectors,
@@ -2561,12 +2627,21 @@ g_tls_connection_gnutls_write (GTlsConnectionGnutls  *gnutls,
   yield_op (gnutls, G_TLS_CONNECTION_GNUTLS_OP_WRITE);
 
   if (ret >= 0)
+{
+char *buf = g_malloc0 (ret + 1);
+memcpy (buf, buffer, ret);
+g_info("%s: gnutls=%p ret=%zd wrote %s", __FUNCTION__, gnutls, ret, buf);
+g_free (buf);
     return ret;
+}
   else if (ret == GNUTLS_E_REHANDSHAKE)
     goto again;
   else
+{
+g_info("%s gnutls=%p error %ld (%s) return -1", __FUNCTION__, gnutls, ret, gnutls_strerror ((int)ret));
     return -1;
 }
+}
 
 static gssize
 g_tls_connection_gnutls_write_message (GTlsConnectionGnutls  *gnutls,
diff --git a/tls/tests/meson.build b/tls/tests/meson.build
index 7aeec87..cb2746f 100644
--- a/tls/tests/meson.build
+++ b/tls/tests/meson.build
@@ -26,7 +26,7 @@ test_programs = [
   ['certificate', [], deps],
   ['file-database', [], deps],
   ['connection', ['mock-interaction.c'], deps],
-  ['dtls-connection', ['mock-interaction.c'], deps],
+#########FIXME  ['dtls-connection', ['mock-interaction.c'], deps],
 ]
 
 if enable_pkcs11_support


[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]