- start test only after warmup
[oweals/gnunet.git] / src / mesh / gnunet-service-mesh_channel.c
index 69b15830318a4b24ae13f88646eea4f78a562131..9a81db79eae821943853acbe5f6e23c584cd1c6a 100644 (file)
@@ -69,7 +69,7 @@ struct MeshChannelQueue
   /**
    * Tunnel Queue.
    */
-  struct MeshTunnel3Queue *q;
+  struct MeshTunnel3Queue *tq;
 
   /**
    * Message type (DATA/DATA_ACK)
@@ -117,7 +117,7 @@ struct MeshReliableMessage
   /**
    * Tunnel Queue.
    */
-  struct MeshChannelQueue       *q;
+  struct MeshChannelQueue       *chq;
 
     /**
      * When was this message issued (to calculate ACK delay)
@@ -595,7 +595,13 @@ static void
 send_client_ack (struct MeshChannel *ch, int fwd)
 {
   struct MeshChannelReliability *rel = fwd ? ch->root_rel : ch->dest_rel;
+  struct MeshClient *c = fwd ? ch->root : ch->dest;
 
+  if (NULL == c)
+  {
+    GNUNET_break (GNUNET_NO != ch->destroy);
+    return;
+  }
   LOG (GNUNET_ERROR_TYPE_DEBUG,
        "  sending %s ack to client on channel %s\n",
        GM_f2s (fwd), GMCH_2s (ch));
@@ -613,7 +619,7 @@ send_client_ack (struct MeshChannel *ch, int fwd)
   }
   rel->client_allowed = GNUNET_YES;
 
-  GML_send_ack (fwd ? ch->root : ch->dest, fwd ? ch->lid_root : ch->lid_dest);
+  GML_send_ack (c, fwd ? ch->lid_root : ch->lid_dest);
 }
 
 
@@ -630,7 +636,7 @@ send_client_nack (struct MeshChannel *ch)
     GNUNET_break (0);
     return;
   }
-  GML_send_nack (ch->root, ch->lid_root);
+  GML_send_channel_nack (ch->root, ch->lid_root);
 }
 
 
@@ -722,20 +728,20 @@ ch_message_sent (void *cls,
                  struct MeshTunnel3Queue *q,
                  uint16_t type, size_t size)
 {
-  struct MeshChannelQueue *ch_q = cls;
-  struct MeshReliableMessage *copy = ch_q->copy;
+  struct MeshChannelQueue *chq = cls;
+  struct MeshReliableMessage *copy = chq->copy;
   struct MeshChannelReliability *rel;
 
-  switch (ch_q->type)
+  switch (chq->type)
   {
     case GNUNET_MESSAGE_TYPE_MESH_DATA:
       LOG (GNUNET_ERROR_TYPE_DEBUG, "!!! SENT DATA MID %u\n", copy->mid);
-      GNUNET_assert (ch_q == copy->q);
+      GNUNET_assert (chq == copy->chq);
       copy->timestamp = GNUNET_TIME_absolute_get ();
       rel = copy->rel;
       if (GNUNET_SCHEDULER_NO_TASK == rel->retry_task)
       {
-        LOG (GNUNET_ERROR_TYPE_DEBUG, "!! scheduling retry in %s\n",
+        LOG (GNUNET_ERROR_TYPE_DEBUG, "!! scheduling retry in 4 * %s\n",
              GNUNET_STRINGS_relative_time_to_string (rel->expected_delay,
                                                      GNUNET_YES));
         if (0 != rel->expected_delay.rel_value_us)
@@ -761,20 +767,21 @@ ch_message_sent (void *cls,
       {
         LOG (GNUNET_ERROR_TYPE_DEBUG, "!! retry task %u\n", rel->retry_task);
       }
-      copy->q = NULL;
+      copy->chq = NULL;
       break;
 
 
     case GNUNET_MESSAGE_TYPE_MESH_DATA_ACK:
     case GNUNET_MESSAGE_TYPE_MESH_CHANNEL_CREATE:
     case GNUNET_MESSAGE_TYPE_MESH_CHANNEL_ACK:
-      LOG (GNUNET_ERROR_TYPE_DEBUG, "!!! SENT %s\n", GM_m2s (ch_q->type));
-      rel = ch_q->rel;
-      GNUNET_assert (rel->uniq == ch_q);
+      LOG (GNUNET_ERROR_TYPE_DEBUG, "!!! SENT %s\n", GM_m2s (chq->type));
+      rel = chq->rel;
+      GNUNET_assert (rel->uniq == chq);
       rel->uniq = NULL;
 
       if (MESH_CHANNEL_READY != rel->ch->state
-          && GNUNET_MESSAGE_TYPE_MESH_DATA_ACK != type)
+          && GNUNET_MESSAGE_TYPE_MESH_DATA_ACK != type
+          && GNUNET_NO == rel->ch->destroy)
       {
         GNUNET_assert (GNUNET_SCHEDULER_NO_TASK == rel->retry_task);
         LOG (GNUNET_ERROR_TYPE_DEBUG, "!!! STD BACKOFF %s\n",
@@ -791,7 +798,7 @@ ch_message_sent (void *cls,
       GNUNET_break (0);
   }
 
-  GNUNET_free (ch_q);
+  GNUNET_free (chq);
 }
 
 
@@ -850,8 +857,8 @@ fire_and_forget (const struct GNUNET_MessageHeader *msg,
                  struct MeshChannel *ch,
                  int force)
 {
-  GNUNET_break (NULL == GMT_send_prebuilt_message (msg, ch->t, force,
-                                                   NULL, NULL));
+  GNUNET_break (NULL == GMT_send_prebuilt_message (msg, ch->t, NULL,
+                                                   force, NULL, NULL));
 }
 
 
@@ -929,7 +936,7 @@ channel_rel_free_all (struct MeshChannelReliability *rel)
     next = copy->next;
     GNUNET_CONTAINER_DLL_remove (rel->head_recv, rel->tail_recv, copy);
     LOG (GNUNET_ERROR_TYPE_DEBUG, " COPYFREE BATCH RECV %p\n", copy);
-    GNUNET_break (NULL == copy->q);
+    GNUNET_break (NULL == copy->chq);
     GNUNET_free (copy);
   }
   for (copy = rel->head_sent; NULL != copy; copy = next)
@@ -937,24 +944,24 @@ channel_rel_free_all (struct MeshChannelReliability *rel)
     next = copy->next;
     GNUNET_CONTAINER_DLL_remove (rel->head_sent, rel->tail_sent, copy);
     LOG (GNUNET_ERROR_TYPE_DEBUG, " COPYFREE BATCH %p\n", copy);
-    if (NULL != copy->q)
+    if (NULL != copy->chq)
     {
-      if (NULL != copy->q->q)
+      if (NULL != copy->chq->tq)
       {
-        GMT_cancel (copy->q->q);
+        GMT_cancel (copy->chq->tq);
         /* ch_message_sent will free copy->q */
       }
       else
       {
-        GNUNET_free (copy->q);
+        GNUNET_free (copy->chq);
         GNUNET_break (0);
       }
     }
     GNUNET_free (copy);
   }
