gnunet-svn
[Top][All Lists]
Advanced

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

[GNUnet-SVN] r8497 - in gnunet/src: core transport util


From: gnunet
Subject: [GNUnet-SVN] r8497 - in gnunet/src: core transport util
Date: Tue, 9 Jun 2009 15:45:43 -0600

Author: grothoff
Date: 2009-06-09 15:45:43 -0600 (Tue, 09 Jun 2009)
New Revision: 8497

Modified:
   gnunet/src/core/core.h
   gnunet/src/core/gnunet-service-core.c
   gnunet/src/transport/transport_api.c
   gnunet/src/util/network.c
Log:
nicer log messages

Modified: gnunet/src/core/core.h
===================================================================
--- gnunet/src/core/core.h      2009-06-09 18:20:23 UTC (rev 8496)
+++ gnunet/src/core/core.h      2009-06-09 21:45:43 UTC (rev 8497)
@@ -26,9 +26,17 @@
 #include "gnunet_crypto_lib.h"
 #include "gnunet_time_lib.h"
 
+/**
+ * General core debugging.
+ */
 #define DEBUG_CORE GNUNET_YES
 
 /**
+ * Debugging interaction core-clients.
+ */
+#define DEBUG_CORE_CLIENT GNUNET_NO
+
+/**
  * Definition of bits in the InitMessage's options field that specify
  * which events this client cares about.  Note that inbound messages
  * for handlers that were specifically registered are always

Modified: gnunet/src/core/gnunet-service-core.c
===================================================================
--- gnunet/src/core/gnunet-service-core.c       2009-06-09 18:20:23 UTC (rev 
8496)
+++ gnunet/src/core/gnunet-service-core.c       2009-06-09 21:45:43 UTC (rev 
8497)
@@ -728,12 +728,16 @@
   size_t ret;
 
   client->th = NULL;
+#if DEBUG_CORE_CLIENT
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Client ready to receive %u bytes.\n", size);
+#endif
   if (buf == NULL)
     {
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+#if DEBUG_CORE
+      GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
                   "Failed to transmit data to client (disconnect)?\n");
+#endif
       return 0;                 /* we'll surely get a disconnect soon... */
     }
   tgt = buf;
@@ -749,8 +753,10 @@
   GNUNET_assert (ret > 0);
   if (client->event_head == NULL)
     client->event_tail = NULL;
+#if DEBUG_CORE_CLIENT
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Transmitting %u bytes to client\n", ret);
+#endif
   request_transmit (client);
   return ret;
 }
@@ -769,9 +775,11 @@
     return;                     /* already pending */
   if (NULL == client->event_head)
     return;                     /* no more events pending */
+#if DEBUG_CORE_CLIENT
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Asking server to transmit %u bytes to client\n",
               client->event_head->size);
+#endif
   client->th
     = GNUNET_SERVER_notify_transmit_ready (client->client_handle,
                                            client->event_head->size,
@@ -794,9 +802,11 @@
   struct Event *e;
   uint16_t msize;
 
+#if DEBUG_CORE_CLIENT
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Preparing to send message of type %u to client.\n",
               ntohs (msg->type));
+#endif
   msize = ntohs (msg->size);
   e = GNUNET_malloc (sizeof (struct Event) + msize);
   /* append */
@@ -845,9 +855,11 @@
   struct Neighbour *n;
   struct ConnectNotifyMessage cnm;
 
+#if DEBUG_CORE_CLIENT
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Client connecting to core service with `%s' message\n",
               "INIT");
+#endif
   /* check that we don't have an entry already */
   c = clients;
   while (c != NULL)
@@ -885,8 +897,10 @@
   memcpy (&irm.publicKey,
           &my_public_key,
           sizeof (struct GNUNET_CRYPTO_RsaPublicKeyBinaryEncoded));
+#if DEBUG_CORE_CLIENT
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Sending `%s' message to client.\n", "INIT_REPLY");
+#endif
   send_to_client (c, &irm.header, GNUNET_NO);
   /* notify new client about existing neighbours */
   cnm.header.size = htons (sizeof (struct ConnectNotifyMessage));
@@ -894,8 +908,10 @@
   n = neighbours;
   while (n != NULL)
     {
+#if DEBUG_CORE_CLIENT
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                   "Sending `%s' message to client.\n", "NOTIFY_CONNECT");
+#endif
       cnm.bpm_available = htonl (n->bpm_out);
       cnm.last_activity = GNUNET_TIME_absolute_hton (n->last_activity);
       cnm.peer = n->peer;
@@ -918,8 +934,10 @@
   struct Client *pos;
   struct Client *prev;
 
+#if DEBUG_CORE_CLIENT
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Client has disconnected from core service.\n");
+#endif
   prev = NULL;
   pos = clients;
   while (pos != NULL)
@@ -956,8 +974,10 @@
   struct Client *c;
   int reserv;
 
