- fix coverity
[oweals/gnunet.git] / src / cadet / gnunet-service-cadet_channel.c
index e72b1e4730903ac75d190af282640088962c115b..d4f9754da2315743d3dd0d75fa35502240eae61b 100644 (file)
@@ -1,6 +1,6 @@
 /*
      This file is part of GNUnet.
-     Copyright (C) 2013 Christian Grothoff (and other contributing authors)
+     Copyright (C) 2013 GNUnet e.V.
 
      GNUnet is free software; you can redistribute it and/or modify
      it under the terms of the GNU General Public License as published
@@ -14,8 +14,8 @@
 
      You should have received a copy of the GNU General Public License
      along with GNUnet; see the file COPYING.  If not, write to the
-     Free Software Foundation, Inc., 59 Temple Place - Suite 330,
-     Boston, MA 02111-1307, USA.
+     Free Software Foundation, Inc., 51 Franklin Street, Fifth Floor,
+     Boston, MA 02110-1301, USA.
 */
 
 
@@ -33,6 +33,7 @@
 #include "gnunet-service-cadet_peer.h"
 
 #define LOG(level, ...) GNUNET_log_from(level,"cadet-chn",__VA_ARGS__)
+#define LOG2(level, ...) GNUNET_log_from_nocheck(level,"cadet-chn",__VA_ARGS__)
 
 #define CADET_RETRANSMIT_TIME    GNUNET_TIME_relative_multiply(\
                                     GNUNET_TIME_UNIT_MILLISECONDS, 250)
@@ -720,11 +721,9 @@ send_client_nack (struct CadetChannel *ch)
  * We haven't received an ACK after a certain time: restransmit the message.
  *
  * @param cls Closure (CadetChannelReliability with the message to restransmit)
- * @param tc TaskContext.
  */
 static void