-  if (NULL != rel->uniq && NULL != rel->uniq->q)
+  if (NULL != rel->uniq && NULL != rel->uniq->tq)
   {
-    GMT_cancel (rel->uniq->q);
+    GMT_cancel (rel->uniq->tq);
     /* ch_message_sent is called freeing uniq */
   }
   if (GNUNET_SCHEDULER_NO_TASK != rel->retry_task)
@@ -1012,7 +1019,7 @@ channel_rel_free_sent (struct MeshChannelReliability *rel,
     target = mid + i + 1;
     LOG (GNUNET_ERROR_TYPE_DEBUG, " target %u\n", target);
     while (NULL != copy && GM_is_pid_bigger (target, copy->mid))
-     copy = copy->next;
+      copy = copy->next;
 
     /* Did we run out of copies? (previously freed, it's ok) */
     if (NULL == copy)
@@ -1070,21 +1077,20 @@ rel_message_free (struct MeshReliableMessage *copy, int update_time)
       rel->expected_delay.rel_value_us += time.rel_value_us;
       rel->expected_delay.rel_value_us /= 8;
     }
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "!!!  took %s\n",
-                GNUNET_STRINGS_relative_time_to_string (time, GNUNET_NO));
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "!!!  new expected delay %s\n",
-                GNUNET_STRINGS_relative_time_to_string (rel->expected_delay,
-                                                        GNUNET_NO));
+    LOG (GNUNET_ERROR_TYPE_INFO, "!!!  took %s, new delay %s\n",
+         GNUNET_STRINGS_relative_time_to_string (time, GNUNET_NO),
+         GNUNET_STRINGS_relative_time_to_string (rel->expected_delay,
+                                                 GNUNET_NO));
     rel->retry_timer = rel->expected_delay;
   }
   else
   {
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "!!! batch free, ignoring timing\n");
+    LOG (GNUNET_ERROR_TYPE_INFO, "!!! batch free, ignoring timing\n");
   }
   rel->ch->pending_messages--;
