}
-// FIXME: improve logging after this point!
-
/**
* Pick a queue of @a n under constraints @a options and schedule
* transmission of @a hdr.
{
/* This can happen rarely if the last confirmed queue timed
out just as we were beginning to process this message. */
+ GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+ "Could not route message of type %u to %s: no valid queue\n",
+ ntohs (hdr->type),
+ GNUNET_i2s (&n->pid));
GNUNET_STATISTICS_update (GST_stats,
"# route selection failed (all no valid queue)",
1,
(pos->validated_until.abs_value_us > now.abs_value_us))
{
if ((sel1 == candidates) || (sel2 == candidates))
+ {
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Routing message of type %u to %s using %s (#%u)\n",
+ ntohs (hdr->type),
+ GNUNET_i2s (&n->pid),
+ pos->address,
+ (sel1 == candidates) ? 1 : 2);
queue_send_msg (pos, NULL, hdr, ntohs (hdr->size));
+ }
candidates++;
}
}
hops,
(0 == (options & RMO_REDUNDANT)) ? 1 : 2);
for (unsigned int i = 0; i < res; i++)
+ {
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Routing message of type %u to %s using DV (#%u/%u)\n",
+ ntohs (hdr->type),
+ GNUNET_i2s (&dv->target),
+ i + 1,
+ res + 1);
forward_via_dvh (hops[i], hdr, options & (~RMO_REDUNDANT));
+ }
}
}
if ((NULL == n) && (NULL == dv))
{
+ GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+ "Cannot route message of type %u to %s: no route\n",
+ ntohs (hdr->type),
+ GNUNET_i2s (target));
GNUNET_STATISTICS_update (GST_stats,
"# Messages dropped in routing: no acceptable method",
1,
GNUNET_free (hdr);
return;
}
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Routing message of type %u to %s with options %X\n",
+ ntohs (hdr->type),
+ GNUNET_i2s (target),
+ (unsigned int) options);
/* If both dv and n are possible and we must choose:
flip a coin for the choice between the two; for now 50/50 */
if ((NULL != n) && (NULL != dv) && (0 == (options & RMO_REDUNDANT)))
sizeof (km),
iv,
sizeof (*iv)));
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Deriving backchannel key based on KM %s and IV %s\n",
+ GNUNET_h2s (km),
+ GNUNET_sh2s (iv));
gcry_cipher_open (&key->cipher,
GCRY_CIPHER_AES256 /* low level: go for speed */,
GCRY_CIPHER_MODE_CTR,
char *mpos;
uint16_t msize;
+ {
+ const struct GNUNET_MessageHeader *inbox;
+ const char *is;
+
+ inbox = (const struct GNUNET_MessageHeader *) &cb[1];
+ /* 0-termination of 'is' was checked already in
+ #check_communicator_backchannel() */
+ is = (const char *) &cb[1];
+ is += ntohs (inbox->size);
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Preparing backchannel transmission to %s:%s of type %u\n",
+ GNUNET_i2s (&cb->pid),
+ is,
+ ntohs (inbox->size));
+ }
/* encapsulate and encrypt message */
msize = ntohs (cb->header.size) - sizeof (*cb) +
sizeof (struct TransportBackchannelRequestPayloadP);
GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
"Failed to store our own address `%s' in peerstore!\n",
ale->address);
+ else
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Successfully stored our own address `%s' in peerstore!\n",
+ ale->address);
/* refresh period is 1/4 of expiration time, that should be plenty
without being excessive. */
ale->st =
ale->st = NULL;
expiration = GNUNET_TIME_relative_to_absolute (ale->expiration);
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Storing our address `%s' in peerstore until %s!\n",
+ ale->address,
+ GNUNET_STRINGS_absolute_time_to_string (expiration));
GNUNET_HELLO_sign_address (ale->address,
ale->nt,
hello_mono_time,
struct AddressListEntry *ale;
size_t slen;
+ /* 0-termination of &aam[1] was checked in #check_add_address */
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Communicator added address `%s'!\n",
+ (const char *) &aam[1]);
slen = ntohs (aam->header.size) - sizeof (*aam);
ale = GNUNET_malloc (sizeof (struct AddressListEntry) + slen);
ale->tc = tc;
if (dam->aid != ale->aid)
continue;
GNUNET_assert (ale->tc == tc);
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Communicator deleted address `%s'!\n",
+ ale->address);
free_address_list_entry (ale);
GNUNET_SERVICE_client_continue (tc->client);
}
struct CommunicatorMessageContext *cmc = cls;
struct VirtualLink *vl;
uint16_t size = ntohs (mh->size);
+ int have_core;
if ((size > UINT16_MAX - sizeof (struct InboundMessage)) ||
(size < sizeof (struct GNUNET_MessageHeader)))
return;
}
/* Forward to all CORE clients */
+ have_core = GNUNET_NO;
for (struct TransportClient *tc = clients_head; NULL != tc; tc = tc->next)
{
struct GNUNET_MQ_Envelope *env;
if (CT_CORE != tc->type)
continue;
+ have_core = GNUNET_YES;
env = GNUNET_MQ_msg_extra (im, size, GNUNET_MESSAGE_TYPE_TRANSPORT_RECV);
im->peer = cmc->im.sender;
memcpy (&im[1], mh, size);
GNUNET_MQ_send (tc->mq, env);
}
vl->core_recv_window--;
+ if (GNUNET_NO == have_core)
+ GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+ "Dropped message to CORE: no CORE client connected!\n");
+ else
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Delivered message from %s of type %u to CORE\n",
+ GNUNET_i2s (&cmc->im.sender),
+ ntohs (mh->type));
if (vl->core_recv_window > 0)
{
finish_cmc_handling (cmc);
struct TransportCummulativeAckPayloadP *ap;
ac->task = NULL;
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Sending ACK with %u components to %s\n",
+ ac->ack_counter,
+ GNUNET_i2s (&ac->target));
GNUNET_assert (0 < ac->ack_counter);
ack = GNUNET_malloc (sizeof (*ack) +
ac->ack_counter *
{
struct AcknowledgementCummulator *ac;
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Scheduling ACK %s for transmission to %s\n",
+ GNUNET_sh2s (&ack_uuid->value),
+ GNUNET_i2s (pid));
ac = GNUNET_CONTAINER_multipeermap_get (ack_cummulators, pid);
if (NULL == ac)
{
target = (char *) &rc[1];
rc->bitfield = (uint8_t *) (target + rc->msg_size);
rc->msg_missing = rc->msg_size;
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Received fragment at offset %u/%u from %s for NEW message %u\n",
+ ntohs (fb->frag_off),
+ msize,
+ GNUNET_i2s (&cmc->im.sender),
+ (unsigned int) fb->msg_uuid.uuid);
}
else
{
target = (char *) &rc[1];
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Received fragment at offset %u/%u from %s for message %u\n",
+ ntohs (fb->frag_off),
+ msize,
+ GNUNET_i2s (&cmc->im.sender),
+ (unsigned int) fb->msg_uuid.uuid);
}
if (msize != rc->msg_size)
{
return;
}
/* successful reassembly */
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Fragment reassembly complete for message %u\n",
+ (unsigned int) fb->msg_uuid.uuid);
+
demultiplex_with_cmc (cmc, msg);
/* FIXME-OPTIMIZE: really free here? Might be bad if fragments are still
en-route and we forget that we finished this reassembly immediately!
struct CommunicatorMessageContext *cmc = cls;
const struct GNUNET_MessageHeader *inbox =
(const struct GNUNET_MessageHeader *) &rb[1];
+ struct GNUNET_TIME_Relative rtt;
- // FIXME: call cummulative_ack(), have ack_countdown influence max_delay!
- (void) (0 == ntohl (rb->ack_countdown));
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Received reliability box from %s with UUID %s of type %u\n",
+ GNUNET_i2s (&cmc->im.sender),
+ GNUNET_sh2s (&rb->ack_uuid.value),
+ (unsigned int) ntohs (inbox->type));
+ rtt = GNUNET_TIME_UNIT_SECONDS; /* FIXME: should base this on "RTT", but we
+ do not really have an RTT for the
+ *incoming* queue (should we have
+ the sender add it to the rb message?) */
+ cummulative_ack (
+ &cmc->im.sender,
+ &rb->ack_uuid,
+ (0 == ntohl (rb->ack_countdown))
+ ? GNUNET_TIME_UNIT_ZERO_ABS
+ : GNUNET_TIME_relative_to_absolute (
+ GNUNET_TIME_relative_divide (rtt, 8 /* FIXME: magic constant */)));
/* continue with inner message */
demultiplex_with_cmc (cmc, inbox);
}
GNUNET_CONTAINER_multishortmap_get (pending_acks, &ack[i].ack_uuid.value);
if (NULL == pa)
{
+ GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+ "Received ACK from %s with UUID %s which is unknown to us!\n",
+ GNUNET_i2s (&cmc->im.sender),
+ GNUNET_sh2s (&ack[i].ack_uuid.value));
GNUNET_STATISTICS_update (
GST_stats,
"# FRAGMENT_ACKS dropped, no matching pending message",
GNUNET_NO);
continue;
}
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Received ACK from %s with UUID %s\n",
+ GNUNET_i2s (&cmc->im.sender),
+ GNUNET_sh2s (&ack[i].ack_uuid.value));
handle_acknowledged (pa, GNUNET_TIME_relative_ntoh (ack[i].ack_delay));
}
return;
}
/* Finally, deliver backchannel message to communicator */
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Delivering backchannel message from %s of type %u to %s\n",
+ GNUNET_i2s (&b->pid),
+ ntohs (mh->type),
+ target_communicator);
env = GNUNET_MQ_msg_extra (
cbi,
msg_size,
mt = GNUNET_TIME_absolute_ntoh (*mtbe);
if (mt.abs_value_us > b->monotonic_time.abs_value_us)
{
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Backtalker message from %s dropped, monotime in the past\n",
+ GNUNET_i2s (&b->pid));
GNUNET_STATISTICS_update (
GST_stats,
"# Backchannel messages dropped: monotonic time not increasing",
if (0 != GNUNET_memcmp (&be->target, &GST_my_identity))
{
/* not for me, try to route to target */
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Forwarding backtalk to %s\n",
+ GNUNET_i2s (&be->target));
route_message (&be->target,
GNUNET_copy_message (&be->header),
RMO_DV_ALLOWED);
bc_decrypt (&key, &body, &hdr[sizeof (ppay)], hdr_len - sizeof (ppay));
bc_key_clean (&key);
monotime = GNUNET_TIME_absolute_ntoh (ppay.monotonic_time);
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Decrypted backtalk from %s\n",
+ GNUNET_i2s (&ppay.sender));
b = GNUNET_CONTAINER_multipeermap_get (backtalkers, &ppay.sender);
if ((NULL != b) && (monotime.abs_value_us < b->monotonic_time.abs_value_us))
{
{
/* Link was already up, remember dv is also now available and we are done */
vl->dv = dv;
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Virtual link to %s could now also use DV!\n",
+ GNUNET_i2s (&dv->target));
return;
}
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Creating new virtual link to %s using DV!\n",
+ GNUNET_i2s (&dv->target));
vl = GNUNET_new (struct VirtualLink);
vl->target = dv->target;
vl->dv = dv;
}
+// FIXME: add logging logic from here!
+
+
/**
* We have learned a @a path through the network to some other peer, add it to
* our DV data structure (returning #GNUNET_YES on success).
{
/* Link was already up, remember n is also now available and we are done */
vl->n = n;
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Virtual link to %s could now also direct neighbour!\n",
+ GNUNET_i2s (&vs->pid));
return;
}
+ GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
+ "Creating new virtual link to %s using direct neighbour!\n",
+ GNUNET_i2s (&vs->pid));
vl = GNUNET_new (struct VirtualLink);
vl->target = n->pid;
vl->n = n;
projects / oweals / gnunet.git / commitdiff