-channel_retransmit_message (void *cls,
-                            const struct GNUNET_SCHEDULER_TaskContext *tc)
+channel_retransmit_message (void *cls)
 {
   struct CadetChannelReliability *rel = cls;
   struct CadetReliableMessage *copy;
@@ -733,9 +732,6 @@ channel_retransmit_message (void *cls,
   int fwd;
 
   rel->retry_task = NULL;
-  if (0 != (tc->reason & GNUNET_SCHEDULER_REASON_SHUTDOWN))
-    return;
-
   ch = rel->ch;
   copy = rel->head_sent;
   if (NULL == copy)
@@ -759,19 +755,16 @@ channel_retransmit_message (void *cls,
  * We haven't received an Channel ACK after a certain time: resend the CREATE.
  *
  * @param cls Closure (CadetChannelReliability of the channel to recreate)
- * @param tc TaskContext.
  */
 static void
-channel_recreate (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
+channel_recreate (void *cls)
 {
   struct CadetChannelReliability *rel = cls;
 
   rel->retry_task = NULL;
-  if (0 != (tc->reason & GNUNET_SCHEDULER_REASON_SHUTDOWN))
-    return;
-
   LOG (GNUNET_ERROR_TYPE_DEBUG, "RE-CREATE\n");
-  GNUNET_STATISTICS_update (stats, "# data retransmitted", 1, GNUNET_NO);
+  GNUNET_STATISTICS_update (stats,
+                           "# data retransmitted", 1, GNUNET_NO);
 
   if (rel == rel->ch->root_rel)
   {
@@ -785,7 +778,6 @@ channel_recreate (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
   {
     GNUNET_break (0);
   }
-
 }
 
 
@@ -820,14 +812,15 @@ ch_message_sent (void *cls,
       rel = copy->rel;
       if (NULL == rel->retry_task)
       {
-        LOG (GNUNET_ERROR_TYPE_DEBUG, "  scheduling retry in 4 * %s\n",
+        LOG (GNUNET_ERROR_TYPE_DEBUG, "  scheduling retry in %d * %s\n",
+             CADET_RETRANSMIT_MARGIN,
              GNUNET_STRINGS_relative_time_to_string (rel->expected_delay,
                                                      GNUNET_YES));
         if (0 != rel->expected_delay.rel_value_us)
         {
           rel->retry_timer =
-          GNUNET_TIME_relative_multiply (rel->expected_delay,
-                                         CADET_RETRANSMIT_MARGIN);
+              GNUNET_TIME_relative_multiply (rel->expected_delay,
+                                             CADET_RETRANSMIT_MARGIN);
         }
         else
         {
@@ -1021,8 +1014,10 @@ channel_rel_free_all (struct CadetChannelReliability *rel)
  *
  * @param rel Reliability data.
  * @param msg DataACK message with a bitfield of future ACK'd messages.
+ *
+ * @return How many messages have been freed.
  */
-static void
+static unsigned int
 channel_rel_free_sent (struct CadetChannelReliability *rel,
                        const struct GNUNET_CADET_DataACK *msg)
 {
@@ -1033,12 +1028,13 @@ channel_rel_free_sent (struct CadetChannelReliability *rel,
   uint32_t mid;
   uint32_t target;
   unsigned int i;
+  unsigned int r;
 
   bitfield = msg->futures;
   mid = ntohl (msg->mid);
-  LOG (GNUNET_ERROR_TYPE_DEBUG, "free_sent_reliable %u %llX\n", mid, bitfield);
+  LOG (GNUNET_ERROR_TYPE_DEBUG, "free_sent_reliable %u %lX\n", mid, bitfield);
   LOG (GNUNET_ERROR_TYPE_DEBUG, " rel %p, head %p\n", rel, rel->head_sent);
-  for (i = 0, copy = rel->head_sent;
+  for (i = 0, r = 0, copy = rel->head_sent;
        i < 64 && NULL != copy && 0 != bitfield;
        i++)
   {
@@ -1062,7 +1058,7 @@ channel_rel_free_sent (struct CadetChannelReliability *rel,
     if (NULL == copy)
     {
       LOG (GNUNET_ERROR_TYPE_DEBUG, "run out of copies...\n");
-      return;
+      return r;
     }
 
     /* Did we overshoot the target? (previously freed, it's ok) */
@@ -1078,9 +1074,11 @@ channel_rel_free_sent (struct CadetChannelReliability *rel,
     /* Now copy->mid == target, free it */
     next = copy->next;
     GNUNET_break (GNUNET_YES != rel_message_free (copy, GNUNET_YES));
+    r++;
     copy = next;
   }
   LOG (GNUNET_ERROR_TYPE_DEBUG, "free_sent_reliable END\n");
+  return r;
 }
 
 
@@ -1106,7 +1104,7 @@ rel_message_free (struct CadetReliableMessage *copy, int update_time)
 
   rel = copy->rel;
   LOG (GNUNET_ERROR_TYPE_DEBUG, "Freeing %u\n", copy->mid);
-  if (update_time)
+  if (GNUNET_YES == update_time)
   {
     time = GNUNET_TIME_absolute_get_duration (copy->timestamp);
     if (0 == rel->expected_delay.rel_value_us)
@@ -1362,7 +1360,7 @@ GCCH_destroy (struct CadetChannel *ch)
 
   LOG (GNUNET_ERROR_TYPE_DEBUG, "destroying channel %s:%u\n",
               GCT_2s (ch->t), ch->gid);
-  GCCH_debug (ch);
+  GCCH_debug (ch, GNUNET_ERROR_TYPE_DEBUG);
 
   c = ch->root;
   if (NULL != c)
@@ -1431,7 +1429,7 @@ GCCH_get_buffer (struct CadetChannel *ch, int fwd)
 
   rel = fwd ? ch->dest_rel : ch->root_rel;
   LOG (GNUNET_ERROR_TYPE_DEBUG, "   get buffer, channel %s\n", GCCH_2s (ch));
-  GCCH_debug (ch);
+  GCCH_debug (ch, GNUNET_ERROR_TYPE_DEBUG);
   /* If rel is NULL it means that the end is not yet created,
    * most probably is a loopback channel at the point of sending
    * the ChannelCreate to itself.
@@ -1554,11 +1552,9 @@ GCCH_send_data_ack (struct CadetChannel *ch, int fwd)
     mask = 0x1LL << delta;
     msg.futures |= mask;
     LOG (GNUNET_ERROR_TYPE_DEBUG,
-         " setting bit for %u (delta %u) (%llX) -> %llX\n",
+         " setting bit for %u (delta %u) (%lX) -> %lX\n",
          copy->mid, delta, mask, msg.futures);
   }
-  LOG (GNUNET_ERROR_TYPE_INFO, "===> DATA_ACK for %u + %llX\n",
-       ack, msg.futures);
 
   GCCH_send_prebuilt_message (&msg.header, ch, !fwd, NULL);
   LOG (GNUNET_ERROR_TYPE_DEBUG, "send_data_ack END\n");
@@ -1637,40 +1633,45 @@ GCCH_allow_client (struct CadetChannel *ch, int fwd)
  * Log channel info.
  *
  * @param ch Channel.
+ * @param level Debug level to use.
  */
 void
-GCCH_debug (struct CadetChannel *ch)
+GCCH_debug (struct CadetChannel *ch, enum GNUNET_ErrorType level)
 {
+  int do_log;
+
+  do_log = GNUNET_get_log_call_status (level & (~GNUNET_ERROR_TYPE_BULK),
+                                       "cadet-chn",
+                                       __FILE__, __FUNCTION__, __LINE__);
+  if (0 == do_log)
+    return;
+
   if (NULL == ch)
   {
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "*** DEBUG NULL CHANNEL ***\n");
+    LOG2 (level, "CHN *** DEBUG NULL CHANNEL ***\n");
     return;
   }
-  LOG (GNUNET_ERROR_TYPE_DEBUG, "Channel %s:%X (%p)\n",
-              GCT_2s (ch->t), ch->gid, ch);
-  LOG (GNUNET_ERROR_TYPE_DEBUG, "  root %p/%p\n",
-              ch->root, ch->root_rel);
+  LOG2 (level, "CHN Channel %s:%X (%p)\n", GCT_2s (ch->t), ch->gid, ch);
+  LOG2 (level, "CHN   root %p/%p\n", ch->root, ch->root_rel);
   if (NULL != ch->root)
   {
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "  cli %s\n", GML_2s (ch->root));
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "  ready %s\n",
-                ch->root_rel->client_ready ? "YES" : "NO");
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "  id %X\n", ch->lid_root);
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "  recv %d\n", ch->root_rel->n_recv);
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "  MID r: %d, s: %d\n",
-         ch->root_rel->mid_recv, ch->root_rel->mid_send);
+    LOG2 (level, "CHN   cli %s\n", GML_2s (ch->root));
+    LOG2 (level, "CHN   ready %s\n", ch->root_rel->client_ready ? "YES" : "NO");
+    LOG2 (level, "CHN   id %X\n", ch->lid_root);
+    LOG2 (level, "CHN   recv %d\n", ch->root_rel->n_recv);
+    LOG2 (level, "CHN   MID r: %d, s: %d\n",
+          ch->root_rel->mid_recv, ch->root_rel->mid_send);
   }
-  LOG (GNUNET_ERROR_TYPE_DEBUG, "  dest %p/%p\n",
+  LOG2 (level, "CHN   dest %p/%p\n",
               ch->dest, ch->dest_rel);
   if (NULL != ch->dest)
   {
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "  cli %s\n", GML_2s (ch->dest));
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "  ready %s\n",
-                ch->dest_rel->client_ready ? "YES" : "NO");
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "  id %X\n", ch->lid_dest);
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "  recv %d\n", ch->dest_rel->n_recv);
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "  MID r: %d, s: %d\n",
-         ch->dest_rel->mid_recv, ch->dest_rel->mid_send);
+    LOG2 (level, "CHN   cli %s\n", GML_2s (ch->dest));
+    LOG2 (level, "CHN   ready %s\n", ch->dest_rel->client_ready ? "YES" : "NO");
+    LOG2 (level, "CHN   id %X\n", ch->lid_dest);
+    LOG2 (level, "CHN   recv %d\n", ch->dest_rel->n_recv);
+    LOG2 (level, "CHN   MID r: %d, s: %d\n",
+          ch->dest_rel->mid_recv, ch->dest_rel->mid_send);
 
   }
 }
@@ -1847,7 +1848,7 @@ GCCH_handle_local_create (struct CadetClient *c,
   CADET_ChannelNumber chid;
 
   LOG (GNUNET_ERROR_TYPE_DEBUG, "  towards %s:%u\n",
-              GNUNET_i2s (&msg->peer), ntohl (msg->port));
+       GNUNET_i2s (&msg->peer), ntohl (msg->port));
   chid = ntohl (msg->channel_id);
 
   /* Sanity check for duplicate channel IDs */
@@ -1857,7 +1858,7 @@ GCCH_handle_local_create (struct CadetClient *c,
     return GNUNET_SYSERR;
   }
 
-  peer = GCP_get (&msg->peer);
+  peer = GCP_get (&msg->peer, GNUNET_YES);
   GCP_add_tunnel (peer);
   t = GCP_get_tunnel (peer);
 
@@ -1912,7 +1913,10 @@ GCCH_handle_data (struct CadetChannel *ch,
 {
   struct CadetChannelReliability *rel;
   struct CadetClient *c;
+  struct GNUNET_MessageHeader *payload_msg;
   uint32_t mid;
+  uint16_t payload_type;
+  uint16_t payload_size;
 
   /* If this is a remote (non-loopback) channel, find 'fwd'. */
   if (GNUNET_SYSERR == fwd)
@@ -1953,18 +1957,22 @@ GCCH_handle_data (struct CadetChannel *ch,
     channel_confirm (ch, GNUNET_NO);
   }
 
-  GNUNET_STATISTICS_update (stats, "# data received", 1, GNUNET_NO);
+  payload_msg = (struct GNUNET_MessageHeader *) &msg[1];
+  payload_type = ntohs (payload_msg->type);
+  payload_size = ntohs (payload_msg->size);
+
+  GNUNET_STATISTICS_update (stats, "# messages received", 1, GNUNET_NO);
+  GNUNET_STATISTICS_update (stats, "# bytes received", payload_size, GNUNET_NO);
 
   mid = ntohl (msg->mid);
-  LOG (GNUNET_ERROR_TYPE_INFO, "<=== DATA %u %s on channel %s\n",
-       mid, GC_f2s (fwd), GCCH_2s (ch));
+  LOG (GNUNET_ERROR_TYPE_INFO, "<== %s (%s %4u) on chan %s (%p) %s [%5u]\n",
+       GC_m2s (GNUNET_MESSAGE_TYPE_CADET_DATA), GC_m2s (payload_type), mid,
+       GCCH_2s (ch), ch, GC_f2s (fwd), ntohs (msg->header.size));
 
   if (GNUNET_NO == ch->reliable ||
       ( !GC_is_pid_bigger (rel->mid_recv, mid) &&
         GC_is_pid_bigger (rel->mid_recv + 64, mid) ) )
   {
-    LOG (GNUNET_ERROR_TYPE_DEBUG, "RECV MID %u (%u)\n",
-         mid, ntohs (msg->header.size));
     if (GNUNET_YES == ch->reliable)
     {
       /* Is this the exact next expected messasge? */
@@ -1989,23 +1997,24 @@ GCCH_handle_data (struct CadetChannel *ch,
   }
   else
   {
+    GNUNET_STATISTICS_update (stats, "# duplicate MID", 1, GNUNET_NO);
     if (GC_is_pid_bigger (rel->mid_recv, mid))
     {
       GNUNET_break_op (0);
-      LOG (GNUNET_ERROR_TYPE_WARNING,
-          "MID %u on channel %s not expected (window: %u - %u). Dropping!\n",
-          mid, GCCH_2s (ch), rel->mid_recv, rel->mid_recv + 63);
+      LOG (GNUNET_ERROR_TYPE_INFO,
+           "MID %u on channel %s not expected (window: %u - %u). Dropping!\n",
+           mid, GCCH_2s (ch), rel->mid_recv, rel->mid_recv + 63);
     }
     else
     {
-      LOG (GNUNET_ERROR_TYPE_WARNING,
+      LOG (GNUNET_ERROR_TYPE_INFO,
            "Duplicate MID %u, channel %s (expecting MID %u). Re-sending ACK!\n",
            mid, GCCH_2s (ch), rel->mid_recv);
       if (NULL != rel->uniq)
       {
         LOG (GNUNET_ERROR_TYPE_WARNING,
-            "We are trying to send an ACK, but don't seem have the "
-            "bandwidth. Try to increase your ats QUOTA in you config file\n");
+             "We are trying to send an ACK, but don't seem have the "
+             "bandwidth. Have you set enough [ats] QUOTA in your config?\n");
       }
 
     }
@@ -2050,20 +2059,19 @@ GCCH_handle_data_ack (struct CadetChannel *ch,
   }
 
   ack = ntohl (msg->mid);
-  LOG (GNUNET_ERROR_TYPE_INFO, "<=== %s ACK %u + %llX\n",
-       GC_f2s (fwd), ack, msg->futures);
+  LOG (GNUNET_ERROR_TYPE_INFO,
+       "<== %s (0x%010lX %4u) on chan %s (%p) %s [%5u]\n",
+       GC_m2s (GNUNET_MESSAGE_TYPE_CADET_DATA_ACK), msg->futures, ack,
+       GCCH_2s (ch), ch, GC_f2s (fwd), ntohs (msg->header.size));
 
   if (GNUNET_YES == fwd)
-  {
     rel = ch->root_rel;
-  }
   else
-  {
     rel = ch->dest_rel;
-  }
+
   if (NULL == rel)
   {
-    GNUNET_break_op (GNUNET_NO != ch->destroy);
+    GNUNET_break (GNUNET_NO != ch->destroy);
     return;
   }
 
@@ -2073,14 +2081,18 @@ GCCH_handle_data_ack (struct CadetChannel *ch,
     if (GC_is_pid_bigger (copy->mid, ack))
     {
       LOG (GNUNET_ERROR_TYPE_DEBUG, "  head %u, out!\n", copy->mid);
-      channel_rel_free_sent (rel, msg);
+      if (0 < channel_rel_free_sent (rel, msg))
+        work = GNUNET_YES;
       break;
     }
     work = GNUNET_YES;
     LOG (GNUNET_ERROR_TYPE_DEBUG, "  id %u\n", copy->mid);
     next = copy->next;
     if (GNUNET_YES == rel_message_free (copy, GNUNET_YES))
+    {
+      LOG (GNUNET_ERROR_TYPE_DEBUG, " channel destoyed\n");
       return;
+    }
   }
 
   /* ACK client if needed and possible */
@@ -2111,8 +2123,11 @@ GCCH_handle_data_ack (struct CadetChannel *ch,
     }
     else
     {
-      /* Work was done but no task was pending? Shouldn't happen! */
-      GNUNET_break (0);
+      /* Work was done but no task was pending.
+       * Task was cancelled by a retransmission that is sitting in the queue.
+       */
+      // FIXME add test to make sure this is the case, probably add return
+      // value to GCCH_send_prebuilt_message
     }
   }
 }
@@ -2134,8 +2149,10 @@ GCCH_handle_create (struct CadetTunnel *t,
   struct CadetChannel *ch;
   struct CadetClient *c;
   int new_channel;
+  uint32_t port;
 
   chid = ntohl (msg->chid);
+
   ch = GCT_get_channel (t, chid);
   if (NULL == ch)
   {
@@ -2149,11 +2166,17 @@ GCCH_handle_create (struct CadetTunnel *t,
   {
     new_channel = GNUNET_NO;
   }
+  port = ntohl (msg->port);
+
+  LOG (GNUNET_ERROR_TYPE_INFO,
+       "<== %s (  0x%08X %4u) on chan %s (%p) %s [%5u]\n",
+       GC_m2s (GNUNET_MESSAGE_TYPE_CADET_CHANNEL_CREATE), chid, port,
+       GCCH_2s (ch), ch, GC_f2s (GNUNET_YES), ntohs (msg->header.size));
 
   if (GNUNET_YES == new_channel || GCT_is_loopback (t))
   {
     /* Find a destination client */
-    ch->port = ntohl (msg->port);
+    ch->port = port;
     LOG (GNUNET_ERROR_TYPE_DEBUG, "   port %u\n", ch->port);
     c = GML_client_get_by_port (ch->port);
     if (NULL == c)
@@ -2218,6 +2241,11 @@ GCCH_handle_create (struct CadetTunnel *t,
 void
 GCCH_handle_nack (struct CadetChannel *ch)
 {
+  LOG (GNUNET_ERROR_TYPE_INFO,
+       "<== %s (  0x%08X %4u) on chan %s (%p) %s [%5u]\n",
+       GC_m2s (GNUNET_MESSAGE_TYPE_CADET_CHANNEL_NACK), ch->gid, 0,
+       GCCH_2s (ch), ch, "---", 0);
+
   send_client_nack (ch);
   GCCH_destroy (ch);
 }
@@ -2238,6 +2266,11 @@ GCCH_handle_ack (struct CadetChannel *ch,
                  const struct GNUNET_CADET_ChannelManage *msg,
                  int fwd)
 {
+  LOG (GNUNET_ERROR_TYPE_INFO,
+       "<== %s (  0x%08X %4u) on chan %s (%p) %s [%5u]\n",
+       GC_m2s (GNUNET_MESSAGE_TYPE_CADET_CHANNEL_ACK), ch->gid, 0,
+       GCCH_2s (ch), ch, GC_f2s (fwd), ntohs (msg->header.size));
+
   /* If this is a remote (non-loopback) channel, find 'fwd'. */
   if (GNUNET_SYSERR == fwd)
   {
@@ -2271,6 +2304,11 @@ GCCH_handle_destroy (struct CadetChannel *ch,
 {
   struct CadetChannelReliability *rel;
 
+  LOG (GNUNET_ERROR_TYPE_INFO,
+       "<== %s (  0x%08X %4u) on chan %s (%p) %s [%5u]\n",
+       GC_m2s (GNUNET_MESSAGE_TYPE_CADET_CHANNEL_DESTROY), ch->gid, 0,
+       GCCH_2s (ch), ch, GC_f2s (fwd), ntohs (msg->header.size));
+
   /* If this is a remote (non-loopback) channel, find 'fwd'. */
   if (GNUNET_SYSERR == fwd)
   {
@@ -2283,7 +2321,7 @@ GCCH_handle_destroy (struct CadetChannel *ch,
     fwd = (NULL != ch->dest) ? GNUNET_YES : GNUNET_NO;
   }
 
-  GCCH_debug (ch);
+  GCCH_debug (ch, GNUNET_ERROR_TYPE_DEBUG);
   if ( (fwd && NULL == ch->dest) || (!fwd && NULL == ch->root) )
   {
     /* Not for us (don't destroy twice a half-open loopback channel) */
@@ -2325,11 +2363,64 @@ GCCH_send_prebuilt_message (const struct GNUNET_MessageHeader *message,
                             void *existing_copy)
 {
   struct CadetChannelQueue *chq;
+  uint32_t data_id;
   uint16_t type;
+  uint16_t size;
+  char info[32];
 
   type = ntohs (message->type);
-  LOG (GNUNET_ERROR_TYPE_INFO, "===> %s %s on channel %s\n",
-       GC_m2s (type), GC_f2s (fwd), GCCH_2s (ch));
+  size = ntohs (message->size);
+
+  switch (type)
+  {
+    case GNUNET_MESSAGE_TYPE_CADET_DATA:
+    {
+      struct GNUNET_CADET_Data *data_msg;
+      struct GNUNET_MessageHeader *payload_msg;
+      uint16_t payload_type;
+
+      data_msg = (struct GNUNET_CADET_Data *) message;
+      data_id = ntohl (data_msg->mid);
+      payload_msg = (struct GNUNET_MessageHeader *) &data_msg[1];
+      payload_type = ntohs (payload_msg->type);
+      strncpy (info, GC_m2s (payload_type), 31);
+      info[31] = '\0';
+      break;
+    }
+    case GNUNET_MESSAGE_TYPE_CADET_DATA_ACK:
+    {
+      struct GNUNET_CADET_DataACK *ack_msg;
+      ack_msg = (struct GNUNET_CADET_DataACK *) message;
+      data_id = ntohl (ack_msg->mid);
+      SPRINTF (info, "0x%010lX", ack_msg->futures);
+      break;
+    }
+    case GNUNET_MESSAGE_TYPE_CADET_CHANNEL_CREATE:
+    {
+      struct GNUNET_CADET_ChannelCreate *cc_msg;
+      cc_msg = (struct GNUNET_CADET_ChannelCreate *) message;
+      data_id = ntohl (cc_msg->port);
+      SPRINTF (info, "  0x%08X", ntohl (cc_msg->chid));
+      break;
+    }
+    case GNUNET_MESSAGE_TYPE_CADET_CHANNEL_ACK:
+    case GNUNET_MESSAGE_TYPE_CADET_CHANNEL_NACK:
+    case GNUNET_MESSAGE_TYPE_CADET_CHANNEL_DESTROY:
+    {
+      struct GNUNET_CADET_ChannelManage *m_msg;
+      m_msg = (struct GNUNET_CADET_ChannelManage *) message;
+      data_id = 0;
+      SPRINTF (info, "  0x%08X", ntohl (m_msg->chid));
+      break;
+    }
+    default:
+      data_id = 0;
+      info[0] = '\0';
+  }
+  LOG (GNUNET_ERROR_TYPE_INFO,
+       "==> %s (%12s %4u) on chan %s (%p) %s [%5u]\n",
+       GC_m2s (type), info, data_id,
+       GCCH_2s (ch), ch, GC_f2s (fwd), size);
 
   if (GCT_is_loopback (ch->t))
   {
@@ -2339,12 +2430,7 @@ GCCH_send_prebuilt_message (const struct GNUNET_MessageHeader *message,
 
   switch (type)
   {
-    struct GNUNET_CADET_Data *payload;
     case GNUNET_MESSAGE_TYPE_CADET_DATA:
-
-      payload = (struct GNUNET_CADET_Data *) message;
-      LOG (GNUNET_ERROR_TYPE_INFO, "===> %s %u\n",
-           GC_m2s (type), ntohl (payload->mid));
       if (GNUNET_YES == ch->reliable)
       {
         chq = GNUNET_new (struct CadetChannelQueue);
@@ -2378,7 +2464,7 @@ GCCH_send_prebuilt_message (const struct GNUNET_MessageHeader *message,
         LOG (GNUNET_ERROR_TYPE_DEBUG, "  new chq: %p\n", chq);
         chq->copy->chq = chq;
         chq->tq = GCT_send_prebuilt_message (message, ch->t, NULL,
-                                             NULL != existing_copy,
+                                             GNUNET_YES,
                                              &ch_message_sent, chq);
         /* q itself is stored in copy */
         GNUNET_assert (NULL != chq->tq || GNUNET_NO != ch->destroy);
@@ -2433,7 +2519,7 @@ GCCH_send_prebuilt_message (const struct GNUNET_MessageHeader *message,
 
     default:
       GNUNET_break (0);
-      LOG (GNUNET_ERROR_TYPE_DEBUG, "type %s unknown!\n", GC_m2s (type));
+      LOG (GNUNET_ERROR_TYPE_WARNING, "type %s unknown!\n", GC_m2s (type));
       fire_and_forget (message, ch, GNUNET_YES);
   }
 }