5 files changed, 110 insertions, 15 deletions

diff --git a/src/util/client.c b/src/util/client.c
index 3d74bff33..e5bf7e176 100644
--- a/src/util/client.c
+++ b/src/util/client.c
@@ -261,14 +261,27 @@ transmit_ready (void *cls)
   pos = (const char *) cstate->msg;
   len = ntohs (cstate->msg->size);
   GNUNET_assert (cstate->msg_off < len);
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+              "client: message of type %u trying to send with socket %p (MQ: %p\n",
+              ntohs(cstate->msg->type),
+              cstate->sock,
+              cstate->mq);
+
  RETRY:
   ret = GNUNET_NETWORK_socket_send (cstate->sock,
                                     &pos[cstate->msg_off],
                                     len - cstate->msg_off);
   if (-1 == ret)
   {
-    if (EINTR == errno)
+    GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+                "client: error during sending message of type %u\n",
+                ntohs(cstate->msg->type));
+    if (EINTR == errno){
+      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+                  "client: retrying message of type %u\n",
+                  ntohs(cstate->msg->type));
       goto RETRY;
+    }
     GNUNET_MQ_inject_error (cstate->mq,
                             GNUNET_MQ_ERROR_WRITE);
     return;
@@ -277,6 +290,9 @@ transmit_ready (void *cls)
   cstate->msg_off += ret;
   if (cstate->msg_off < len)
   {
+    GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+                "client: rescheduling message of type %u\n",
+                ntohs(cstate->msg->type));
     cstate->send_task
       = GNUNET_SCHEDULER_add_write_net (GNUNET_TIME_UNIT_FOREVER_REL,
                                         cstate->sock,
@@ -286,6 +302,9 @@ transmit_ready (void *cls)
       GNUNET_MQ_impl_send_in_flight (cstate->mq);
     return;
   }
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+              "client: sending message of type %u successful\n",
+              ntohs(cstate->msg->type));
   cstate->msg = NULL;
   GNUNET_MQ_impl_send_continue (cstate->mq);
 }
@@ -297,7 +316,9 @@ transmit_ready (void *cls)
  *
  * @param cls the `struct ClientState`
  * @param msg message we received.
- * @return #GNUNET_OK on success, #GNUNET_SYSERR to stop further processing
+ * @return #GNUNET_OK on success,
+ *     #GNUNET_NO to stop further processing due to disconnect (no error)
+ *     #GNUNET_SYSERR to stop further processing due to error
  */
 static int
 recv_message (void *cls,
@@ -306,7 +327,7 @@ recv_message (void *cls,
   struct ClientState *cstate = cls;
 
   if (GNUNET_YES == cstate->in_destroy)
-    return GNUNET_SYSERR;
+    return GNUNET_NO;
   LOG (GNUNET_ERROR_TYPE_DEBUG,
        "Received message of type %u and size %u from %s\n",
        ntohs (msg->type),
@@ -315,7 +336,7 @@ recv_message (void *cls,
   GNUNET_MQ_inject_message (cstate->mq,
                             msg);
   if (GNUNET_YES == cstate->in_destroy)
-    return GNUNET_SYSERR;
+    return GNUNET_NO;
   return GNUNET_OK;
 }
 
@@ -371,8 +392,12 @@ connection_client_destroy_impl (struct GNUNET_MQ_Handle *mq,
     GNUNET_SCHEDULER_cancel (cstate->recv_task);
   if (NULL != cstate->retry_task)
     GNUNET_SCHEDULER_cancel (cstate->retry_task);
-  if (NULL != cstate->sock)
+  if (NULL != cstate->sock){
+    GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+                "client: destroying socket: %p\n",
+                cstate->sock);
     GNUNET_NETWORK_socket_close (cstate->sock);
+  }
   cancel_aps (cstate);
   GNUNET_free (cstate->service_name);
   GNUNET_free_non_null (cstate->hostname);
@@ -794,8 +819,12 @@ connection_client_send_impl (struct GNUNET_MQ_Handle *mq,
   GNUNET_assert (NULL == cstate->send_task);
   cstate->msg = msg;
   cstate->msg_off = 0;
-  if (NULL == cstate->sock)
+  if (NULL == cstate->sock){
+    GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+                "client: message of type %u waiting for socket\n",
+                ntohs(msg->type));
     return; /* still waiting for connection */
+   }
   cstate->send_task
     = GNUNET_SCHEDULER_add_write_net (GNUNET_TIME_UNIT_FOREVER_REL,
                                       cstate->sock,
diff --git a/src/util/mq.c b/src/util/mq.c
index 90b2aa968..8d71359ac 100644
--- a/src/util/mq.c
+++ b/src/util/mq.c
@@ -357,6 +357,12 @@ GNUNET_MQ_send (struct GNUNET_MQ_Handle *mq,
   }
   GNUNET_assert (NULL == mq->envelope_head);
   mq->current_envelope = ev;
+
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+              "mq: sending message of type %u, queue empty (MQ: %p)\n",
+              ntohs(ev->mh->type),
+              mq);
+
   mq->send_impl (mq,
                  ev->mh,
                  mq->impl_state);
@@ -452,6 +458,11 @@ impl_send_continue (void *cls)
   GNUNET_CONTAINER_DLL_remove (mq->envelope_head,
                                mq->envelope_tail,
                                mq->current_envelope);
+
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+              "mq: sending message of type %u from queue\n",
+              ntohs(mq->current_envelope->mh->type));
+
   mq->send_impl (mq,
                  mq->current_envelope->mh,
                  mq->impl_state);
@@ -840,6 +851,9 @@ GNUNET_MQ_destroy (struct GNUNET_MQ_Handle *mq)
                                  ev);
     GNUNET_assert (0 < mq->queue_length);
     mq->queue_length--;
+    GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+                "MQ destroy drops message of type %u\n",
+                ntohs (ev->mh->type));
     GNUNET_MQ_discard (ev);
   }
   if (NULL != mq->current_envelope)
