fix off-by-one error in cadet connection construction, also enforce better timeouts for retransmissions of handshake

7 files changed, 407 insertions, 73 deletions

diff --git a/src/cadet/cadet_protocol.h b/src/cadet/cadet_protocol.h
index de0cec5d0..d4a40f9e5 100644
--- a/src/cadet/cadet_protocol.h
+++ b/src/cadet/cadet_protocol.h
@@ -28,6 +28,14 @@
 #ifndef CADET_PROTOCOL_H_
 #define CADET_PROTOCOL_H_
 
+/**
+ * At best, enable when debugging #5328!
+ */
+#define DEBUG_KX 0
+#if DEBUG_KX
+#warning NEVER run this in production! KX debugging is on!
+#endif
+
 #include "platform.h"
 #include "gnunet_util_lib.h"
 #include "cadet.h"
@@ -234,6 +242,22 @@ struct GNUNET_CADET_TunnelKeyExchangeMessage
    */
   struct GNUNET_CRYPTO_EcdhePublicKey ephemeral_key;
 
+#if DEBUG_KX
+  /**
+   * Sender's ephemeral public ECC key encoded in a
+   * format suitable for network transmission, as created
+   * using 'gcry_sexp_sprint'.
+   */
+  struct GNUNET_CRYPTO_EcdhePrivateKey ephemeral_key_XXX; // for debugging KX-crypto!
+
+  /**
+   * Sender's ephemeral public ECC key encoded in a
+   * format suitable for network transmission, as created
+   * using 'gcry_sexp_sprint'.
+   */
+  struct GNUNET_CRYPTO_EddsaPrivateKey private_key_XXX; // for debugging KX-crypto!
+#endif
+
   /**
    * Sender's next ephemeral public ECC key encoded in a
    * format suitable for network transmission, as created
@@ -256,6 +280,15 @@ struct GNUNET_CADET_TunnelKeyExchangeAuthMessage
    */
   struct GNUNET_CADET_TunnelKeyExchangeMessage kx;
 
+#if DEBUG_KX
+  /**
+   * Received ephemeral public ECC key encoded in a
+   * format suitable for network transmission, as created
+   * using 'gcry_sexp_sprint'.
+   */
+  struct GNUNET_CRYPTO_EcdhePublicKey r_ephemeral_key_XXX; // for debugging KX-crypto!
+#endif
+
   /**
    * KDF-proof that sender could compute the 3-DH, used in lieu of a
    * signature or payload data.
diff --git a/src/cadet/gnunet-service-cadet_connection.c b/src/cadet/gnunet-service-cadet_connection.c
index 82ab5cc2c..9ff62b29f 100644
--- a/src/cadet/gnunet-service-cadet_connection.c
+++ b/src/cadet/gnunet-service-cadet_connection.c
@@ -39,6 +39,13 @@
 
 
 /**
+ * How long do we wait initially before retransmitting the KX?
+ * TODO: replace by 2 RTT if/once we have connection-level RTT data!
+ */
+#define INITIAL_CONNECTION_CREATE_RETRY_DELAY GNUNET_TIME_relative_multiply(GNUNET_TIME_UNIT_MILLISECONDS, 200)
+
+
+/**
  * All the states a connection can be in.
  */
 enum CadetConnectionState
@@ -134,6 +141,16 @@ struct CadetConnection
   struct GNUNET_TIME_Relative retry_delay;
 
   /**
+   * Earliest time for re-trying CREATE
+   */
+  struct GNUNET_TIME_Absolute create_at;
+
+  /**
+   * Earliest time for re-trying CREATE_ACK
+   */
+  struct GNUNET_TIME_Absolute create_ack_at;
+
+  /**
    * Performance metrics for this connection.
    */
   struct CadetConnectionMetrics metrics;
