From 1e30974ec0ae6efd6516ec14d27d339339dad08c Mon Sep 17 00:00:00 2001 From: Christian Grothoff Date: Wed, 25 May 2011 10:21:22 +0000 Subject: [PATCH] clean up logging, set rim ID always, even if neighbour was not found --- src/core/core_api.c | 40 ++++++++++++-------- src/core/gnunet-service-core.c | 69 ++++++++++++++++++++-------------- 2 files changed, 65 insertions(+), 44 deletions(-) diff --git a/src/core/core_api.c b/src/core/core_api.c index 195e94e29..daf93b3c4 100644 --- a/src/core/core_api.c +++ b/src/core/core_api.c @@ -578,10 +578,9 @@ request_next_transmission (struct PeerRecord *pr) 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 @@ transmit_message (void *cls, 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 @@ main_notify_handler (void *cls, 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 @@ main_notify_handler (void *cls, 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 @@ main_notify_handler (void *cls, } #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_CORE_peer_request_connect (struct GNUNET_CORE_Handle *h, 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 @@ GNUNET_CORE_peer_request_connect_cancel (struct GNUNET_CORE_PeerRequestHandle *r 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 @@ GNUNET_CORE_peer_change_preference (struct GNUNET_CORE_Handle *h, 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 @@ GNUNET_CORE_peer_change_preference (struct GNUNET_CORE_Handle *h, 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; } diff --git a/src/core/gnunet-service-core.c b/src/core/gnunet-service-core.c index fce515e0f..0b7886796 100644 --- a/src/core/gnunet-service-core.c +++ b/src/core/gnunet-service-core.c @@ -963,7 +963,7 @@ send_to_client (struct Client *client, 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 @@ send_to_all_clients (const struct GNUNET_MessageHeader *msg, { 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 @@ handle_peer_status_change (struct Neighbour *n) 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 @@ handle_client_request_info (void *cls, #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 @@ do_encrypt (struct Neighbour *n, &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_encrypted_neighbour_queue (struct Neighbour *n) 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 @@ do_decrypt (struct Neighbour *n, 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 @@ select_messages (struct Neighbour *n, 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 @@ select_messages (struct Neighbour *n, } 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 @@ batch_message (struct Neighbour *n, 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 @@ batch_message (struct Neighbour *n, } 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 @@ process_plaintext_neighbour_queue (struct Neighbour *n) } 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 @@ process_plaintext_neighbour_queue (struct Neighbour *n) &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 @@ process_plaintext_neighbour_queue (struct Neighbour *n) &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 @@ process_plaintext_neighbour_queue (struct Neighbour *n) 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 @@ handle_ping (struct Neighbour *n, 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 @@ handle_pong (struct Neighbour *n, 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 @@ deliver_message (void *cls, 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 @@ handle_transport_receive (void *cls, 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 @@ handle_transport_receive (void *cls, 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 @@ handle_transport_receive (void *cls, 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 @@ neighbour_quota_update (void *cls, 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)); -- 2.25.1