[GNUnet-SVN] r15294 - gnunet/src/core

[gnunet]

Author: grothoff
Date: 2011-05-25 12:21:22 +0200 (Wed, 25 May 2011)
New Revision: 15294

Modified:
   gnunet/src/core/core_api.c
   gnunet/src/core/gnunet-service-core.c
Log:
clean up logging, set rim ID always, even if neighbour was not found

Modified: gnunet/src/core/core_api.c
===================================================================
--- gnunet/src/core/core_api.c  2011-05-25 10:20:03 UTC (rev 15293)
+++ gnunet/src/core/core_api.c  2011-05-25 10:21:22 UTC (rev 15294)
@@ -578,10 +578,9 @@
   smr->queue_size = htonl (pr->queue_size);
   smr->size = htons (th->msize);
   smr->smr_id = htons (th->smr_id = pr->smr_id_gen++);
-  GNUNET_CONTAINER_DLL_insert_after (h->control_pending_head,
-                                    h->control_pending_tail,
-                                    h->control_pending_tail,
-                                    cm);
+  GNUNET_CONTAINER_DLL_insert_tail (h->control_pending_head,
+                                   h->control_pending_tail,
+                                   cm);
 #if DEBUG_CORE
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
              "Adding SEND REQUEST for peer `%s' to message queue\n",
@@ -726,8 +725,14 @@
       ret = th->get_message (th->get_message_cls,
                             size - sizeof (struct SendMessage),
                             &sm[1]);
-
-      if (0 == ret)
+ 
+#if DEBUG_CORE
+      GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+                 "Transmitting SEND request to `%s' yielded %u bytes.\n",
+                 GNUNET_i2s (&pr->peer),
+                 ret);
+#endif
+     if (0 == ret)
        {
 #if DEBUG_CORE
          GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
@@ -852,7 +857,7 @@
       return;
     }
   msize = ntohs (msg->size);
-#if DEBUG_CORE
+#if DEBUG_CORE > 2
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Processing message of type %u and size %u from core service\n",
               ntohs (msg->type), msize);
@@ -1030,7 +1035,7 @@
          reconnect_later (h);
          return;
         }
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                  "Received notification about status change by `%s'.\n",
                  GNUNET_i2s (&psnm->peer));
@@ -1238,8 +1243,9 @@
        }
 #if DEBUG_CORE
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-                 "Received notification about configuration update for 
`%s'.\n",
-                 GNUNET_i2s (&cim->peer));
+                 "Received notification about configuration update for `%s' 
with RIM %u.\n",
+                 GNUNET_i2s (&cim->peer),
+                 (unsigned int) ntohl (cim->rim_id));
 #endif
       pr = GNUNET_CONTAINER_multihashmap_get (h->peers,
                                              &cim->peer.hashPubKey);
@@ -1793,8 +1799,7 @@
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
              "Queueing REQUEST_CONNECT request\n");
 #endif
-  if (h->control_pending_head == cm)
-    trigger_next_request (h, GNUNET_NO);
+  trigger_next_request (h, GNUNET_NO);
   return ret;
 }
 
@@ -1811,6 +1816,10 @@
   struct GNUNET_CORE_Handle *h = req->h;
   struct ControlMessage *cm = req->cm;
 
+#if DEBUG_CORE
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+             "A CHANGE PREFERENCE request was cancelled!\n");
+#endif
   GNUNET_CONTAINER_DLL_remove (h->control_pending_head,
                               h->control_pending_tail,
                               cm);
@@ -1929,7 +1938,9 @@
   rim->peer = *peer;
 #if DEBUG_CORE
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
-             "Queueing CHANGE PREFERENCE request\n");
+             "Queueing CHANGE PREFERENCE request for peer `%s' with RIM %u\n",
+             GNUNET_i2s (peer),
+             (unsigned int) pr->rim_id);
 #endif
   GNUNET_CONTAINER_DLL_insert_tail (h->control_pending_head,
                                    h->control_pending_tail,
@@ -1937,8 +1948,7 @@
   pr->pcic = info;
   pr->pcic_cls = info_cls;
   pr->pcic_ptr = irc; /* for free'ing irc */
-  if (h->control_pending_head == cm)
-    trigger_next_request (h, GNUNET_NO);
+  trigger_next_request (h, GNUNET_NO);
   return irc;
 }
 