+#if DEBUG_CORE_CLIENT
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Core service receives `%s' request.\n", "CONFIGURE");
+#endif
   rcm = (const struct RequestConfigureMessage *) message;
   n = find_neighbour (&rcm->peer);
   memset (&cim, 0, sizeof (cim));
@@ -997,8 +1017,10 @@
       GNUNET_break (0);
       return;
     }
+#if DEBUG_CORE_CLIENT
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Sending `%s' message to client.\n", "CONFIGURATION_INFO");
+#endif
   send_to_client (c, &cim.header, GNUNET_NO);
 }
 
@@ -1031,9 +1053,6 @@
   char *cbuf;
 
   n->th = NULL;
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Transport ready to receive %u bytes for `%4s'\n",
-              size, GNUNET_i2s (&n->peer));
   GNUNET_assert (NULL != (m = n->encrypted_head));
   n->encrypted_head = m->next;
   if (m->next == NULL)
@@ -1053,7 +1072,7 @@
     }
   else
     {
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+      GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
                   "Transmission for message of type %u and size %u failed\n",
                   ntohs (((struct GNUNET_MessageHeader *) &m[1])->type),
                   m->size);
@@ -1084,15 +1103,10 @@
 process_encrypted_neighbour_queue (struct Neighbour *n)
 {
   if (n->th != NULL)
-    {
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Asked to process encrypted queue, but request already 
pending.\n");
-      return;                   /* already pending */
-    }
+    return;  /* request already pending */
   if (n->encrypted_head == NULL)
     {
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Encrypted queue empty, trying plaintext queue instead.\n");
+      /* encrypted queue empty, try plaintext instead */
       process_plaintext_neighbour_queue (n);
       return;
     }
@@ -1473,9 +1487,6 @@
   struct GNUNET_TIME_Absolute deadline;
   struct GNUNET_TIME_Relative retry_time;
 
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Processing plaintext message queue for `%4s', scheduling 
messages.\n",
-              GNUNET_i2s (&n->peer));
   if (n->retry_plaintext_task != GNUNET_SCHEDULER_NO_PREREQUISITE_TASK)
     {
       GNUNET_SCHEDULER_cancel (sched, n->retry_plaintext_task);
@@ -1486,19 +1497,22 @@
     case PEER_STATE_DOWN:
       send_key (n);
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Not yet connected, deferring processing of plaintext 
messages.\n");
+                  "Not yet connected to `%4s', deferring processing of 
plaintext messages.\n",
+                 GNUNET_i2s(&n->peer));
       return;
     case PEER_STATE_KEY_SENT:
       GNUNET_assert (n->retry_set_key_task !=
                      GNUNET_SCHEDULER_NO_PREREQUISITE_TASK);
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Not yet connected, deferring processing of plaintext 
messages.\n");
+                  "Not yet connected to `%4s', deferring processing of 
plaintext messages.\n",
+                 GNUNET_i2s(&n->peer));
       return;
     case PEER_STATE_KEY_RECEIVED:
       GNUNET_assert (n->retry_set_key_task !=
                      GNUNET_SCHEDULER_NO_PREREQUISITE_TASK);
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Not yet connected, deferring processing of plaintext 
messages.\n");
+                  "Not yet connected to `%4s', deferring processing of 
plaintext messages.\n",
+                 GNUNET_i2s(&n->peer));
       return;
     case PEER_STATE_KEY_CONFIRMED:
       /* ready to continue */
@@ -1507,14 +1521,16 @@
   if (n->messages == NULL)
     {
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Plaintext message queue is empty.\n");
+                  "Plaintext message queue for `%4s' is empty.\n",
+                 GNUNET_i2s(&n->peer));
       return;                   /* no pending messages */
     }
   discard_expired_messages (n);
   if (n->encrypted_head != NULL)
     {
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Encrypted message queue is still full, delaying plaintext 
processing.\n");
+                  "Encrypted message queue for `%4s' is still full, delaying 
plaintext processing.\n",
+                 GNUNET_i2s(&n->peer));
       return;                   /* wait for messages already encrypted to be
                                    processed first! */
     }