-  if (NULL != copy->q)
+  if (NULL != copy->chq)
   {
-    GMT_cancel (copy->q->q);
+    GMT_cancel (copy->chq->tq);
     /* copy->q is set to NULL by ch_message_sent */
   }
   GNUNET_CONTAINER_DLL_remove (rel->head_sent, rel->tail_sent, copy);
@@ -1126,30 +1132,33 @@ channel_confirm (struct MeshChannel *ch, int fwd)
   oldstate = ch->state;
   ch->state = MESH_CHANNEL_READY;
 
-  rel->client_ready = GNUNET_YES;
-  LOG (GNUNET_ERROR_TYPE_DEBUG,
-       "  !! retry timer confirm %s\n",
-       GNUNET_STRINGS_relative_time_to_string (rel->retry_timer, GNUNET_NO));
-  rel->expected_delay = rel->retry_timer;
-  if (GMT_get_connections_buffer (ch->t) > 0 || GMT_is_loopback (ch->t))
-    send_client_ack (ch, fwd);
-
-  if (GNUNET_SCHEDULER_NO_TASK != rel->retry_task)
+  if (MESH_CHANNEL_READY != oldstate || GNUNET_YES == is_loopback (ch))
   {
-    GNUNET_SCHEDULER_cancel (rel->retry_task);
-    rel->retry_task = GNUNET_SCHEDULER_NO_TASK;
-  }
-  else if (NULL != rel->uniq)
-  {
-    GMT_cancel (rel->uniq->q);
-    /* ch_message_sent will free and NULL uniq */
-  }
-  else
-  {
-    if (GNUNET_NO == is_loopback (ch))
+    rel->client_ready = GNUNET_YES;
+    LOG (GNUNET_ERROR_TYPE_DEBUG,
+         "  !! retry timer confirm %s\n",
+         GNUNET_STRINGS_relative_time_to_string (rel->retry_timer, GNUNET_NO));
+    rel->expected_delay = rel->retry_timer;
+    if (GMT_get_connections_buffer (ch->t) > 0 || GMT_is_loopback (ch->t))
+      send_client_ack (ch, fwd);
+
+    if (GNUNET_SCHEDULER_NO_TASK != rel->retry_task)
     {
-      /* We SHOULD have been trying to retransmit this! */
-      GNUNET_break (oldstate == MESH_CHANNEL_READY);
+      GNUNET_SCHEDULER_cancel (rel->retry_task);
+      rel->retry_task = GNUNET_SCHEDULER_NO_TASK;
+    }
+    else if (NULL != rel->uniq)
+    {
+      GMT_cancel (rel->uniq->tq);
+      /* ch_message_sent will free and NULL uniq */
+    }
+    else
+    {
+      if (GNUNET_NO == is_loopback (ch))
+      {
+        /* We SHOULD have been trying to retransmit this! */
+        GNUNET_break (0);
+      }
     }
   }
 