Modified: gnunet/src/core/gnunet-service-core.c
===================================================================
--- gnunet/src/core/gnunet-service-core.c       2011-05-25 10:20:03 UTC (rev 
15293)
+++ gnunet/src/core/gnunet-service-core.c       2011-05-25 10:21:22 UTC (rev 
15294)
@@ -963,7 +963,7 @@
                 const struct GNUNET_MessageHeader *msg, 
                int can_drop)
 {
-#if DEBUG_CORE_CLIENT
+#if DEBUG_CORE_CLIENT 
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Preparing to send %u bytes of message of type %u to client.\n",
              (unsigned int) ntohs (msg->size),
@@ -996,7 +996,7 @@
     {
       if (0 != (c->options & options))
        {
-#if DEBUG_CORE_CLIENT
+#if DEBUG_CORE_CLIENT > 1
          GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                      "Sending message of type %u to client.\n",
                      (unsigned int) ntohs (msg->type));
@@ -1025,7 +1025,7 @@
   if ( (! n->is_connected) ||
        (n->status != PEER_STATE_KEY_CONFIRMED) )
     return;
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Peer `%4s' changed status\n",
              GNUNET_i2s (&n->peer));
@@ -1652,13 +1652,22 @@
 #endif
       cim.reserved_amount = htonl (got_reserv);
       cim.reserve_delay = GNUNET_TIME_relative_hton (rdelay);
-      cim.rim_id = rcm->rim_id;
       cim.bw_out = n->bw_out;
       cim.preference = n->current_preference;
     }
+  else
+    {
+      /* Technically, this COULD happen (due to asynchronous behavior),
+        but it is very odd, so we should at least generate a stern
+        warning */
+      GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
+                 "Client asked for preference change with peer `%s', which is 
not connected!\n",
+                 GNUNET_i2s (&rcm->peer));
+    }
   cim.header.size = htons (sizeof (struct ConfigurationInfoMessage));
   cim.header.type = htons (GNUNET_MESSAGE_TYPE_CORE_CONFIGURATION_INFO);
   cim.peer = rcm->peer;
+  cim.rim_id = rcm->rim_id;
 #if DEBUG_CORE_CLIENT
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Sending `%s' message to client.\n", "CONFIGURATION_INFO");
@@ -1782,7 +1791,7 @@
                                             &n->encrypt_key,
                                             iv, out));
   GNUNET_STATISTICS_update (stats, gettext_noop ("# bytes encrypted"), size, 
GNUNET_NO);
-#if DEBUG_CORE
+#if DEBUG_CORE > 2
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Encrypted %u bytes for `%4s' using key %u, IV %u\n",
              (unsigned int) size,
@@ -2028,7 +2037,7 @@
       process_plaintext_neighbour_queue (n);
       return;
     }
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Asking transport for transmission of %u bytes to `%4s' in next 
%llu ms\n",
               (unsigned int) m->size,
@@ -2099,7 +2108,7 @@
                            gettext_noop ("# bytes decrypted"), 
                            size, 
                            GNUNET_NO);
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Decrypted %u bytes from `%4s' using key %u, IV %u\n",
               (unsigned int) size, 
@@ -2292,7 +2301,7 @@
           pos->do_transmit = GNUNET_YES;        /* mark for transmission */
           off += pos->size;
           size -= pos->size;
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
          GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                      "Selecting message of size %u for transmission\n",
                      (unsigned int) pos->size);
@@ -2300,7 +2309,7 @@
         }
       else
        {
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
          GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                      "Not selecting message of size %u for transmission at 
this time (maximum is %u)\n",
                      (unsigned int) pos->size,
@@ -2412,7 +2421,7 @@
           ret += pos->size;
           size -= pos->size;
           *priority += pos->priority;
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
          GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                      "Adding plaintext message of size %u with deadline %llu 
ms to batch\n",
                      (unsigned int) pos->size,
@@ -2431,7 +2440,7 @@
         }
       pos = next;
     }
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
              "Deadline for message batch is %llu ms\n",
              GNUNET_TIME_absolute_get_remaining (*deadline).rel_value);