@@ -1530,7 +1546,8 @@
   if (used == sizeof (struct EncryptedMessage))
     {
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "No messages selected for processing at this time, will try 
again later.\n");
+                  "No messages selected for transmission to `%4s' at this 
time, will try again later.\n",
+                 GNUNET_i2s(&n->peer));
       /* no messages selected for sending, try again later... */
       n->retry_plaintext_task =
         GNUNET_SCHEDULER_add_delayed (sched,
@@ -1559,7 +1576,9 @@
   GNUNET_CRYPTO_hash (&ph->sequence_number, esize, &em->plaintext_hash);
   /* encrypt */
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Encrypting plaintext messages for transmission.\n");
+              "Encrypting %u bytes of plaintext messages for `%4s' for 
transmission.\n",
+             esize,
+             GNUNET_i2s(&n->peer));
   GNUNET_assert (GNUNET_OK ==
                  do_encrypt (n,
                              &em->plaintext_hash,
@@ -1602,7 +1621,7 @@
 
   if (buf == NULL)
     {
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+      GNUNET_log (GNUNET_ERROR_TYPE_INFO,
                   "Asked to send message to disconnected peer `%4s' and 
connection failed.  Discarding message.\n",
                   GNUNET_i2s (&sm->peer));
       GNUNET_free (sm);
@@ -1611,7 +1630,7 @@
       return 0;
     }
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Connection to peer `%4s' succeeded, retrying original send 
request\n",
+              "Connection to peer `%4s' succeeded, retrying original 
transmission request\n",
               GNUNET_i2s (&sm->peer));
   handle_client_send (NULL, NULL, &sm->header);
   GNUNET_free (sm);
@@ -1636,8 +1655,6 @@
   struct MessageEntry *e;
   uint16_t msize;
 
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Core service receives `%s' request.\n", "SEND");
   msize = ntohs (message->size);
   if (msize <
       sizeof (struct SendMessage) + sizeof (struct GNUNET_MessageHeader))
@@ -1661,7 +1678,8 @@
   if (n == NULL)
     {
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Not yet connected to `%4s', will try to establish 
connection within %llu ms\n",
+                  "Core received `%s' request for `%4s', will try to establish 
connection within %llu ms\n",
+                 "SEND",
                   GNUNET_i2s (&sm->peer),
                  sm->deadline.value);
       msize += sizeof (struct SendMessage);
@@ -1685,8 +1703,10 @@
       return;
     }
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Core queues %u bytes of plaintext data for transmission to 
`%4s'.\n",
-              msize, GNUNET_i2s (&sm->peer));
+              "Core received `%s' request, queueing %u bytes of plaintext data 
for transmission to `%4s'.\n",
+             "SEND",
+              msize, 
+             GNUNET_i2s (&sm->peer));
   /* FIXME: consider bounding queue size */
   e = GNUNET_malloc (sizeof (struct MessageEntry) + msize);
   e->deadline = GNUNET_TIME_absolute_ntoh (sm->deadline);
@@ -1758,7 +1778,8 @@
   if (n->public_key != NULL)
     return;
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Received new HELLO for `%4s', initiating key exchange.\n",
+              "Received new `%s' message for `%4s', initiating key 
exchange.\n",
+             "HELLO",
               GNUNET_i2s (peer));
   n->public_key =
     GNUNET_malloc (sizeof (struct GNUNET_CRYPTO_RsaPublicKeyBinaryEncoded));
@@ -1897,8 +1918,6 @@
       break;
     }
   /* trigger queue processing */
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Triggering processing of encrypted message queue.\n");
   process_encrypted_neighbour_queue (n);
   if (n->status != PEER_STATE_KEY_CONFIRMED)
     n->retry_set_key_task