@@ -1255,6 +1264,8 @@ handle_loopback (struct MeshChannel *ch,
   {
     case GNUNET_MESSAGE_TYPE_MESH_DATA:
       /* Don't send hop ACK, wait for client to ACK */
+      LOG (GNUNET_ERROR_TYPE_DEBUG, "!!! SEND loopback %u (%u)\n",
+           ntohl (((struct GNUNET_MESH_Data *) msgh)->mid), ntohs (msgh->size));
       GMCH_handle_data (ch, (struct GNUNET_MESH_Data *) msgh, fwd);
       break;
 
@@ -1340,11 +1351,11 @@ GMCH_destroy (struct MeshChannel *ch)
 
 
 /**
- * Get channel ID.
+ * Get the channel's public ID.
  *
  * @param ch Channel.
  *
- * @return ID
+ * @return ID used to identify the channel with the remote peer.
  */
 MESH_ChannelNumber
 GMCH_get_id (const struct MeshChannel *ch)
@@ -1479,9 +1490,7 @@ GMCH_send_data_ack (struct MeshChannel *ch, int fwd)
   }
   rel = fwd ? ch->dest_rel : ch->root_rel;
   ack = rel->mid_recv - 1;
-  LOG (GNUNET_ERROR_TYPE_DEBUG,
-              " !! Send DATA_ACK for %u\n",
-              ack);
+  LOG (GNUNET_ERROR_TYPE_INFO, "=> DATA_ACK for %u\n", ack);
 
   msg.header.type = htons (GNUNET_MESSAGE_TYPE_MESH_DATA_ACK);
   msg.header.size = htons (sizeof (msg));
@@ -1806,6 +1815,7 @@ GMCH_handle_local_create (struct MeshClient *c,
   }
   else
   {
+    /* FIXME change to a tunnel API, eliminate ch <-> peer connection */
     GMP_connect (peer);
   }
 
@@ -1870,7 +1880,7 @@ GMCH_handle_data (struct MeshChannel *ch,
 
   if (NULL == c)
   {
-    GNUNET_break (0);
+    GNUNET_break (GNUNET_NO != ch->destroy);
     return;
   }
 
@@ -1900,7 +1910,8 @@ GMCH_handle_data (struct MeshChannel *ch,
       ( !GM_is_pid_bigger (rel->mid_recv, mid) &&
         GM_is_pid_bigger (rel->mid_recv + 64, mid) ) )
   {
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "!!! RECV %u\n", mid);
+    LOG (GNUNET_ERROR_TYPE_DEBUG, "!!! RECV %u (%u)\n",
+         mid, ntohs (msg->header.size));
     if (GNUNET_YES == ch->reliable)
     {
       /* Is this the exact next expected messasge? */
@@ -1927,9 +1938,9 @@ GMCH_handle_data (struct MeshChannel *ch,
   else
   {
     GNUNET_break_op (GM_is_pid_bigger (rel->mid_recv, mid));
-    LOG (GNUNET_ERROR_TYPE_DEBUG,
-                " !!! MID %u not expected (%u - %u), dropping!\n",
-                mid, rel->mid_recv, rel->mid_recv + 63);
+    LOG (GNUNET_ERROR_TYPE_WARNING,
+         "MID %u not expected (%u - %u), dropping!\n",
+         mid, rel->mid_recv, rel->mid_recv + 63);
   }
 
   GMCH_send_data_ack (ch, fwd);
@@ -1971,8 +1982,7 @@ GMCH_handle_data_ack (struct MeshChannel *ch,
   }
 
   ack = ntohl (msg->mid);
-  LOG (GNUNET_ERROR_TYPE_DEBUG, "!!! %s ACK %u\n",
-       (GNUNET_YES == fwd) ? "FWD" : "BCK", ack);
+  LOG (GNUNET_ERROR_TYPE_INFO, "<= %s ACK %u\n", GM_f2s (fwd), ack);
 
   if (GNUNET_YES == fwd)
   {
@@ -1984,27 +1994,27 @@ GMCH_handle_data_ack (struct MeshChannel *ch,
   }
   if (NULL == rel)
   {
-    GNUNET_break_op (0);
+    GNUNET_break_op (GNUNET_NO != ch->destroy);
     return;
   }
 
-  /* Free ACK'd copies: no need to retransmit those anymore */
+  /* Free ACK'd copies: no need to retransmit those anymore FIXME refactor */
   for (work = GNUNET_NO, copy = rel->head_sent; copy != NULL; copy = next)
   {
     if (GM_is_pid_bigger (copy->mid, ack))
     {
-      LOG (GNUNET_ERROR_TYPE_DEBUG, "!!!  head %u, out!\n", copy->mid);
+      LOG (GNUNET_ERROR_TYPE_DEBUG, "  head %u, out!\n", copy->mid);
       channel_rel_free_sent (rel, msg);
       break;
     }
     work = GNUNET_YES;
-    LOG (GNUNET_ERROR_TYPE_DEBUG, " !!  id %u\n", copy->mid);
+    LOG (GNUNET_ERROR_TYPE_DEBUG, "  id %u\n", copy->mid);
     next = copy->next;
     if (GNUNET_YES == rel_message_free (copy, GNUNET_YES))
       return;
   }
 
-  /* ACK client if needed */
+  /* ACK client if needed and possible */
   GMCH_allow_client (ch, fwd);
 
   /* If some message was free'd, update the retransmission delay */
@@ -2014,7 +2024,7 @@ GMCH_handle_data_ack (struct MeshChannel *ch,
     {
       GNUNET_SCHEDULER_cancel (rel->retry_task);
       rel->retry_task = GNUNET_SCHEDULER_NO_TASK;
-      if (NULL != rel->head_sent && NULL == rel->head_sent->q)
+      if (NULL != rel->head_sent && NULL == rel->head_sent->chq)
       {
         struct GNUNET_TIME_Absolute new_target;
         struct GNUNET_TIME_Relative delay;
@@ -2030,8 +2040,9 @@ GMCH_handle_data_ack (struct MeshChannel *ch,
                                           rel);
       }
     }
-    else /* work was done but no task was pending? shouldn't happen! */
+    else
     {
+      /* Work was done but no task was pending? Shouldn't happen! */
       GNUNET_break (0);
     }
   }
@@ -2226,13 +2237,12 @@ GMCH_send_prebuilt_message (const struct GNUNET_MessageHeader *message,
                             struct MeshChannel *ch, int fwd,
                             void *existing_copy)
 {
-  struct MeshChannelQueue *q;
+  struct MeshChannelQueue *chq;
   uint16_t type;
 
   type = ntohs (message->type);
-  LOG (GNUNET_ERROR_TYPE_DEBUG, "GMCH Send %s %s on channel %s\n",
-       GM_f2s (fwd), GM_m2s (type),
-       GMCH_2s (ch));
+  LOG (GNUNET_ERROR_TYPE_INFO, "=> %s %s on channel %s\n",
+       GM_m2s (type), GM_f2s (fwd), GMCH_2s (ch));
 
   if (GMT_is_loopback (ch->t))
   {
@@ -2242,18 +2252,22 @@ GMCH_send_prebuilt_message (const struct GNUNET_MessageHeader *message,
 
   switch (type)
   {
+    struct GNUNET_MESH_Data *payload;
     case GNUNET_MESSAGE_TYPE_MESH_DATA:
 
+      payload = (struct GNUNET_MESH_Data *) message;
+      LOG (GNUNET_ERROR_TYPE_INFO, "=> %s %u\n",
+           GM_m2s (type), ntohl(payload->mid));
       if (GNUNET_YES == ch->reliable)
       {
-        q = GNUNET_new (struct MeshChannelQueue);
-        q->type = type;
+        chq = GNUNET_new (struct MeshChannelQueue);
+        chq->type = type;
         if (NULL == existing_copy)
-          q->copy = channel_save_copy (ch, message, fwd);
+          chq->copy = channel_save_copy (ch, message, fwd);
         else
         {
-          q->copy = (struct MeshReliableMessage *) existing_copy;
-          if (NULL != q->copy->q)
+          chq->copy = (struct MeshReliableMessage *) existing_copy;
+          if (NULL != chq->copy->chq)
           {
             /* Last retransmission was queued but not yet sent!
              * This retransmission was scheduled by a ch_message_sent which
@@ -2264,7 +2278,7 @@ GMCH_send_prebuilt_message (const struct GNUNET_MessageHeader *message,
              * retransmission leaves the peer and ch_message_sent starts
              * the timer for the next one.
              */
-            GNUNET_free (q);
+            GNUNET_free (chq);
             LOG (GNUNET_ERROR_TYPE_DEBUG,
                  "  exisitng copy not yet transmitted!\n");
             return;
@@ -2272,15 +2286,15 @@ GMCH_send_prebuilt_message (const struct GNUNET_MessageHeader *message,
           LOG (GNUNET_ERROR_TYPE_DEBUG,
                "  using existing copy: %p {r:%p q:%p t:%u}\n",
                existing_copy,
-               q->copy->rel, q->copy->q, q->copy->type);
+               chq->copy->rel, chq->copy->chq, chq->copy->type);
         }
-        LOG (GNUNET_ERROR_TYPE_DEBUG, "  new q: %p\n", q);
-        q->copy->q = q;
-        q->q = GMT_send_prebuilt_message (message, ch->t,
-                                          NULL != existing_copy,
-                                          &ch_message_sent, q);
+        LOG (GNUNET_ERROR_TYPE_DEBUG, "  new chq: %p\n", chq);
+            chq->copy->chq = chq;
+            chq->tq = GMT_send_prebuilt_message (message, ch->t, NULL,
+                                                 NULL != existing_copy,
+                                                 &ch_message_sent, chq);
         /* q itself is stored in copy */
-        GNUNET_assert (NULL != q->q || GNUNET_NO != ch->destroy);
+        GNUNET_assert (NULL != chq->tq || GNUNET_NO != ch->destroy);
       }
       else
       {
@@ -2294,29 +2308,37 @@ GMCH_send_prebuilt_message (const struct GNUNET_MessageHeader *message,
       {
         /* BCK ACK (going FWD) is just a response for a SYNACK, don't keep*/
         fire_and_forget (message, ch, GNUNET_YES);
-        break;
+        return;
       }
       /* fall-trough */
     case GNUNET_MESSAGE_TYPE_MESH_DATA_ACK:
     case GNUNET_MESSAGE_TYPE_MESH_CHANNEL_CREATE:
-      q = GNUNET_new (struct MeshChannelQueue);
-      q->type = type;
-      q->rel = fwd ? ch->root_rel : ch->dest_rel;
-      if (NULL != q->rel->uniq)
+      chq = GNUNET_new (struct MeshChannelQueue);
+      chq->type = type;
+      chq->rel = fwd ? ch->root_rel : ch->dest_rel;
+      if (NULL != chq->rel->uniq)
       {
-        if (NULL != q->rel->uniq->q)
+        if (NULL != chq->rel->uniq->tq)
         {
-          GMT_cancel (q->rel->uniq->q);
+          GMT_cancel (chq->rel->uniq->tq);
           /* ch_message_sent is called, freeing and NULLing uniq */
         }
         else
         {
-          GNUNET_free (q->rel->uniq);
+          GNUNET_break (0);
+          GNUNET_free (chq->rel->uniq);
         }
       }
-      q->q = GMT_send_prebuilt_message (message, ch->t, GNUNET_YES,
-                                        &ch_message_sent, q);
-      q->rel->uniq = q;
+      chq->tq = GMT_send_prebuilt_message (message, ch->t, NULL, GNUNET_YES,
+                                           &ch_message_sent, chq);
+      if (NULL == chq->tq)
+      {
+        GNUNET_break (0);
+        GNUNET_free (chq);
+        chq = NULL;
+        return;
+      }
+      chq->rel->uniq = chq;
       break;