@@ -847,6 +861,9 @@ GNUNET_MQ_destroy (struct GNUNET_MQ_Handle *mq)
     /* we can only discard envelopes that
      * are not queued! */
     mq->current_envelope->parent_queue = NULL;
+    GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+                "MQ destroy drops current message of type %u\n",
+                ntohs (mq->current_envelope->mh->type));
     GNUNET_MQ_discard (mq->current_envelope);
     mq->current_envelope = NULL;
     GNUNET_assert (0 < mq->queue_length);
@@ -928,6 +945,11 @@ GNUNET_MQ_send_cancel (struct GNUNET_MQ_Envelope *ev)
       GNUNET_CONTAINER_DLL_remove (mq->envelope_head,
                                    mq->envelope_tail,
                                    mq->current_envelope);
+
+      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+                  "mq: sending canceled message of type %u queue\n",
+                  ntohs(ev->mh->type));
+
       mq->send_impl (mq,
                      mq->current_envelope->mh,
                      mq->impl_state);
diff --git a/src/util/mst.c b/src/util/mst.c
index 0d90c5d10..5e472965f 100644
--- a/src/util/mst.c
+++ b/src/util/mst.c
@@ -1,6 +1,6 @@
 /*
      This file is part of GNUnet.
-     Copyright (C) 2010, 2016 GNUnet e.V.
+     Copyright (C) 2010, 2016, 2017 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
@@ -126,6 +126,7 @@ GNUNET_MST_from_buffer (struct GNUNET_MessageStreamTokenizer *mst,
   int need_align;
   unsigned long offset;
   int ret;
+  int cbret;
 
   GNUNET_assert (mst->off <= mst->pos);
   GNUNET_assert (mst->pos <= mst->curr_buf);
@@ -229,9 +230,17 @@ do_align:
     if (one_shot == GNUNET_YES)
       one_shot = GNUNET_SYSERR;
     mst->off += want;
-  if (GNUNET_SYSERR == mst->cb (mst->cb_cls,
-                                hdr))
+    if (GNUNET_OK !=
+        (cbret = mst->cb (mst->cb_cls,
+                           hdr)))
+    {
+      if (GNUNET_SYSERR == cbret)
+        GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+                    "Failure processing message of type %u and size %u\n",
+                    ntohs (hdr->type),
+                    ntohs (hdr->size));
       return GNUNET_SYSERR;
+    }
     if (mst->off == mst->pos)
     {
       /* reset to beginning of buffer, it's free right now! */
@@ -271,9 +280,17 @@ do_align:
       }
       if (one_shot == GNUNET_YES)
         one_shot = GNUNET_SYSERR;