@@ -1946,9 +1965,6 @@
       GNUNET_free (sm);
       return;
     }
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Looking for peer `%4s' to handle `%s' message.\n",
-              GNUNET_i2s (peer), "SET_KEY");
   n = find_neighbour (peer);
   if (n == NULL)
     {
@@ -1961,6 +1977,7 @@
     GNUNET_malloc (sizeof (struct GNUNET_CRYPTO_RsaPublicKeyBinaryEncoded));
   if (GNUNET_OK != GNUNET_HELLO_get_key (hello, n->public_key))
     {
+      GNUNET_break_op (0);
       GNUNET_free (n->public_key);
       n->public_key = NULL;
       return;
@@ -2251,7 +2268,8 @@
   struct NotifyTrafficMessage *ntm;
 
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Core service passes P2P message of type %u to client.\n",
+              "Core service passes message from `%4s' of type %u to client.\n",
+             GNUNET_i2s(&sender->peer),
               ntohs (((const struct GNUNET_MessageHeader *) m)->type));
   ntm = (struct NotifyTrafficMessage *) buf;
   ntm->header.size = htons (msize + sizeof (struct NotifyTrafficMessage));
@@ -2279,8 +2297,6 @@
   unsigned int tpos;
   int deliver_full;
 
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Passing decrypted P2P message to interested clients.\n");
   type = ntohs (m->type);
   cpos = clients;
   while (cpos != NULL)
@@ -2343,9 +2359,6 @@
   uint16_t msize;
   int need_align;
 
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Delivering %u bytes of plaintext to interested clients.\n",
-              buffer_size);
   while (offset + sizeof (struct GNUNET_MessageHeader) <= buffer_size)
     {
       if (0 != offset % sizeof (uint16_t))
@@ -2425,7 +2438,7 @@
   snum = ntohl (pt->sequence_number);
   if (n->last_sequence_number_received == snum)
     {
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+      GNUNET_log (GNUNET_ERROR_TYPE_INFO,
                   "Received duplicate message, ignoring.\n");
       /* duplicate, ignore */
       return;
@@ -2433,7 +2446,7 @@
   if ((n->last_sequence_number_received > snum) &&
       (n->last_sequence_number_received - snum > 32))
     {
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+      GNUNET_log (GNUNET_ERROR_TYPE_INFO,
                   "Received ancient out of sequence message, ignoring.\n");
       /* ancient out of sequence, ignore */
       return;
@@ -2444,7 +2457,7 @@
         1 << (n->last_sequence_number_received - snum - 1);
       if ((n->last_packets_bitmap & rotbit) != 0)
         {
-          GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+          GNUNET_log (GNUNET_ERROR_TYPE_INFO,
                       "Received duplicate message, ignoring.\n");
           /* duplicate, ignore */
           return;
@@ -2604,8 +2617,6 @@
   struct GNUNET_TIME_Absolute now;
   struct ConnectNotifyMessage cnm;
 
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Received connection from `%4s'.\n", GNUNET_i2s (peer));
   n = find_neighbour (peer);
   if (n != NULL)
     {
@@ -2631,7 +2642,7 @@
   n->ping_challenge = GNUNET_CRYPTO_random_u32 (GNUNET_CRYPTO_QUALITY_WEAK,
                                                 (uint32_t) - 1);
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Created entry for new neighbour `%4s'.\n",
+              "Received connection from `%4s'.\n",
               GNUNET_i2s (&n->peer));
   cnm.header.size = htons (sizeof (struct ConnectNotifyMessage));
   cnm.header.type = htons (GNUNET_MESSAGE_TYPE_CORE_NOTIFY_CONNECT);
@@ -2725,7 +2736,8 @@
 static void
 cleaning_task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 {
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "Core service shutting down.\n");
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+             "Core service shutting down.\n");
   GNUNET_assert (transport != NULL);
   GNUNET_TRANSPORT_disconnect (transport);
   transport = NULL;

Modified: gnunet/src/transport/transport_api.c
===================================================================
--- gnunet/src/transport/transport_api.c        2009-06-09 18:20:23 UTC (rev 
8496)
+++ gnunet/src/transport/transport_api.c        2009-06-09 21:45:43 UTC (rev 
8497)
@@ -361,14 +361,14 @@
   size_t ret;
   char *cbuf;
 
-#if DEBUG_TRANSPORT
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Ready to transmit %u bytes to transport service\n", size);
-#endif
   h->network_handle = NULL;
   h->transmission_scheduled = GNUNET_NO;
   if (buf == NULL)
     {
+#if DEBUG_TRANSPORT
+      GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+                 "Could not transmit to transport service, cancelling pending 
requests\n");
+#endif
       th = h->connect_ready_head;
       if (th->next != NULL)
         th->next->prev = NULL;
@@ -381,7 +381,11 @@
       GNUNET_assert (0 == th->notify (th->notify_cls, 0, NULL));
       GNUNET_free (th);
       return 0;
-    }
+    } 
+#if DEBUG_TRANSPORT
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+              "Ready to transmit %u bytes to transport service\n", size);
+#endif
   cbuf = buf;
   ret = 0;
   h->network_handle = NULL;
@@ -427,28 +431,11 @@
 
   GNUNET_assert (NULL == h->network_handle);
   if (h->client == NULL)
-    {
-#if DEBUG_TRANSPORT
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Not yet connected to transport service, need to wait.\n");
-#endif
-      return;
-    }
+    return; /* not yet connected */
   th = h->connect_ready_head;
   if (th == NULL)
-    {
-#if DEBUG_TRANSPORT
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Schedule transmission called, but no request is 
pending.\n");
-#endif
-      return;
-    }
+    return; /* no request pending */
   h->transmission_scheduled = GNUNET_YES;
-#if DEBUG_TRANSPORT
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Asking client API for transmission of %u bytes\n",
-              th->notify_size);
-#endif
   h->network_handle = GNUNET_CLIENT_notify_transmit_ready (h->client,
                                                            th->notify_size,
                                                            
GNUNET_TIME_absolute_get_remaining
@@ -518,10 +505,7 @@
                            void *notify_cls)
 {
   struct GNUNET_TRANSPORT_TransmitHandle *th;
-#if DEBUG_TRANSPORT
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Queueing %u bytes control transmission request.\n", size);
-#endif
+
   th = GNUNET_malloc (sizeof (struct GNUNET_TRANSPORT_TransmitHandle));
   th->handle = h;
   th->notify = notify;
@@ -770,7 +754,7 @@
   if (buf == NULL)
     {
 #if DEBUG_TRANSPORT
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+      GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
                   "Timeout while trying to transmit `%s' request.\n",
                   "HELLO");
 #endif
@@ -807,7 +791,7 @@
   if (handle->client == NULL)
     {
 #if DEBUG_TRANSPORT
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+      GNUNET_log (GNUNET_ERROR_TYPE_INFO,
                   "Not connected to transport service, dropping offered 
HELLO\n");
 #endif
       return;
@@ -835,8 +819,15 @@
   struct GNUNET_MessageHeader *s = buf;
 
   if (buf == NULL)
-    return 0;
+    {
 #if DEBUG_TRANSPORT
+      GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+                  "Timeout while trying to transmit `%s' request.\n",
+                  "START");
+#endif
+      return 0;
+    }
+#if DEBUG_TRANSPORT
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Transmitting `%s' request.\n", "START");
 #endif
@@ -984,7 +975,9 @@
   if (th->neighbour != NULL)
     th->neighbour->transmit_handle = NULL;
 #if DEBUG_TRANSPORT
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "Transmission request timed out.\n");
+  GNUNET_log (GNUNET_ERROR_TYPE_INFO, 
+             "Request for transmission to peer `%s' timed out.\n",
+             GNUNET_i2s(&th->target));
 #endif
   th->notify_delay_task = GNUNET_SCHEDULER_NO_PREREQUISITE_TASK;
   remove_from_wait_list (th);
@@ -1034,8 +1027,9 @@
           /* signal timeout! */
 #if DEBUG_TRANSPORT
           GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                      "Would need %llu ms before bandwidth is available for 
delivery, that is too long.  Signaling timeout.\n",
-                      duration.value);
+                      "Would need %llu ms before bandwidth is available for 
delivery to `%4s', that is too long.  Signaling timeout.\n",
+                      duration.value,
+                     GNUNET_i2s(&th->target));
 #endif
           remove_from_wait_list (th);
           th->notify (th->notify_cls, 0, NULL);
@@ -1044,7 +1038,8 @@
         }
 #if DEBUG_TRANSPORT
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Need more bandwidth, delaying delivery by %llu ms\n",
+                  "Need more bandwidth, delaying delivery to `%4s' by %llu 
ms\n",
+                 GNUNET_i2s(&th->target),
                   duration.value);
 #endif
       th->notify_delay_task
