- dht debug path
[oweals/gnunet.git] / src / mesh / gnunet-service-mesh_channel.c
index ff2d822bc3c7c4ce15e916bc3fbfc6fd741fe4f5..9a81db79eae821943853acbe5f6e23c584cd1c6a 100644 (file)
@@ -636,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);
 }
 
 
@@ -741,7 +741,7 @@ ch_message_sent (void *cls,
       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)
@@ -780,7 +780,8 @@ ch_message_sent (void *cls,
       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",
@@ -856,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));
 }
 
 
@@ -1018,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)
@@ -1076,16 +1077,15 @@ 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->chq)
@@ -1132,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)
-  {
-    GNUNET_SCHEDULER_cancel (rel->retry_task);
-    rel->retry_task = GNUNET_SCHEDULER_NO_TASK;
-  }
-  else if (NULL != rel->uniq)
+  if (MESH_CHANNEL_READY != oldstate || GNUNET_YES == is_loopback (ch))
   {
-    GMT_cancel (rel->uniq->tq);
-    /* 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)
+    {
+      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
     {
-      /* We SHOULD have been trying to retransmit this! */
-      GNUNET_break (oldstate == MESH_CHANNEL_READY);
+      if (GNUNET_NO == is_loopback (ch))
+      {
+        /* We SHOULD have been trying to retransmit this! */
+        GNUNET_break (0);
+      }
     }
   }
 
@@ -1261,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;
 
@@ -1346,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)
@@ -1485,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));
@@ -1877,7 +1880,7 @@ GMCH_handle_data (struct MeshChannel *ch,
 
   if (NULL == c)
   {
-    GNUNET_break (0);
+    GNUNET_break (GNUNET_NO != ch->destroy);
     return;
   }
 
@@ -1907,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? */
@@ -1934,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);
@@ -1978,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)
   {
@@ -1991,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 */
@@ -2037,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);
     }
   }
@@ -2237,9 +2241,8 @@ GMCH_send_prebuilt_message (const struct GNUNET_MessageHeader *message,
   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))
   {
@@ -2249,8 +2252,12 @@ 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)
       {
         chq = GNUNET_new (struct MeshChannelQueue);
@@ -2283,9 +2290,9 @@ GMCH_send_prebuilt_message (const struct GNUNET_MessageHeader *message,
         }
         LOG (GNUNET_ERROR_TYPE_DEBUG, "  new chq: %p\n", chq);
             chq->copy->chq = chq;
-            chq->tq = GMT_send_prebuilt_message (message, ch->t,
-                                          NULL != existing_copy,
-                                          &ch_message_sent, 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 != chq->tq || GNUNET_NO != ch->destroy);
       }
@@ -2322,7 +2329,7 @@ GMCH_send_prebuilt_message (const struct GNUNET_MessageHeader *message,
           GNUNET_free (chq->rel->uniq);
         }
       }
-      chq->tq = GMT_send_prebuilt_message (message, ch->t, GNUNET_YES,
+      chq->tq = GMT_send_prebuilt_message (message, ch->t, NULL, GNUNET_YES,
                                            &ch_message_sent, chq);
       if (NULL == chq->tq)
       {