-      if (GNUNET_SYSERR == mst->cb (mst->cb_cls,
-                                    hdr))
+      if (GNUNET_OK !=
+          (cbret = mst->cb (mst->cb_cls,
+                            hdr)))
+      {
+        if (GNUNET_SYSERR == cbret)
+          GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+                      "Failure processing message of type %u and size %u\n",
+                      ntohs (hdr->type),
+                      ntohs (hdr->size));
         return GNUNET_SYSERR;
+      }
       buf += want;
       size -= want;
     }
diff --git a/src/util/scheduler.c b/src/util/scheduler.c
index 540a60557..4615ecee9 100644
--- a/src/util/scheduler.c
+++ b/src/util/scheduler.c
@@ -589,9 +589,7 @@ static void
 dump_backtrace (struct GNUNET_SCHEDULER_Task *t)
 {
 #if EXECINFO
-  unsigned int i;
-
-  for (i = 0; i < t->num_backtrace_strings; i++)
+  for (unsigned int i = 0; i < t->num_backtrace_strings; i++)
     LOG (GNUNET_ERROR_TYPE_DEBUG,
          "Task %p trace %u: %s\n",
          t,
diff --git a/src/util/service.c b/src/util/service.c
index fcdf45a51..b4eb33caa 100644
--- a/src/util/service.c
+++ b/src/util/service.c
@@ -1932,6 +1932,11 @@ do_send (void *cls)
   size_t left;
   const char *buf;
 
+  LOG (GNUNET_ERROR_TYPE_DEBUG,
+       "service: sending message with type %u",
+       ntohs(client->msg->type));
+
+
   client->send_task = NULL;
   buf = (const char *) client->msg;
   left = ntohs (client->msg->size) - client->msg_pos;
@@ -1941,6 +1946,8 @@ do_send (void *cls)
   GNUNET_assert (ret <= (ssize_t) left);
   if (0 == ret)
   {
+    LOG (GNUNET_ERROR_TYPE_DEBUG,
+         "no data send");
     GNUNET_MQ_inject_error (client->mq,
                             GNUNET_MQ_ERROR_WRITE);
     return;
@@ -1958,6 +1965,9 @@ do_send (void *cls)
       if (EPIPE != errno)
         GNUNET_log_strerror (GNUNET_ERROR_TYPE_WARNING,
                              "send");
+      LOG (GNUNET_ERROR_TYPE_DEBUG,
+           "socket send returned with error code %i",
+           errno);
       GNUNET_MQ_inject_error (client->mq,
                               GNUNET_MQ_ERROR_WRITE);
       return;
@@ -2402,7 +2412,7 @@ resume_client_receive (void *cls)
                          GNUNET_YES);
   if (GNUNET_SYSERR == ret)
   {
-    if (NULL != c->drop_task)
+    if (NULL == c->drop_task)
       GNUNET_SERVICE_client_drop (c);
     return;
   }
@@ -2431,6 +2441,7 @@ resume_client_receive (void *cls)
 void
 GNUNET_SERVICE_client_continue (struct GNUNET_SERVICE_Client *c)
 {
+  GNUNET_assert (NULL == c->drop_task);
   GNUNET_assert (GNUNET_YES == c->needs_continue);
   GNUNET_assert (NULL == c->recv_task);
   c->needs_continue = GNUNET_NO;
@@ -2513,6 +2524,24 @@ GNUNET_SERVICE_client_drop (struct GNUNET_SERVICE_Client *c)
 {
   struct GNUNET_SERVICE_Handle *sh = c->sh;
 
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+              "Client dropped: %p (MQ: %p)\n",
+              c,
+              c->mq);
+
+#if EXECINFO
+  void *backtrace_array[MAX_TRACE_DEPTH];
+  int num_backtrace_strings = backtrace (backtrace_array, MAX_TRACE_DEPTH);
+    char **backtrace_strings =
+        backtrace_symbols (backtrace_array,
+         t->num_backtrace_strings);
+    for (unsigned int i = 0; i < num_backtrace_strings; i++)
+      LOG (GNUNET_ERROR_TYPE_DEBUG,
+     "client drop trace %u: %s\n",
+     i,
+     backtrace_strings[i]);
+#endif
+
   if (NULL != c->drop_task)
   {
     /* asked to drop twice! */