@@ -1081,7 +1076,8 @@
   n->transmit_ok = GNUNET_NO;
   remove_from_wait_list (th);
 #if DEBUG_TRANSPORT
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "Moving message to ready list\n");
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "Moving message for `%4s' to ready 
list\n",
+             GNUNET_i2s(&n->id));
 #endif
   insert_transmit_handle (&h->connect_ready_head, th);
   if (GNUNET_NO == h->transmission_scheduled)
@@ -1127,55 +1123,39 @@
   while (pos != NULL)
     {
       next = pos->next;
-#if DEBUG_TRANSPORT
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Found entry in connect_wait_head for `%4s'.\n",
-                  GNUNET_i2s (&pos->target));
-#endif
       if (0 == memcmp (pid,
                        &pos->target, sizeof (struct GNUNET_PeerIdentity)))
         {
-#if DEBUG_TRANSPORT
-          GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                      "Found pending request for new connection, will trigger 
now.\n");
-#endif
           pos->neighbour = n;
-          if (pos->notify_delay_task != GNUNET_SCHEDULER_NO_PREREQUISITE_TASK)
-            {
-              GNUNET_SCHEDULER_cancel (h->sched, pos->notify_delay_task);
-              pos->notify_delay_task = GNUNET_SCHEDULER_NO_PREREQUISITE_TASK;
-            }
           GNUNET_assert (NULL == n->transmit_handle);
           n->transmit_handle = pos;
+          if (prev == NULL)
+            h->connect_wait_head = next;
+          else
+            prev->next = next;
           if (GNUNET_YES == n->received_ack)
             {
 #if DEBUG_TRANSPORT
-              GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                          "`%s' already received, scheduling request\n",
-                          "ACK");
+             GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+                         "Found pending request for `%4s' will trigger it 
now.\n",
+                         GNUNET_i2s (&pos->target));
 #endif
+             if (pos->notify_delay_task != 
GNUNET_SCHEDULER_NO_PREREQUISITE_TASK)
+               {
+                 GNUNET_SCHEDULER_cancel (h->sched, pos->notify_delay_task);
+                 pos->notify_delay_task = 
GNUNET_SCHEDULER_NO_PREREQUISITE_TASK;
+               }
               schedule_request (pos);
             }
           else
             {
 #if DEBUG_TRANSPORT
-              GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                          "Still need to wait to receive `%s' message\n",
-                          "ACK");
+             GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+                         "Found pending request for `%4s' but still need `%s' 
before proceeding.\n",
+                         GNUNET_i2s (&pos->target),
+                         "ACK");
 #endif
-              pos->notify_delay_task
-                = GNUNET_SCHEDULER_add_delayed (h->sched,
-                                                GNUNET_NO,
-                                                GNUNET_SCHEDULER_PRIORITY_KEEP,
-                                                
GNUNET_SCHEDULER_NO_PREREQUISITE_TASK,
-                                                
GNUNET_TIME_absolute_get_remaining
-                                                (pos->timeout),
-                                                &transmit_timeout, pos);
             }
-          if (prev == NULL)
-            h->connect_wait_head = next;
-          else
-            prev->next = next;
           break;
         }
       prev = pos;
@@ -1282,8 +1262,8 @@
       handle->hwl_head = hwl->next;
       GNUNET_SCHEDULER_cancel (handle->sched, hwl->task);
       GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