@@ -2610,7 +2619,7 @@
     }
   if (n->encrypted_head != NULL)
     {
-#if DEBUG_CORE
+#if DEBUG_CORE > 2
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                   "Encrypted message queue for `%4s' is still full, delaying 
plaintext processing.\n",
                  GNUNET_i2s(&n->peer));
@@ -2628,7 +2637,7 @@
                          &deadline, &retry_time, &priority);
   if (used == sizeof (struct EncryptedMessage))
     {
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
       GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                   "No messages selected for transmission to `%4s' at this 
time, will try again later.\n",
                  GNUNET_i2s(&n->peer));
@@ -2639,7 +2648,7 @@
                                       &retry_plaintext_processing, n);
       return;
     }
-#if DEBUG_CORE_QUOTA
+#if DEBUG_CORE_QUOTA 
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
              "Sending %u b/s as new limit to peer `%4s'\n",
              (unsigned int) ntohl (n->bw_in.value__),
@@ -2661,7 +2670,7 @@
   em->iv_seed = ph->iv_seed;
   derive_iv (&iv, &n->encrypt_key, ph->iv_seed, &n->peer);
   /* encrypt */
-#if DEBUG_HANDSHAKE
+#if DEBUG_HANDSHAKE 
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Encrypting %u bytes of plaintext messages for `%4s' for 
transmission in %llums.\n",
              (unsigned int) used - ENCRYPTED_HEADER_SIZE,
@@ -3535,14 +3544,16 @@
   if (0 != memcmp (&t.target,
                    &my_identity, sizeof (struct GNUNET_PeerIdentity)))
     {
-      char * sender;
-         GNUNET_asprintf(&sender, "%s",GNUNET_i2s (&n->peer));
-         char * peer;
-         GNUNET_asprintf(&peer, "%s",GNUNET_i2s (&t.target));
-         GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
-                 "Received PING from `%s' for different identity: I am `%s', 
PONG identity: `%s'\n",sender, GNUNET_i2s (&my_identity), peer );
-         GNUNET_free (sender);
-         GNUNET_free (peer);
+      char sender[9];
+      char peer[9];
+
+      GNUNET_snprintf(sender, sizeof (sender), "%8s", GNUNET_i2s (&n->peer));
+      GNUNET_snprintf(peer, sizeof (peer), "%8s", GNUNET_i2s (&t.target));
+      GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
+                 _("Received PING from `%s' for different identity: I am `%s', 
PONG identity: `%s'\n"),
+                 sender,
+                 GNUNET_i2s (&my_identity), 
+                 peer);
       GNUNET_break_op (0);
       return;
     }
@@ -3609,7 +3620,7 @@
   struct GNUNET_TRANSPORT_ATS_Information *mats;
   size_t size;
 
-#if DEBUG_CORE
+#if DEBUG_HANDSHAKE
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Core service receives `%s' response from `%4s'.\n",
               "PONG", GNUNET_i2s (&n->peer));
@@ -4001,7 +4012,7 @@
   int dropped;
 
   type = ntohs (m->type);
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
              "Received encapsulated message of type %u and size %u from 
`%4s'\n",
              (unsigned int) type,
@@ -4258,7 +4269,7 @@
   uint16_t size;
   int changed;
 
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
               "Received message of type %u from `%4s', demultiplexing.\n",
               (unsigned int) ntohs (message->type), 
@@ -4323,7 +4334,7 @@
       if ((n->status != PEER_STATE_KEY_RECEIVED) &&
           (n->status != PEER_STATE_KEY_CONFIRMED))
         {
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
           GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                       "Core service receives `%s' request from `%4s' but have 
not processed key; marking as pending.\n",
                       "PING", GNUNET_i2s (&n->peer));
@@ -4346,7 +4357,7 @@
       if ( (n->status != PEER_STATE_KEY_RECEIVED) &&
           (n->status != PEER_STATE_KEY_CONFIRMED) )
         {
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
           GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
                       "Core service receives `%s' request from `%4s' but have 
not processed key; marking as pending.\n",
                       "PONG", GNUNET_i2s (&n->peer));
@@ -4412,7 +4423,7 @@
   uint64_t need_per_second;
   unsigned int neighbour_count;
 
-#if DEBUG_CORE
+#if DEBUG_CORE > 1
   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
              "Neighbour quota update calculation running for peer `%4s'\n",
              GNUNET_i2s (&n->peer));