@@ -482,8 +499,9 @@ GCC_latency_observed (const struct GNUNET_CADET_ConnectionTunnelIdentifier *cid,
 
 
 /**
- * A #GNUNET_MESSAGE_TYPE_CADET_CONNECTION_CREATE_ACK was received for this connection, implying
- * that the end-to-end connection is up.  Process it.
+ * A #GNUNET_MESSAGE_TYPE_CADET_CONNECTION_CREATE_ACK was received for
+ * this connection, implying that the end-to-end connection is up.
+ * Process it.
  *
  * @param cc the connection that got the ACK.
  */
@@ -525,6 +543,11 @@ void
 GCC_handle_kx (struct CadetConnection *cc,
                const struct GNUNET_CADET_TunnelKeyExchangeMessage *msg)
 {
+  LOG (GNUNET_ERROR_TYPE_DEBUG,
+       "Received KX message with ephermal %s on CC %s in state %d\n",
+       GNUNET_e2s (&msg->ephemeral_key),
+       GNUNET_sh2s (&cc->cid.connection_of_tunnel),
+       cc->state);
   if (CADET_CONNECTION_SENT == cc->state)
   {
     /* We didn't get the CADET_CONNECTION_CREATE_ACK, but instead got payload. That's fine,
@@ -549,6 +572,11 @@ void
 GCC_handle_kx_auth (struct CadetConnection *cc,
                     const struct GNUNET_CADET_TunnelKeyExchangeAuthMessage *msg)
 {
+  LOG (GNUNET_ERROR_TYPE_DEBUG,
+       "Received KX AUTH message with ephermal %s on CC %s in state %d\n",
+       GNUNET_e2s (&msg->kx.ephemeral_key),
+       GNUNET_sh2s (&cc->cid.connection_of_tunnel),
+       cc->state);
   if (CADET_CONNECTION_SENT == cc->state)
   {
     /* We didn't get the CADET_CONNECTION_CREATE_ACK, but instead got payload. That's fine,
@@ -601,25 +629,26 @@ send_create (void *cls)
   struct GNUNET_CADET_ConnectionCreateMessage *create_msg;
   struct GNUNET_PeerIdentity *pids;
   struct GNUNET_MQ_Envelope *env;
-  unsigned int path_length;
 
   cc->task = NULL;
   GNUNET_assert (GNUNET_YES == cc->mqm_ready);
-  path_length = GCPP_get_length (cc->path);
   env = GNUNET_MQ_msg_extra (create_msg,
-                             (1 + path_length) * sizeof (struct GNUNET_PeerIdentity),
+                             (2 + cc->off) * sizeof (struct GNUNET_PeerIdentity),
                              GNUNET_MESSAGE_TYPE_CADET_CONNECTION_CREATE);
   create_msg->options = htonl ((uint32_t) cc->options);
   create_msg->cid = cc->cid;
   pids = (struct GNUNET_PeerIdentity *) &create_msg[1];
   pids[0] = my_full_id;
-  for (unsigned int i=0;i<path_length;i++)
+  for (unsigned int i=0;i<=cc->off;i++)
     pids[i + 1] = *GCP_get_id (GCPP_get_peer_at_offset (cc->path,
                                                         i));
   LOG (GNUNET_ERROR_TYPE_DEBUG,
-       "Sending CADET_CONNECTION_CREATE message for %s\n",
-       GCC_2s (cc));
+       "Sending CADET_CONNECTION_CREATE message for %s with %u hops\n",
+       GCC_2s (cc),
+       cc->off + 2);
   cc->env = env;
+  cc->retry_delay = GNUNET_TIME_STD_BACKOFF (cc->retry_delay);
+  cc->create_at = GNUNET_TIME_relative_to_absolute (cc->retry_delay);
   update_state (cc,
                 CADET_CONNECTION_SENT,
                 GNUNET_NO);
@@ -641,7 +670,6 @@ send_create_ack (void *cls)
   struct GNUNET_MQ_Envelope *env;
 
   cc->task = NULL;
-  GNUNET_assert (CADET_CONNECTION_CREATE_RECEIVED == cc->state);
   LOG (GNUNET_ERROR_TYPE_DEBUG,
        "Sending CONNECTION_CREATE_ACK message for %s\n",
        GCC_2s (cc));
@@ -650,9 +678,16 @@ send_create_ack (void *cls)
                        GNUNET_MESSAGE_TYPE_CADET_CONNECTION_CREATE_ACK);
   ack_msg->cid = cc->cid;
   cc->env = env;
-  update_state (cc,
-                CADET_CONNECTION_READY,
-                GNUNET_NO);
+  cc->retry_delay = GNUNET_TIME_STD_BACKOFF (cc->retry_delay);
+  cc->create_ack_at = GNUNET_TIME_relative_to_absolute (cc->retry_delay);
+  if (CADET_CONNECTION_CREATE_RECEIVED == cc->state)
+    update_state (cc,
+                  CADET_CONNECTION_READY,
+                  GNUNET_NO);
+  if (CADET_CONNECTION_READY == cc->state)
+    cc->task = GNUNET_SCHEDULER_add_delayed (keepalive_period,
+                                             &send_keepalive,
+                                             cc);
   GCP_send (cc->mq_man,
             env);
 }
@@ -681,8 +716,9 @@ GCC_handle_duplicate_create (struct CadetConnection *cc)
                   cc->mqm_ready);
     if (NULL != cc->task)
       GNUNET_SCHEDULER_cancel (cc->task);
-    cc->task = GNUNET_SCHEDULER_add_now (&send_create_ack,
-                                         cc);
+    cc->task = GNUNET_SCHEDULER_add_at (cc->create_ack_at,
+                                        &send_create_ack,
+                                        cc);
   }
   else
   {
@@ -721,7 +757,7 @@ manage_first_hop_mq (void *cls,
     update_state (cc,
                   CADET_CONNECTION_NEW,
                   GNUNET_NO);
-    cc->retry_delay = GNUNET_TIME_UNIT_ZERO;
+    cc->retry_delay = INITIAL_CONNECTION_CREATE_RETRY_DELAY;
     if (NULL != cc->task)
     {
       GNUNET_SCHEDULER_cancel (cc->task);
@@ -741,8 +777,9 @@ manage_first_hop_mq (void *cls,
   {
   case CADET_CONNECTION_NEW:
     /* Transmit immediately */
-    cc->task = GNUNET_SCHEDULER_add_now (&send_create,
-                                         cc);
+    cc->task = GNUNET_SCHEDULER_add_at (cc->create_at,
+                                        &send_create,
+                                        cc);
     break;
   case CADET_CONNECTION_SENDING_CREATE:
     /* Should not be possible to be called in this state. */
@@ -750,16 +787,16 @@ manage_first_hop_mq (void *cls,
     break;
   case CADET_CONNECTION_SENT:
     /* Retry a bit later... */
-    cc->retry_delay = GNUNET_TIME_STD_BACKOFF (cc->retry_delay);
-    cc->task = GNUNET_SCHEDULER_add_delayed (cc->retry_delay,
-                                             &send_create,
-                                             cc);
+    cc->task = GNUNET_SCHEDULER_add_at (cc->create_at,
+                                        &send_create,
+                                        cc);
     break;
   case CADET_CONNECTION_CREATE_RECEIVED:
     /* We got the 'CREATE' (incoming connection), should send the CREATE_ACK */
     cc->metrics.age = GNUNET_TIME_absolute_get ();
-    cc->task = GNUNET_SCHEDULER_add_now (&send_create_ack,
-                                         cc);
+    cc->task = GNUNET_SCHEDULER_add_at (cc->create_ack_at,
+                                        &send_create_ack,
+                                        cc);
     break;
   case CADET_CONNECTION_READY:
     if ( (NULL == cc->keepalive_qe) &&
@@ -814,6 +851,8 @@ connection_create (struct CadetPeer *destination,
   cc->state = init_state;
   cc->ct = ct;
   cc->cid = *cid;
+  cc->retry_delay = GNUNET_TIME_relative_multiply (INITIAL_CONNECTION_CREATE_RETRY_DELAY,
+                                                   off);
   GNUNET_assert (GNUNET_OK ==
                  GNUNET_CONTAINER_multishortmap_put (connections,
                                                      &GCC_get_id (cc)->connection_of_tunnel,
@@ -824,9 +863,10 @@ connection_create (struct CadetPeer *destination,
   cc->path = path;
   cc->off = off;
   LOG (GNUNET_ERROR_TYPE_DEBUG,
-       "Creating %s using path %s\n",
+       "Creating %s using path %s (offset: %u)\n",
        GCC_2s (cc),
-       GCPP_2s (path));
+       GCPP_2s (path),
+       off);
   GCPP_add_connection (path,
                        off,
                        cc);
@@ -834,7 +874,6 @@ connection_create (struct CadetPeer *destination,
     GCP_add_connection (GCPP_get_peer_at_offset (path,
                                                  i),
                         cc);
-
   first_hop = GCPP_get_peer_at_offset (path,
                                        0);
   cc->mq_man = GCP_request_mq (first_hop,
@@ -1001,11 +1040,14 @@ GCC_transmit (struct CadetConnection *cc,
  * Obtain the path used by this connection.
  *
  * @param cc connection
+ * @param off[out] set to the length of the path we use
  * @return path to @a cc
  */
 struct CadetPeerPath *
-GCC_get_path (struct CadetConnection *cc)
+GCC_get_path (struct CadetConnection *cc,
+              unsigned int *off)
 {
+  *off = cc->off;
   return cc->path;
 }
 
diff --git a/src/cadet/gnunet-service-cadet_connection.h b/src/cadet/gnunet-service-cadet_connection.h
index fdb184366..1c0475d40 100644
--- a/src/cadet/gnunet-service-cadet_connection.h
+++ b/src/cadet/gnunet-service-cadet_connection.h
@@ -300,10 +300,12 @@ GCC_get_ct (struct CadetConnection *cc);
  * Obtain the path used by this connection.
  *
  * @param cc connection
+ * @param off[out] set to offset in this path where the connection @a cc ends
  * @return path to @a cc
  */
 struct CadetPeerPath *
-GCC_get_path (struct CadetConnection *cc);
+GCC_get_path (struct CadetConnection *cc,
+              unsigned int *off);
 
 
 /**
diff --git a/src/cadet/gnunet-service-cadet_core.c b/src/cadet/gnunet-service-cadet_core.c
index 84aff1857..06d1fe3cc 100644
--- a/src/cadet/gnunet-service-cadet_core.c
+++ b/src/cadet/gnunet-service-cadet_core.c
@@ -406,6 +406,28 @@ route_message (struct CadetPeer *prev,
        (NULL != dir->env_head) )
     discard_buffer (dir,
                     dir->env_head);
+  /* Check for duplicates */
+  for (const struct GNUNET_MQ_Envelope *env = dir->env_head;
+       NULL != env;
+       env = GNUNET_MQ_env_next (env))
+  {
+    const struct GNUNET_MessageHeader *hdr = GNUNET_MQ_env_get_msg (env);
+
+    if ( (hdr->size == msg->size) &&
+         (0 == memcmp (hdr,
+                       msg,
+                       ntohs (msg->size))) )
+    {
+      LOG (GNUNET_ERROR_TYPE_DEBUG,
+           "Received duplicate of message already in buffer, dropping\n");
+      GNUNET_STATISTICS_update (stats,
+                                "# messages dropped due to duplicate in buffer",
+                                1,
+                                GNUNET_NO);
+      return;
+    }
+  }
+
   rung = dir->rung;
   if (cur_buffers == max_buffers)
   {
@@ -434,7 +456,7 @@ route_message (struct CadetPeer *prev,
   GNUNET_CONTAINER_DLL_remove (rung->rd_head,
                                rung->rd_tail,
                                dir);
-  /* make 'nxt' point to the next higher rung, creat if necessary */
+  /* make 'nxt' point to the next higher rung, create if necessary */
   nxt = rung->next;
   if ( (NULL == nxt) ||
        (rung->rung_off + 1 != nxt->rung_off) )
@@ -781,31 +803,45 @@ handle_connection_create (void *cls,
   if (0 == path_length)
   {
     LOG (GNUNET_ERROR_TYPE_DEBUG,
-      "Dropping CADET_CONNECTION_CREATE with empty path\n");
+         "Dropping CADET_CONNECTION_CREATE with empty path\n");
     GNUNET_break_op (0);
     return;
   }
+  LOG (GNUNET_ERROR_TYPE_DEBUG,
+       "Handling CADET_CONNECTION_CREATE from %s for CID %s with %u hops\n",
+       GCP_2s (sender),
+       GNUNET_sh2s (&msg->cid.connection_of_tunnel),
+       path_length);
   /* Check for loops */
-  struct GNUNET_CONTAINER_MultiPeerMap *map;
-  map = GNUNET_CONTAINER_multipeermap_create (path_length * 2,
-                                              GNUNET_YES);
-  GNUNET_assert (NULL != map);
-  for (off = 0; off < path_length; off++) {
-    if (GNUNET_SYSERR ==
-        GNUNET_CONTAINER_multipeermap_put (map,
-                                           &pids[off],
-                                           NULL,
-                                           GNUNET_CONTAINER_MULTIHASHMAPOPTION_UNIQUE_ONLY)) {
-      /* bogus request */
-      GNUNET_CONTAINER_multipeermap_destroy (map);
+  {
+    struct GNUNET_CONTAINER_MultiPeerMap *map;
+
+    map = GNUNET_CONTAINER_multipeermap_create (path_length * 2,
+                                                GNUNET_YES);
+    GNUNET_assert (NULL != map);
+    for (unsigned int i=0;i<path_length;i++)
+    {
       LOG (GNUNET_ERROR_TYPE_DEBUG,
-        "Dropping CADET_CONNECTION_CREATE with cyclic path\n");
-      GNUNET_break_op (0);
-      return;
+           "CADET_CONNECTION_CREATE has peer %s at offset %u\n",
+           GNUNET_i2s (&pids[i]),
+           i);
+      if (GNUNET_SYSERR ==
+          GNUNET_CONTAINER_multipeermap_put (map,
+                                             &pids[i],
+                                             NULL,
+                                             GNUNET_CONTAINER_MULTIHASHMAPOPTION_UNIQUE_ONLY))
+      {
+        /* bogus request */
+        GNUNET_CONTAINER_multipeermap_destroy (map);
+        LOG (GNUNET_ERROR_TYPE_DEBUG,
+             "Dropping CADET_CONNECTION_CREATE with cyclic path\n");
+        GNUNET_break_op (0);
+        return;
+      }
     }
+    GNUNET_CONTAINER_multipeermap_destroy (map);
   }
-  GNUNET_CONTAINER_multipeermap_destroy (map);
-  /* Initiator is at offset 0. */
+  /* Initiator is at offset 0, find us */
   for (off=1;off<path_length;off++)
     if (0 == memcmp (&my_full_id,
                      &pids[off],
@@ -814,7 +850,7 @@ handle_connection_create (void *cls,
   if (off == path_length)
   {
     LOG (GNUNET_ERROR_TYPE_DEBUG,
-      "Dropping CADET_CONNECTION_CREATE without us in the path\n");
+         "Dropping CADET_CONNECTION_CREATE without us in the path\n");
     GNUNET_break_op (0);
     return;
   }
@@ -823,14 +859,15 @@ handle_connection_create (void *cls,
                          GNUNET_NO))
   {
     LOG (GNUNET_ERROR_TYPE_DEBUG,
-      "Dropping CADET_CONNECTION_CREATE without sender in the path\n");
+         "Dropping CADET_CONNECTION_CREATE without sender at previous hop in the path\n");
     GNUNET_break_op (0);
     return;
   }
   if (NULL !=
-      get_route (&msg->cid))
+      (route = get_route (&msg->cid)))
   {
     /* Duplicate CREATE, pass it on, previous one might have been lost! */
+
     LOG (GNUNET_ERROR_TYPE_DEBUG,
          "Passing on duplicate CADET_CONNECTION_CREATE message on connection %s\n",
          GNUNET_sh2s (&msg->cid.connection_of_tunnel));
@@ -859,7 +896,7 @@ handle_connection_create (void *cls,
     origin = GCP_get (&pids[0],
                       GNUNET_YES);
     LOG (GNUNET_ERROR_TYPE_DEBUG,
-         "Received CADET_CONNECTION_CREATE message from %s for connection %s, building inverse path\n",
+         "I am destination for CADET_CONNECTION_CREATE message from %s for connection %s, building inverse path\n",
          GCP_2s (origin),
          GNUNET_sh2s (&msg->cid.connection_of_tunnel));
     path = GCPP_get_path_from_route (path_length - 1,
@@ -949,6 +986,10 @@ handle_connection_create (void *cls,
                                                                                 3),
                                                  &timeout_cb,
                                                  NULL);
+  /* also pass CREATE message along to next hop */
+  route_message (sender,
+                 &msg->cid,
+                 &msg->header);
 }
 
 
@@ -970,7 +1011,9 @@ handle_connection_create_ack (void *cls,
   if (NULL != cc)
   {
     /* verify ACK came from the right direction */
-    struct CadetPeerPath *path = GCC_get_path (cc);
+    unsigned int len;
+    struct CadetPeerPath *path = GCC_get_path (cc,
+                                               &len);
 
     if (peer !=
         GCPP_get_peer_at_offset (path,
@@ -1014,7 +1057,9 @@ handle_connection_broken (void *cls,
   if (NULL != cc)
   {
     /* verify message came from the right direction */
-    struct CadetPeerPath *path = GCC_get_path (cc);
+    unsigned int len;
+    struct CadetPeerPath *path = GCC_get_path (cc,
+                                               &len);
 
     if (peer !=
         GCPP_get_peer_at_offset (path,
@@ -1063,7 +1108,9 @@ handle_connection_destroy (void *cls,
   if (NULL != cc)
   {
     /* verify message came from the right direction */
-    struct CadetPeerPath *path = GCC_get_path (cc);
+    unsigned int len;
+    struct CadetPeerPath *path = GCC_get_path (cc,
+                                               &len);
 
     if (peer !=
         GCPP_get_peer_at_offset (path,
@@ -1108,11 +1155,19 @@ handle_tunnel_kx (void *cls,
   struct CadetConnection *cc;
 
   /* First, check if message belongs to a connection that ends here. */
+  LOG (GNUNET_ERROR_TYPE_DEBUG,
+       "Routing KX with ephemeral %s on CID %s\n",
+       GNUNET_e2s (&msg->ephemeral_key),
+       GNUNET_sh2s (&msg->cid.connection_of_tunnel));
+
+
   cc = GCC_lookup (&msg->cid);
   if (NULL != cc)
   {
     /* verify message came from the right direction */
-    struct CadetPeerPath *path = GCC_get_path (cc);
+    unsigned int len;
+    struct CadetPeerPath *path = GCC_get_path (cc,
+                                               &len);
 
     if (peer !=
         GCPP_get_peer_at_offset (path,
@@ -1152,7 +1207,9 @@ handle_tunnel_kx_auth (void *cls,
   if (NULL != cc)
   {
     /* verify message came from the right direction */
-    struct CadetPeerPath *path = GCC_get_path (cc);
+    unsigned int len;
+    struct CadetPeerPath *path = GCC_get_path (cc,
+                                               &len);
 
     if (peer !=
         GCPP_get_peer_at_offset (path,
@@ -1208,7 +1265,9 @@ handle_tunnel_encrypted (void *cls,
   if (NULL != cc)
   {
     /* verify message came from the right direction */
-    struct CadetPeerPath *path = GCC_get_path (cc);
+    unsigned int len;
+    struct CadetPeerPath *path = GCC_get_path (cc,
+                                               &len);
 
     if (peer !=
         GCPP_get_peer_at_offset (path,
diff --git a/src/cadet/gnunet-service-cadet_paths.c b/src/cadet/gnunet-service-cadet_paths.c
index b443cf9e8..5218d0848 100644
--- a/src/cadet/gnunet-service-cadet_paths.c
+++ b/src/cadet/gnunet-service-cadet_paths.c
@@ -146,7 +146,7 @@ GCPP_add_connection (struct CadetPeerPath *path,
   struct CadetPeerPathEntry *entry;
 
   LOG (GNUNET_ERROR_TYPE_DEBUG,
-       "Adding connection %s to path %s at offset %u\n",
+       "Adding %s to path %s at offset %u\n",
        GCC_2s (cc),
        GCPP_2s (path),
        off);
diff --git a/src/cadet/gnunet-service-cadet_peer.c b/src/cadet/gnunet-service-cadet_peer.c
index 05555e693..35e2c6148 100644
--- a/src/cadet/gnunet-service-cadet_peer.c
+++ b/src/cadet/gnunet-service-cadet_peer.c
@@ -242,12 +242,15 @@ struct CadetPeer
 const char *
 GCP_2s (const struct CadetPeer *cp)
 {
-  static char buf[32];
-
-  GNUNET_snprintf (buf,
-                   sizeof (buf),
-                   "P(%s)",
-                   GNUNET_i2s (&cp->pid));
+  static char buf[5];
+  char *ret;
+
+  ret = GNUNET_CRYPTO_eddsa_public_key_to_string (&cp->pid.public_key);
+  strncpy (buf,
+           ret,
+           sizeof (buf) - 1);
+  GNUNET_free (ret);
+  buf[4] = '\0';
   return buf;
 }
 
@@ -649,6 +652,27 @@ mqm_execute (struct GCP_MessageQueueManager *mqm)
   }
   else
   {
+    {
+      const struct GNUNET_MessageHeader *mh;
+
+      mh = GNUNET_MQ_env_get_msg (mqm->env);
+      switch (ntohs (mh->type))
+      {
+      case GNUNET_MESSAGE_TYPE_CADET_TUNNEL_KX:
+        {
+          const struct GNUNET_CADET_TunnelKeyExchangeMessage *msg
+            = (const struct GNUNET_CADET_TunnelKeyExchangeMessage *) mh;
+          LOG (GNUNET_ERROR_TYPE_DEBUG,
+               "P2P forwarding KX with ephemeral %s to %s on CID %s\n",
+               GNUNET_e2s (&msg->ephemeral_key),
+               GCP_2s (cp),
+               GNUNET_sh2s (&msg->cid.connection_of_tunnel));
+        }
+        break;
+      default:
+        break;
+      }
+    }
     LOG (GNUNET_ERROR_TYPE_DEBUG,
          "Sending to peer %s from MQM %p\n",
          GCP_2s (cp),
@@ -1044,7 +1068,7 @@ GCP_add_connection (struct CadetPeer *cp,
                     struct CadetConnection *cc)
 {
   LOG (GNUNET_ERROR_TYPE_DEBUG,
-       "Adding connection %s to peer %s\n",
+       "Adding %s to peer %s\n",
        GCC_2s (cc),
        GCP_2s (cp));
   GNUNET_assert (GNUNET_OK ==
diff --git a/src/cadet/gnunet-service-cadet_tunnels.c b/src/cadet/gnunet-service-cadet_tunnels.c
index 75d454522..dbd84a818 100644
--- a/src/cadet/gnunet-service-cadet_tunnels.c
+++ b/src/cadet/gnunet-service-cadet_tunnels.c
@@ -1369,6 +1369,15 @@ send_kx (struct CadetTunnel *t,
   msg->cid = *GCC_get_id (cc);
   GNUNET_CRYPTO_ecdhe_key_get_public (&ax->kx_0,
                                       &msg->ephemeral_key);
+#if DEBUG_KX
+  msg->ephemeral_key_XXX = ax->kx_0;
+  msg->private_key_XXX = *my_private_key;
+#endif
+  LOG (GNUNET_ERROR_TYPE_DEBUG,
+       "Sending KX message to %s with ephemeral %s on CID %s\n",
+       GCT_2s (t),
+       GNUNET_e2s (&msg->ephemeral_key),
+       GNUNET_sh2s (&msg->cid.connection_of_tunnel));
   GNUNET_CRYPTO_ecdhe_key_get_public (&ax->DHRs,
                                       &msg->ratchet_key);
   mark_connection_unready (ct);
@@ -1435,6 +1444,17 @@ send_kx_auth (struct CadetTunnel *t,
                                       &msg->kx.ephemeral_key);
   GNUNET_CRYPTO_ecdhe_key_get_public (&ax->DHRs,
                                       &msg->kx.ratchet_key);
+#if DEBUG_KX
+  msg->kx.ephemeral_key_XXX = ax->kx_0;
+  msg->kx.private_key_XXX = *my_private_key;
+  msg->r_ephemeral_key_XXX = ax->last_ephemeral;
+#endif
+  LOG (GNUNET_ERROR_TYPE_DEBUG,
+       "Sending KX_AUTH message to %s with ephemeral %s on CID %s\n",
+       GCT_2s (t),
+       GNUNET_e2s (&msg->kx.ephemeral_key),
+       GNUNET_sh2s (&msg->kx.cid.connection_of_tunnel));
+
   /* Compute authenticator (this is the main difference to #send_kx()) */
   GNUNET_CRYPTO_hash (&ax->RK,
                       sizeof (ax->RK),
@@ -1705,12 +1725,19 @@ GCT_handle_kx (struct CadetTConnection *ct,
                             "# KX received",
                             1,
                             GNUNET_NO);
-  if (GNUNET_YES == alice_or_bob (GCP_get_id (t->destination)))
+  if (GNUNET_YES ==
+      alice_or_bob (GCP_get_id (t->destination)))
   {
     /* Bob is not allowed to send KX! */
     GNUNET_break_op (0);
     return;
   }
+  LOG (GNUNET_ERROR_TYPE_DEBUG,
+       "Received KX message from %s with ephemeral %s from %s on connection %s\n",
+       GCT_2s (t),
+       GNUNET_e2s (&msg->ephemeral_key),
+       GNUNET_i2s (GCP_get_id (t->destination)),
+       GCC_2s (ct->cc));
 #if 1
   if ( (0 ==
         memcmp (&t->ax.DHRr,
@@ -1823,6 +1850,75 @@ GCT_handle_kx (struct CadetTConnection *ct,
 }
 
 
+#if DEBUG_KX
+static void
+check_ee (const struct GNUNET_CRYPTO_EcdhePrivateKey *e1,
+          const struct GNUNET_CRYPTO_EcdhePrivateKey *e2)
+{
+  struct GNUNET_CRYPTO_EcdhePublicKey p1;
+  struct GNUNET_CRYPTO_EcdhePublicKey p2;
+  struct GNUNET_HashCode hc1;
+  struct GNUNET_HashCode hc2;
+
+  GNUNET_CRYPTO_ecdhe_key_get_public (e1,
+                                      &p1);
+  GNUNET_CRYPTO_ecdhe_key_get_public (e2,
+                                      &p2);
+  GNUNET_assert (GNUNET_OK ==
+                 GNUNET_CRYPTO_ecc_ecdh (e1,
+                                         &p2,
+                                         &hc1));
+  GNUNET_assert (GNUNET_OK ==
+                 GNUNET_CRYPTO_ecc_ecdh (e2,
+                                         &p1,
+                                         &hc2));
+  GNUNET_break (0 == memcmp (&hc1,
+                             &hc2,
+                             sizeof (hc1)));
+}
+
+
+static void
+check_ed (const struct GNUNET_CRYPTO_EcdhePrivateKey *e1,
+          const struct GNUNET_CRYPTO_EddsaPrivateKey *e2)
+{
+  struct GNUNET_CRYPTO_EcdhePublicKey p1;
+  struct GNUNET_CRYPTO_EddsaPublicKey p2;
+  struct GNUNET_HashCode hc1;
+  struct GNUNET_HashCode hc2;
+
+  GNUNET_CRYPTO_ecdhe_key_get_public (e1,
+                                      &p1);
+  GNUNET_CRYPTO_eddsa_key_get_public (e2,
+                                      &p2);
+  GNUNET_assert (GNUNET_OK ==
+                 GNUNET_CRYPTO_ecdh_eddsa (e1,
+                                           &p2,
+                                           &hc1));
+  GNUNET_assert (GNUNET_OK ==
+                 GNUNET_CRYPTO_eddsa_ecdh (e2,
+                                           &p1,
+                                           &hc2));
+  GNUNET_break (0 == memcmp (&hc1,
+                             &hc2,
+                             sizeof (hc1)));
+}
+
+
+static void
+test_crypto_bug (const struct GNUNET_CRYPTO_EcdhePrivateKey *e1,
+                 const struct GNUNET_CRYPTO_EcdhePrivateKey *e2,
+                 const struct GNUNET_CRYPTO_EddsaPrivateKey *d1,
+                 const struct GNUNET_CRYPTO_EddsaPrivateKey *d2)
+{
+  check_ee (e1, e2);
+  check_ed (e1, d2);
+  check_ed (e2, d1);
+}
+
+#endif
+
+
 /**
  * Handle KX_AUTH message.
  *
@@ -1852,8 +1948,9 @@ GCT_handle_kx_auth (struct CadetTConnection *ct,
     return;
   }
   LOG (GNUNET_ERROR_TYPE_DEBUG,
-       "Handling KX_AUTH message for %s\n",
-       GCT_2s (t));
+       "Handling KX_AUTH message from %s with ephemeral %s\n",
+       GCT_2s (t),
+       GNUNET_e2s (&msg->kx.ephemeral_key));
   /* We do everything in ax_tmp until we've checked the authentication
      so we don't clobber anything we care about by accident. */
   ax_tmp = t->ax;
@@ -1889,6 +1986,32 @@ GCT_handle_kx_auth (struct CadetTConnection *ct,
                               GNUNET_NO);
     LOG (GNUNET_ERROR_TYPE_WARNING,
          "KX AUTH missmatch!\n");
+#if DEBUG_KX
+    {
+      struct GNUNET_CRYPTO_EcdhePublicKey ephemeral_key;
+
+      GNUNET_CRYPTO_ecdhe_key_get_public (&ax_tmp.kx_0,
+                                          &ephemeral_key);
+      if (0 != memcmp (&ephemeral_key,
+                       &msg->r_ephemeral_key_XXX,
+                       sizeof (ephemeral_key)))
+      {
+        LOG (GNUNET_ERROR_TYPE_WARNING,
+           "My ephemeral is %s!\n",
+             GNUNET_e2s (&ephemeral_key));
+        LOG (GNUNET_ERROR_TYPE_WARNING,
+             "Response is for ephemeral %s!\n",
+             GNUNET_e2s (&msg->r_ephemeral_key_XXX));
+      }
+      else
+      {
+        test_crypto_bug (&ax_tmp.kx_0,
+                         &msg->kx.ephemeral_key_XXX,
+                         my_private_key,
+                         &msg->kx.private_key_XXX);
+      }
+    }
+#endif
     if (NULL == t->kx_task)
       t->kx_task
         = GNUNET_SCHEDULER_add_at (t->next_kx_attempt,
@@ -2301,6 +2424,8 @@ connection_ready_cb (void *cls,
     /* Do not begin KX if WE have no channels waiting! */
     if (0 == GCT_count_channels (t))
       return;
+    if (0 != GNUNET_TIME_absolute_get_remaining (t->next_kx_attempt).rel_value_us)
+      return; /* wait for timeout before retrying */
     /* We are uninitialized, just transmit immediately,
        without undue delay. */
     if (NULL != t->kx_task)
@@ -2326,6 +2451,8 @@ connection_ready_cb (void *cls,
   case CADET_TUNNEL_KEY_OK:
     if (GNUNET_YES == t->kx_auth_requested)
     {
+      if (0 != GNUNET_TIME_absolute_get_remaining (t->next_kx_attempt).rel_value_us)
+        return; /* wait for timeout */
       if (NULL != t->kx_task)
       {
         GNUNET_SCHEDULER_cancel (t->kx_task);
@@ -2433,15 +2560,21 @@ evaluate_connection (void *cls,
 {
   struct EvaluationSummary *es = cls;
   struct CadetConnection *cc = ct->cc;
-  struct CadetPeerPath *ps = GCC_get_path (cc);
+  unsigned int ct_length;
+  struct CadetPeerPath *ps;
   const struct CadetConnectionMetrics *metrics;
   GNUNET_CONTAINER_HeapCostType ct_desirability;
   struct GNUNET_TIME_Relative uptime;
   struct GNUNET_TIME_Relative last_use;
-  uint32_t ct_length;
   double score;
   double success_rate;
 
+  ps = GCC_get_path (cc,
+                     &ct_length);
+  LOG (GNUNET_ERROR_TYPE_DEBUG,
+       "Evaluating path %s of existing %s\n",
+       GCPP_2s (ps),
+       GCC_2s (cc));
   if (ps == es->path)
   {
     LOG (GNUNET_ERROR_TYPE_DEBUG,
@@ -2450,8 +2583,39 @@ evaluate_connection (void *cls,
     es->duplicate = GNUNET_YES;
     return;
   }
+  if (NULL != es->path)
+  {
+    int duplicate = GNUNET_YES;
+
+    for (unsigned int i=0;i<ct_length;i++)
+    {
+      GNUNET_assert (GCPP_get_length (es->path) > i);
+      if (GCPP_get_peer_at_offset (es->path,
+                                   i) !=
+          GCPP_get_peer_at_offset (ps,
+                                   i))
+      {
+        duplicate = GNUNET_NO;
+        break;
+      }
+    }
+    if (GNUNET_YES == duplicate)
+    {
+      LOG (GNUNET_ERROR_TYPE_DEBUG,
+           "Ignoring overlapping path %s.\n",
+           GCPP_2s (es->path));
+      es->duplicate = GNUNET_YES;
+      return;
+    }
+    else
+    {
+      LOG (GNUNET_ERROR_TYPE_DEBUG,
+           "Known path %s differs from proposed path\n",
+           GCPP_2s (ps));
+    }
+  }
+
   ct_desirability = GCPP_get_desirability (ps);
-  ct_length = GCPP_get_length (ps);
   metrics = GCC_get_metrics (cc);
   uptime = GNUNET_TIME_absolute_get_duration (metrics->age);
   last_use = GNUNET_TIME_absolute_get_duration (metrics->last_use);
@@ -2500,6 +2664,8 @@ consider_path_cb (void *cls,
   struct CadetTConnection *ct;
 
   GNUNET_assert (off < GCPP_get_length (path));
+  GNUNET_assert (GCPP_get_peer_at_offset (path,
+                                          off) == t->destination);
   es.min_length = UINT_MAX;
   es.max_length = 0;
   es.max_desire = 0;
@@ -2509,6 +2675,13 @@ consider_path_cb (void *cls,
   es.worst = NULL;
 
   /* Compute evaluation summary over existing connections. */
+  LOG (GNUNET_ERROR_TYPE_DEBUG,
+       "Evaluating proposed path %s for target %s\n",
+       GCPP_2s (path),
+       GCT_2s (t));
+  /* FIXME: suspect this does not ACTUALLY iterate
+     over all existing paths, otherwise dup detection
+     should work!!! */
   GCT_iterate_connections (t,
                            &evaluate_connection,
                            &es);
@@ -2653,9 +2826,10 @@ GCT_consider_path (struct CadetTunnel *t,
                    unsigned int off)
 {
   LOG (GNUNET_ERROR_TYPE_DEBUG,
-       "Considering %s for %s\n",
+       "Considering %s for %s (offset %u)\n",
        GCPP_2s (p),
-       GCT_2s (t));
+       GCT_2s (t),
+       off);
   (void) consider_path_cb (t,
                            p,
                            off);