-                  _
-                  ("Disconnect while trying to obtain HELLO from transport 
service.\n"));
+                  _("Disconnect while trying to obtain `%s' from transport 
service.\n"),
+                 "HELLO");
       if (hwl->rec != NULL)
         hwl->rec (hwl->rec_cls, GNUNET_TIME_UNIT_ZERO, NULL, NULL);
       GNUNET_free (hwl);
@@ -1328,7 +1308,9 @@
     {
 #if DEBUG_TRANSPORT
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Failed to transmit connect request to service.\n");
+                  "Failed to transmit `%s' request for `%4s' to service.\n",
+                 "TRY_CONNECT",
+                 GNUNET_i2s(&th->target));
 #endif
       th->notify (th->notify_cls, 0, NULL);
       GNUNET_free (th);
@@ -1471,7 +1453,7 @@
       if (h->client != NULL)
         {
 #if DEBUG_TRANSPORT
-          GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+          GNUNET_log (GNUNET_ERROR_TYPE_INFO,
                       "Error receiving from transport service, disconnecting 
temporarily.\n");
 #endif
           if (h->network_handle != NULL)
@@ -1759,7 +1741,10 @@
 
   if (size + sizeof (struct OutboundMessage) >=
       GNUNET_SERVER_MAX_MESSAGE_SIZE)
-    return NULL;
+    {
+      GNUNET_break (0);
+      return NULL;
+    }
 #if DEBUG_TRANSPORT
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Asking transport service for transmission of %u bytes to peer 
`%4s'.\n",
@@ -1780,10 +1765,6 @@
   th->neighbour = n;
   if (NULL == n)
     {
-#if DEBUG_TRANSPORT
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Transmission request could not be satisfied (not yet 
connected), adding it to pending request list.\n");
-#endif
       pos = handle->connect_wait_head;
       while (pos != NULL)
         {
@@ -1797,39 +1778,37 @@
                   "Will now try to connect to `%4s'.\n", GNUNET_i2s (target));
 #endif
       try_connect (th);
+      return th;
     }
-  else
+
+#if DEBUG_TRANSPORT
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+             "Transmission request queued for transmission to transport 
service.\n");
+#endif
+  GNUNET_assert (NULL == n->transmit_handle);
+  n->transmit_handle = th;
+  if (GNUNET_YES != n->received_ack)
     {
 #if DEBUG_TRANSPORT
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Transmission request queued for transmission to transport 
service.\n");
+                 "Connection to `%4s' is not yet confirmed connected, 
scheduling timeout (%llu ms) only.\n",
+                 GNUNET_i2s (target), timeout.value);
 #endif
-      GNUNET_assert (NULL == n->transmit_handle);
-      n->transmit_handle = th;
-      if (GNUNET_YES == n->received_ack)
-        {
+      th->notify_delay_task
+       = GNUNET_SCHEDULER_add_delayed (handle->sched,
+                                       GNUNET_NO,
+                                       GNUNET_SCHEDULER_PRIORITY_KEEP,
+                                       GNUNET_SCHEDULER_NO_PREREQUISITE_TASK,
+                                       timeout, &transmit_timeout, th);
+      return th;
+    }
+  
 #if DEBUG_TRANSPORT
-          GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                      "Peer `%4s' is connected, scheduling for delivery 
now.\n",
-                      GNUNET_i2s (target));
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+             "Peer `%4s' is ready to receive, scheduling message for delivery 
now.\n",
+             GNUNET_i2s (target));
 #endif
-          schedule_request (th);
-        }
-      else
-        {
-#if DEBUG_TRANSPORT
-          GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                      "Connection to `%4s' is not yet confirmed connected, 
scheduling timeout (%llums) only.\n",
-                      GNUNET_i2s (target), timeout.value);
-#endif
-          th->notify_delay_task
-            = GNUNET_SCHEDULER_add_delayed (handle->sched,
-                                            GNUNET_NO,
-                                            GNUNET_SCHEDULER_PRIORITY_KEEP,
-                                            
GNUNET_SCHEDULER_NO_PREREQUISITE_TASK,
-                                            timeout, &transmit_timeout, th);
-        }
-    }
+  schedule_request (th);
   return th;
 }
 
@@ -1845,6 +1824,12 @@
 {
   struct GNUNET_TRANSPORT_Handle *h;
 
+#if DEBUG_TRANSPORT
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+             "Transmission request of %u bytes to `%4s' was cancelled.\n",
+             th->notify_size - sizeof(struct OutboundMessage),
+             GNUNET_i2s (&th->target));
+#endif
   GNUNET_assert (th->notify == &client_notify_wrapper);
   remove_from_any_list (th);
   h = th->handle;

Modified: gnunet/src/util/network.c
===================================================================
--- gnunet/src/util/network.c   2009-06-09 18:20:23 UTC (rev 8496)
+++ gnunet/src/util/network.c   2009-06-09 21:45:43 UTC (rev 8497)
@@ -293,6 +293,9 @@
       GNUNET_free (uaddr);
       return NULL;
     }
+  GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+             _("Accepting connection from `%s'\n"),
+             GNUNET_a2s(uaddr, addrlen));
   ret = GNUNET_malloc (sizeof (struct GNUNET_NETWORK_SocketHandle) + maxbuf);
   ret->write_buffer = (char *) &ret[1];
   ret->write_buffer_size = maxbuf;
@@ -436,6 +439,10 @@
           GNUNET_break (0 == CLOSE (s));
           return GNUNET_SYSERR;
         }
+      GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+                 _("Trying to connect to `%s'\n"),
+                 GNUNET_a2s(sock->ai_pos->ai_addr,
+                            sock->ai_pos->ai_addrlen));
       if ((0 != CONNECT (s,
                          sock->ai_pos->ai_addr,
                          sock->ai_pos->ai_addrlen)) && (errno != EINPROGRESS))
@@ -513,7 +520,9 @@
     }
   /* connect succeeded! clean up "ai" */
 #if DEBUG_NETWORK
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "Connection succeeded!\n");
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, 
+             "Connection to `%s' succeeded!\n",
+             GNUNET_a2s(sock->addr, sock->addrlen));
 #endif
   freeaddrinfo (sock->ai);
   sock->ai_pos = NULL;
@@ -614,6 +623,9 @@
       GNUNET_break (0 == CLOSE (s));
       return NULL;
     }
+  GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+             _("Trying to connect to `%s'\n"),
+             GNUNET_a2s(serv_addr, addrlen));
   if ((0 != CONNECT (s, serv_addr, addrlen)) && (errno != EINPROGRESS))
     {
       /* maybe refused / unsupported address, try next */
@@ -655,10 +667,6 @@
 
   if (sock->write_task != GNUNET_SCHEDULER_NO_PREREQUISITE_TASK)
     {
-#if DEBUG_NETWORK
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Destroy code waiting for writes to complete.\n");
-#endif
       GNUNET_SCHEDULER_add_after (sock->sched,
                                   GNUNET_YES,
                                   GNUNET_SCHEDULER_PRIORITY_KEEP,
@@ -675,10 +683,6 @@
     }
   if (sock->read_task != GNUNET_SCHEDULER_NO_PREREQUISITE_TASK)
     {
-#if DEBUG_NETWORK
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Destroy code waiting for receive to complete.\n");
-#endif
       GNUNET_SCHEDULER_add_after (sock->sched,
                                   GNUNET_YES,
                                   GNUNET_SCHEDULER_PRIORITY_KEEP,
@@ -697,12 +701,7 @@
         }
     }
   if (sock->sock != -1)
-    {
-#if DEBUG_NETWORK
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "Closing socket.\n");
-#endif
-      GNUNET_break (0 == CLOSE (sock->sock));
-    }
+    GNUNET_break (0 == CLOSE (sock->sock));    
   GNUNET_free_non_null (sock->addr);
   if (sock->ai != NULL)
     freeaddrinfo (sock->ai);
@@ -720,10 +719,6 @@
 void
 GNUNET_NETWORK_socket_destroy (struct GNUNET_NETWORK_SocketHandle *sock)
 {
-#if DEBUG_NETWORK
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Network asked to destroy socket %p\n", sock);
-#endif
   if (sock->write_buffer_off == 0)
     sock->ai_pos = NULL;        /* if we're still trying to connect and have
                                    no message pending, stop trying! */
@@ -745,7 +740,7 @@
 
 #if DEBUG_NETWORK
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Network signals timeout to receiver!\n");
+              "Network signals time out to receiver!\n");
 #endif
   GNUNET_assert (NULL != (receiver = sh->receiver));
   sh->receiver = NULL;
@@ -787,7 +782,7 @@
     {
 #if DEBUG_NETWORK
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Receive encounters error: timeout...\n");
+                  "Receive encounters error: time out...\n");
 #endif
       signal_timeout (sh);
       return;
@@ -818,7 +813,10 @@
     }
 #if DEBUG_NETWORK
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Receive got %d bytes from OS!\n", ret);
+              "receive_ready read %u/%u bytes from `%s'!\n",
+             (unsigned int) ret, 
+             sh->max,
+             GNUNET_a2s(sh->addr, sh->addrlen));
 #endif
   GNUNET_assert (NULL != (receiver = sh->receiver));
   sh->receiver = NULL;
@@ -857,7 +855,7 @@
     {
 #if DEBUG_NETWORK
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Receive encounters error: timeout...\n");
+                  "Receive encounters error: time out...\n");
 #endif
       signal_timeout (sh);
       return;
@@ -865,32 +863,22 @@
   if (sh->connect_task != GNUNET_SCHEDULER_NO_PREREQUISITE_TASK)
     {
       /* connect was retried */
-#if DEBUG_NETWORK
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Receive still waits on connect...\n");
-#endif
       sh->read_task = GNUNET_SCHEDULER_add_after (tc->sched,
                                                   GNUNET_YES,
                                                   
GNUNET_SCHEDULER_PRIORITY_KEEP,
                                                   sh->connect_task,
                                                   &receive_again, sh);
+      return;
     }
-  else
-    {
-      /* connect succeeded, wait for data! */
-#if DEBUG_NETWORK
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Receive now waits for socket...\n");
-#endif
-      sh->read_task = GNUNET_SCHEDULER_add_read (tc->sched,
-                                                 GNUNET_YES,
-                                                 
GNUNET_SCHEDULER_PRIORITY_KEEP,
-                                                 sh->connect_task,
-                                                 
GNUNET_TIME_absolute_get_remaining
-                                                 (sh->receive_timeout),
-                                                 sh->sock, &receive_ready,
-                                                 sh);
-    }
+  /* connect succeeded, wait for data! */
+  sh->read_task = GNUNET_SCHEDULER_add_read (tc->sched,
+                                            GNUNET_YES,
+                                            GNUNET_SCHEDULER_PRIORITY_KEEP,
+                                            sh->connect_task,
+                                            GNUNET_TIME_absolute_get_remaining
+                                            (sh->receive_timeout),
+                                            sh->sock, &receive_ready,
+                                            sh);   
 }
 
 
@@ -916,10 +904,7 @@
                         GNUNET_NETWORK_Receiver receiver, void *receiver_cls)
 {
   struct GNUNET_SCHEDULER_TaskContext tc;
-#if DEBUG_NETWORK
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Network asked to receive from socket...\n");
-#endif
+
   GNUNET_assert ((sock->read_task == GNUNET_SCHEDULER_NO_PREREQUISITE_TASK) &&
                  (sock->receiver == NULL));
   sock->receiver = receiver;
@@ -1055,10 +1040,6 @@
   if (sock->connect_task != GNUNET_SCHEDULER_NO_PREREQUISITE_TASK)
     {
       /* still waiting for connect */
-#if DEBUG_NETWORK
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Transmission still waiting for connect...\n");
-#endif
       GNUNET_assert (sock->write_task ==
                      GNUNET_SCHEDULER_NO_PREREQUISITE_TASK);
       sock->write_task =
@@ -1072,31 +1053,21 @@
   if (sock->sock == -1)
     {
       GNUNET_log (GNUNET_ERROR_TYPE_INFO,
-                  _
-                  ("Did not transmit request, socket closed or connect 
failed.\n"));
+                  _("Could not satisfy pending transmission request, socket 
closed or connect failed.\n"));
       transmit_error (sock);
       return;                   /* connect failed for good, we're finished */
     }
   if ((tc->write_ready == NULL) || (!FD_ISSET (sock->sock, tc->write_ready)))
     {
-#if DEBUG_NETWORK
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Socket not yet ready for writing, will wait for that.\n");
-#endif
+      /* special circumstances: not yet ready to write */
       goto SCHEDULE_WRITE;
     }
-#if DEBUG_NETWORK
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Transmit ready called --- will try to send\n");
-#endif
   GNUNET_assert (sock->write_buffer_off >= sock->write_buffer_pos);
   process_notify (sock);
   have = sock->write_buffer_off - sock->write_buffer_pos;
   if (have == 0)
     {
-#if DEBUG_NETWORK
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "No data ready for writing.\n");
-#endif
+      /* no data ready for writing, terminate write loop */
       return;
     }
 RETRY:
@@ -1117,7 +1088,11 @@
       return;
     }
 #if DEBUG_NETWORK
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "Transmitted %d bytes to OS\n", ret);
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+              "transmit_ready transmitted %u/%u bytes to `%s'\n",
+             (unsigned int) ret,
+             have,
+             GNUNET_a2s(sock->addr, sock->addrlen));
 #endif
   sock->write_buffer_pos += ret;
   if (sock->write_buffer_pos == sock->write_buffer_off)
@@ -1125,18 +1100,10 @@
       /* transmitted all pending data */
       sock->write_buffer_pos = 0;
       sock->write_buffer_off = 0;
-#if DEBUG_NETWORK
-      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Transmission buffer now empty.\n", ret);
-#endif
     }
   if ((sock->write_buffer_off == 0) && (NULL == sock->nth.notify_ready))
     return;                     /* all data sent! */
   /* not done writing, schedule more */
-#if DEBUG_NETWORK
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "More data ready for transmission, scheduling task again!\n");
-#endif
 SCHEDULE_WRITE:
   if (sock->write_task == GNUNET_SCHEDULER_NO_PREREQUISITE_TASK)
     sock->write_task =
@@ -1180,7 +1147,7 @@
     {
 #if DEBUG_NETWORK
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                  "Transmit fails, connection failed.\n");
+                  "Transmission request fails, connection failed.\n");
 #endif
       notify (notify_cls, 0, NULL);
       return &sock->nth;
@@ -1200,10 +1167,6 @@
                                                          timeout,
                                                          &transmit_timeout,
                                                          sock);
-#if DEBUG_NETWORK
-  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-              "Scheduling asynchronous transmission once connect is 
done...\n");
-#endif
   if (sock->write_task == GNUNET_SCHEDULER_NO_PREREQUISITE_TASK)
     sock->write_task = GNUNET_SCHEDULER_add_delayed (sock->sched,
                                                      GNUNET_NO,





reply via email to

[Prev in Thread] Current Thread [Next in Thread]