diff options
author | Christian Grothoff <christian@grothoff.org> | 2019-05-07 11:47:22 +0200 |
---|---|---|
committer | Christian Grothoff <christian@grothoff.org> | 2019-05-07 11:47:22 +0200 |
commit | dc2c3d24159f8ad26c1b076f1de8ee057a6c58a5 (patch) | |
tree | 84394bdca80466d97bcfaba21136ac3ebe3c634c /src/transport/gnunet-service-tng.c | |
parent | da2a7dd658fa766a71444297051854b166b80fc0 (diff) | |
download | gnunet-dc2c3d24159f8ad26c1b076f1de8ee057a6c58a5.tar.gz gnunet-dc2c3d24159f8ad26c1b076f1de8ee057a6c58a5.zip |
add logging
Diffstat (limited to 'src/transport/gnunet-service-tng.c')
-rw-r--r-- | src/transport/gnunet-service-tng.c | 156 |
1 files changed, 152 insertions, 4 deletions
diff --git a/src/transport/gnunet-service-tng.c b/src/transport/gnunet-service-tng.c index df0303571..27b1a20c7 100644 --- a/src/transport/gnunet-service-tng.c +++ b/src/transport/gnunet-service-tng.c | |||
@@ -4166,8 +4166,6 @@ queue_send_msg (struct Queue *queue, | |||
4166 | } | 4166 | } |
4167 | 4167 | ||
4168 | 4168 | ||
4169 | // FIXME: improve logging after this point! | ||
4170 | |||
4171 | /** | 4169 | /** |
4172 | * Pick a queue of @a n under constraints @a options and schedule | 4170 | * Pick a queue of @a n under constraints @a options and schedule |
4173 | * transmission of @a hdr. | 4171 | * transmission of @a hdr. |
@@ -4205,6 +4203,10 @@ route_via_neighbour (const struct Neighbour *n, | |||
4205 | { | 4203 | { |
4206 | /* This can happen rarely if the last confirmed queue timed | 4204 | /* This can happen rarely if the last confirmed queue timed |
4207 | out just as we were beginning to process this message. */ | 4205 | out just as we were beginning to process this message. */ |
4206 | GNUNET_log (GNUNET_ERROR_TYPE_INFO, | ||
4207 | "Could not route message of type %u to %s: no valid queue\n", | ||
4208 | ntohs (hdr->type), | ||
4209 | GNUNET_i2s (&n->pid)); | ||
4208 | GNUNET_STATISTICS_update (GST_stats, | 4210 | GNUNET_STATISTICS_update (GST_stats, |
4209 | "# route selection failed (all no valid queue)", | 4211 | "# route selection failed (all no valid queue)", |
4210 | 1, | 4212 | 1, |
@@ -4224,7 +4226,15 @@ route_via_neighbour (const struct Neighbour *n, | |||
4224 | (pos->validated_until.abs_value_us > now.abs_value_us)) | 4226 | (pos->validated_until.abs_value_us > now.abs_value_us)) |
4225 | { | 4227 | { |
4226 | if ((sel1 == candidates) || (sel2 == candidates)) | 4228 | if ((sel1 == candidates) || (sel2 == candidates)) |
4229 | { | ||
4230 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
4231 | "Routing message of type %u to %s using %s (#%u)\n", | ||
4232 | ntohs (hdr->type), | ||
4233 | GNUNET_i2s (&n->pid), | ||
4234 | pos->address, | ||
4235 | (sel1 == candidates) ? 1 : 2); | ||
4227 | queue_send_msg (pos, NULL, hdr, ntohs (hdr->size)); | 4236 | queue_send_msg (pos, NULL, hdr, ntohs (hdr->size)); |
4237 | } | ||
4228 | candidates++; | 4238 | candidates++; |
4229 | } | 4239 | } |
4230 | } | 4240 | } |
@@ -4281,7 +4291,15 @@ route_via_dv (const struct DistanceVector *dv, | |||
4281 | hops, | 4291 | hops, |
4282 | (0 == (options & RMO_REDUNDANT)) ? 1 : 2); | 4292 | (0 == (options & RMO_REDUNDANT)) ? 1 : 2); |
4283 | for (unsigned int i = 0; i < res; i++) | 4293 | for (unsigned int i = 0; i < res; i++) |
4294 | { | ||
4295 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
4296 | "Routing message of type %u to %s using DV (#%u/%u)\n", | ||
4297 | ntohs (hdr->type), | ||
4298 | GNUNET_i2s (&dv->target), | ||
4299 | i + 1, | ||
4300 | res + 1); | ||
4284 | forward_via_dvh (hops[i], hdr, options & (~RMO_REDUNDANT)); | 4301 | forward_via_dvh (hops[i], hdr, options & (~RMO_REDUNDANT)); |
4302 | } | ||
4285 | } | 4303 | } |
4286 | 4304 | ||
4287 | 4305 | ||
@@ -4316,6 +4334,10 @@ route_message (const struct GNUNET_PeerIdentity *target, | |||
4316 | } | 4334 | } |
4317 | if ((NULL == n) && (NULL == dv)) | 4335 | if ((NULL == n) && (NULL == dv)) |
4318 | { | 4336 | { |
4337 | GNUNET_log (GNUNET_ERROR_TYPE_INFO, | ||
4338 | "Cannot route message of type %u to %s: no route\n", | ||
4339 | ntohs (hdr->type), | ||
4340 | GNUNET_i2s (target)); | ||
4319 | GNUNET_STATISTICS_update (GST_stats, | 4341 | GNUNET_STATISTICS_update (GST_stats, |
4320 | "# Messages dropped in routing: no acceptable method", | 4342 | "# Messages dropped in routing: no acceptable method", |
4321 | 1, | 4343 | 1, |
@@ -4323,6 +4345,11 @@ route_message (const struct GNUNET_PeerIdentity *target, | |||
4323 | GNUNET_free (hdr); | 4345 | GNUNET_free (hdr); |
4324 | return; | 4346 | return; |
4325 | } | 4347 | } |
4348 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
4349 | "Routing message of type %u to %s with options %X\n", | ||
4350 | ntohs (hdr->type), | ||
4351 | GNUNET_i2s (target), | ||
4352 | (unsigned int) options); | ||
4326 | /* If both dv and n are possible and we must choose: | 4353 | /* If both dv and n are possible and we must choose: |
4327 | flip a coin for the choice between the two; for now 50/50 */ | 4354 | flip a coin for the choice between the two; for now 50/50 */ |
4328 | if ((NULL != n) && (NULL != dv) && (0 == (options & RMO_REDUNDANT))) | 4355 | if ((NULL != n) && (NULL != dv) && (0 == (options & RMO_REDUNDANT))) |
@@ -4405,6 +4432,10 @@ bc_setup_key_state_from_km (const struct GNUNET_HashCode *km, | |||
4405 | sizeof (km), | 4432 | sizeof (km), |
4406 | iv, | 4433 | iv, |
4407 | sizeof (*iv))); | 4434 | sizeof (*iv))); |
4435 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
4436 | "Deriving backchannel key based on KM %s and IV %s\n", | ||
4437 | GNUNET_h2s (km), | ||
4438 | GNUNET_sh2s (iv)); | ||
4408 | gcry_cipher_open (&key->cipher, | 4439 | gcry_cipher_open (&key->cipher, |
4409 | GCRY_CIPHER_AES256 /* low level: go for speed */, | 4440 | GCRY_CIPHER_AES256 /* low level: go for speed */, |
4410 | GCRY_CIPHER_MODE_CTR, | 4441 | GCRY_CIPHER_MODE_CTR, |
@@ -4558,6 +4589,21 @@ handle_communicator_backchannel ( | |||
4558 | char *mpos; | 4589 | char *mpos; |
4559 | uint16_t msize; | 4590 | uint16_t msize; |
4560 | 4591 | ||
4592 | { | ||
4593 | const struct GNUNET_MessageHeader *inbox; | ||
4594 | const char *is; | ||
4595 | |||
4596 | inbox = (const struct GNUNET_MessageHeader *) &cb[1]; | ||
4597 | /* 0-termination of 'is' was checked already in | ||
4598 | #check_communicator_backchannel() */ | ||
4599 | is = (const char *) &cb[1]; | ||
4600 | is += ntohs (inbox->size); | ||
4601 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
4602 | "Preparing backchannel transmission to %s:%s of type %u\n", | ||
4603 | GNUNET_i2s (&cb->pid), | ||
4604 | is, | ||
4605 | ntohs (inbox->size)); | ||
4606 | } | ||
4561 | /* encapsulate and encrypt message */ | 4607 | /* encapsulate and encrypt message */ |
4562 | msize = ntohs (cb->header.size) - sizeof (*cb) + | 4608 | msize = ntohs (cb->header.size) - sizeof (*cb) + |
4563 | sizeof (struct TransportBackchannelRequestPayloadP); | 4609 | sizeof (struct TransportBackchannelRequestPayloadP); |
@@ -4640,6 +4686,10 @@ peerstore_store_own_cb (void *cls, int success) | |||
4640 | GNUNET_log (GNUNET_ERROR_TYPE_ERROR, | 4686 | GNUNET_log (GNUNET_ERROR_TYPE_ERROR, |
4641 | "Failed to store our own address `%s' in peerstore!\n", | 4687 | "Failed to store our own address `%s' in peerstore!\n", |
4642 | ale->address); | 4688 | ale->address); |
4689 | else | ||
4690 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
4691 | "Successfully stored our own address `%s' in peerstore!\n", | ||
4692 | ale->address); | ||
4643 | /* refresh period is 1/4 of expiration time, that should be plenty | 4693 | /* refresh period is 1/4 of expiration time, that should be plenty |
4644 | without being excessive. */ | 4694 | without being excessive. */ |
4645 | ale->st = | 4695 | ale->st = |
@@ -4665,6 +4715,10 @@ store_pi (void *cls) | |||
4665 | 4715 | ||
4666 | ale->st = NULL; | 4716 | ale->st = NULL; |
4667 | expiration = GNUNET_TIME_relative_to_absolute (ale->expiration); | 4717 | expiration = GNUNET_TIME_relative_to_absolute (ale->expiration); |
4718 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
4719 | "Storing our address `%s' in peerstore until %s!\n", | ||
4720 | ale->address, | ||
4721 | GNUNET_STRINGS_absolute_time_to_string (expiration)); | ||
4668 | GNUNET_HELLO_sign_address (ale->address, | 4722 | GNUNET_HELLO_sign_address (ale->address, |
4669 | ale->nt, | 4723 | ale->nt, |
4670 | hello_mono_time, | 4724 | hello_mono_time, |
@@ -4707,6 +4761,10 @@ handle_add_address (void *cls, | |||
4707 | struct AddressListEntry *ale; | 4761 | struct AddressListEntry *ale; |
4708 | size_t slen; | 4762 | size_t slen; |
4709 | 4763 | ||
4764 | /* 0-termination of &aam[1] was checked in #check_add_address */ | ||
4765 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
4766 | "Communicator added address `%s'!\n", | ||
4767 | (const char *) &aam[1]); | ||
4710 | slen = ntohs (aam->header.size) - sizeof (*aam); | 4768 | slen = ntohs (aam->header.size) - sizeof (*aam); |
4711 | ale = GNUNET_malloc (sizeof (struct AddressListEntry) + slen); | 4769 | ale = GNUNET_malloc (sizeof (struct AddressListEntry) + slen); |
4712 | ale->tc = tc; | 4770 | ale->tc = tc; |
@@ -4748,6 +4806,9 @@ handle_del_address (void *cls, | |||
4748 | if (dam->aid != ale->aid) | 4806 | if (dam->aid != ale->aid) |
4749 | continue; | 4807 | continue; |
4750 | GNUNET_assert (ale->tc == tc); | 4808 | GNUNET_assert (ale->tc == tc); |
4809 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
4810 | "Communicator deleted address `%s'!\n", | ||
4811 | ale->address); | ||
4751 | free_address_list_entry (ale); | 4812 | free_address_list_entry (ale); |
4752 | GNUNET_SERVICE_client_continue (tc->client); | 4813 | GNUNET_SERVICE_client_continue (tc->client); |
4753 | } | 4814 | } |
@@ -4782,6 +4843,7 @@ handle_raw_message (void *cls, const struct GNUNET_MessageHeader *mh) | |||
4782 | struct CommunicatorMessageContext *cmc = cls; | 4843 | struct CommunicatorMessageContext *cmc = cls; |
4783 | struct VirtualLink *vl; | 4844 | struct VirtualLink *vl; |
4784 | uint16_t size = ntohs (mh->size); | 4845 | uint16_t size = ntohs (mh->size); |
4846 | int have_core; | ||
4785 | 4847 | ||
4786 | if ((size > UINT16_MAX - sizeof (struct InboundMessage)) || | 4848 | if ((size > UINT16_MAX - sizeof (struct InboundMessage)) || |
4787 | (size < sizeof (struct GNUNET_MessageHeader))) | 4849 | (size < sizeof (struct GNUNET_MessageHeader))) |
@@ -4813,6 +4875,7 @@ handle_raw_message (void *cls, const struct GNUNET_MessageHeader *mh) | |||
4813 | return; | 4875 | return; |
4814 | } | 4876 | } |
4815 | /* Forward to all CORE clients */ | 4877 | /* Forward to all CORE clients */ |
4878 | have_core = GNUNET_NO; | ||
4816 | for (struct TransportClient *tc = clients_head; NULL != tc; tc = tc->next) | 4879 | for (struct TransportClient *tc = clients_head; NULL != tc; tc = tc->next) |
4817 | { | 4880 | { |
4818 | struct GNUNET_MQ_Envelope *env; | 4881 | struct GNUNET_MQ_Envelope *env; |
@@ -4820,12 +4883,21 @@ handle_raw_message (void *cls, const struct GNUNET_MessageHeader *mh) | |||
4820 | 4883 | ||
4821 | if (CT_CORE != tc->type) | 4884 | if (CT_CORE != tc->type) |
4822 | continue; | 4885 | continue; |
4886 | have_core = GNUNET_YES; | ||
4823 | env = GNUNET_MQ_msg_extra (im, size, GNUNET_MESSAGE_TYPE_TRANSPORT_RECV); | 4887 | env = GNUNET_MQ_msg_extra (im, size, GNUNET_MESSAGE_TYPE_TRANSPORT_RECV); |
4824 | im->peer = cmc->im.sender; | 4888 | im->peer = cmc->im.sender; |
4825 | memcpy (&im[1], mh, size); | 4889 | memcpy (&im[1], mh, size); |
4826 | GNUNET_MQ_send (tc->mq, env); | 4890 | GNUNET_MQ_send (tc->mq, env); |
4827 | } | 4891 | } |
4828 | vl->core_recv_window--; | 4892 | vl->core_recv_window--; |
4893 | if (GNUNET_NO == have_core) | ||
4894 | GNUNET_log (GNUNET_ERROR_TYPE_WARNING, | ||
4895 | "Dropped message to CORE: no CORE client connected!\n"); | ||
4896 | else | ||
4897 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
4898 | "Delivered message from %s of type %u to CORE\n", | ||
4899 | GNUNET_i2s (&cmc->im.sender), | ||
4900 | ntohs (mh->type)); | ||
4829 | if (vl->core_recv_window > 0) | 4901 | if (vl->core_recv_window > 0) |
4830 | { | 4902 | { |
4831 | finish_cmc_handling (cmc); | 4903 | finish_cmc_handling (cmc); |
@@ -4902,6 +4974,10 @@ transmit_cummulative_ack_cb (void *cls) | |||
4902 | struct TransportCummulativeAckPayloadP *ap; | 4974 | struct TransportCummulativeAckPayloadP *ap; |
4903 | 4975 | ||
4904 | ac->task = NULL; | 4976 | ac->task = NULL; |
4977 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
4978 | "Sending ACK with %u components to %s\n", | ||
4979 | ac->ack_counter, | ||
4980 | GNUNET_i2s (&ac->target)); | ||
4905 | GNUNET_assert (0 < ac->ack_counter); | 4981 | GNUNET_assert (0 < ac->ack_counter); |
4906 | ack = GNUNET_malloc (sizeof (*ack) + | 4982 | ack = GNUNET_malloc (sizeof (*ack) + |
4907 | ac->ack_counter * | 4983 | ac->ack_counter * |
@@ -4941,6 +5017,10 @@ cummulative_ack (const struct GNUNET_PeerIdentity *pid, | |||
4941 | { | 5017 | { |
4942 | struct AcknowledgementCummulator *ac; | 5018 | struct AcknowledgementCummulator *ac; |
4943 | 5019 | ||
5020 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
5021 | "Scheduling ACK %s for transmission to %s\n", | ||
5022 | GNUNET_sh2s (&ack_uuid->value), | ||
5023 | GNUNET_i2s (pid)); | ||
4944 | ac = GNUNET_CONTAINER_multipeermap_get (ack_cummulators, pid); | 5024 | ac = GNUNET_CONTAINER_multipeermap_get (ack_cummulators, pid); |
4945 | if (NULL == ac) | 5025 | if (NULL == ac) |
4946 | { | 5026 | { |
@@ -5088,10 +5168,22 @@ handle_fragment_box (void *cls, const struct TransportFragmentBoxMessage *fb) | |||
5088 | target = (char *) &rc[1]; | 5168 | target = (char *) &rc[1]; |
5089 | rc->bitfield = (uint8_t *) (target + rc->msg_size); | 5169 | rc->bitfield = (uint8_t *) (target + rc->msg_size); |
5090 | rc->msg_missing = rc->msg_size; | 5170 | rc->msg_missing = rc->msg_size; |
5171 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
5172 | "Received fragment at offset %u/%u from %s for NEW message %u\n", | ||
5173 | ntohs (fb->frag_off), | ||
5174 | msize, | ||
5175 | GNUNET_i2s (&cmc->im.sender), | ||
5176 | (unsigned int) fb->msg_uuid.uuid); | ||
5091 | } | 5177 | } |
5092 | else | 5178 | else |
5093 | { | 5179 | { |
5094 | target = (char *) &rc[1]; | 5180 | target = (char *) &rc[1]; |
5181 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
5182 | "Received fragment at offset %u/%u from %s for message %u\n", | ||
5183 | ntohs (fb->frag_off), | ||
5184 | msize, | ||
5185 | GNUNET_i2s (&cmc->im.sender), | ||
5186 | (unsigned int) fb->msg_uuid.uuid); | ||
5095 | } | 5187 | } |
5096 | if (msize != rc->msg_size) | 5188 | if (msize != rc->msg_size) |
5097 | { | 5189 | { |
@@ -5145,6 +5237,10 @@ handle_fragment_box (void *cls, const struct TransportFragmentBoxMessage *fb) | |||
5145 | return; | 5237 | return; |
5146 | } | 5238 | } |
5147 | /* successful reassembly */ | 5239 | /* successful reassembly */ |
5240 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
5241 | "Fragment reassembly complete for message %u\n", | ||
5242 | (unsigned int) fb->msg_uuid.uuid); | ||
5243 | |||
5148 | demultiplex_with_cmc (cmc, msg); | 5244 | demultiplex_with_cmc (cmc, msg); |
5149 | /* FIXME-OPTIMIZE: really free here? Might be bad if fragments are still | 5245 | /* FIXME-OPTIMIZE: really free here? Might be bad if fragments are still |
5150 | en-route and we forget that we finished this reassembly immediately! | 5246 | en-route and we forget that we finished this reassembly immediately! |
@@ -5185,9 +5281,24 @@ handle_reliability_box (void *cls, | |||
5185 | struct CommunicatorMessageContext *cmc = cls; | 5281 | struct CommunicatorMessageContext *cmc = cls; |
5186 | const struct GNUNET_MessageHeader *inbox = | 5282 | const struct GNUNET_MessageHeader *inbox = |
5187 | (const struct GNUNET_MessageHeader *) &rb[1]; | 5283 | (const struct GNUNET_MessageHeader *) &rb[1]; |
5284 | struct GNUNET_TIME_Relative rtt; | ||
5188 | 5285 | ||
5189 | // FIXME: call cummulative_ack(), have ack_countdown influence max_delay! | 5286 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, |
5190 | (void) (0 == ntohl (rb->ack_countdown)); | 5287 | "Received reliability box from %s with UUID %s of type %u\n", |
5288 | GNUNET_i2s (&cmc->im.sender), | ||
5289 | GNUNET_sh2s (&rb->ack_uuid.value), | ||
5290 | (unsigned int) ntohs (inbox->type)); | ||
5291 | rtt = GNUNET_TIME_UNIT_SECONDS; /* FIXME: should base this on "RTT", but we | ||
5292 | do not really have an RTT for the | ||
5293 | *incoming* queue (should we have | ||
5294 | the sender add it to the rb message?) */ | ||
5295 | cummulative_ack ( | ||
5296 | &cmc->im.sender, | ||
5297 | &rb->ack_uuid, | ||
5298 | (0 == ntohl (rb->ack_countdown)) | ||
5299 | ? GNUNET_TIME_UNIT_ZERO_ABS | ||
5300 | : GNUNET_TIME_relative_to_absolute ( | ||
5301 | GNUNET_TIME_relative_divide (rtt, 8 /* FIXME: magic constant */))); | ||
5191 | /* continue with inner message */ | 5302 | /* continue with inner message */ |
5192 | demultiplex_with_cmc (cmc, inbox); | 5303 | demultiplex_with_cmc (cmc, inbox); |
5193 | } | 5304 | } |
@@ -5382,6 +5493,10 @@ handle_reliability_ack (void *cls, | |||
5382 | GNUNET_CONTAINER_multishortmap_get (pending_acks, &ack[i].ack_uuid.value); | 5493 | GNUNET_CONTAINER_multishortmap_get (pending_acks, &ack[i].ack_uuid.value); |
5383 | if (NULL == pa) | 5494 | if (NULL == pa) |
5384 | { | 5495 | { |
5496 | GNUNET_log (GNUNET_ERROR_TYPE_INFO, | ||
5497 | "Received ACK from %s with UUID %s which is unknown to us!\n", | ||
5498 | GNUNET_i2s (&cmc->im.sender), | ||
5499 | GNUNET_sh2s (&ack[i].ack_uuid.value)); | ||
5385 | GNUNET_STATISTICS_update ( | 5500 | GNUNET_STATISTICS_update ( |
5386 | GST_stats, | 5501 | GST_stats, |
5387 | "# FRAGMENT_ACKS dropped, no matching pending message", | 5502 | "# FRAGMENT_ACKS dropped, no matching pending message", |
@@ -5389,6 +5504,10 @@ handle_reliability_ack (void *cls, | |||
5389 | GNUNET_NO); | 5504 | GNUNET_NO); |
5390 | continue; | 5505 | continue; |
5391 | } | 5506 | } |
5507 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
5508 | "Received ACK from %s with UUID %s\n", | ||
5509 | GNUNET_i2s (&cmc->im.sender), | ||
5510 | GNUNET_sh2s (&ack[i].ack_uuid.value)); | ||
5392 | handle_acknowledged (pa, GNUNET_TIME_relative_ntoh (ack[i].ack_delay)); | 5511 | handle_acknowledged (pa, GNUNET_TIME_relative_ntoh (ack[i].ack_delay)); |
5393 | } | 5512 | } |
5394 | 5513 | ||
@@ -5480,6 +5599,11 @@ forward_backchannel_payload (struct Backtalker *b, | |||
5480 | return; | 5599 | return; |
5481 | } | 5600 | } |
5482 | /* Finally, deliver backchannel message to communicator */ | 5601 | /* Finally, deliver backchannel message to communicator */ |
5602 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
5603 | "Delivering backchannel message from %s of type %u to %s\n", | ||
5604 | GNUNET_i2s (&b->pid), | ||
5605 | ntohs (mh->type), | ||
5606 | target_communicator); | ||
5483 | env = GNUNET_MQ_msg_extra ( | 5607 | env = GNUNET_MQ_msg_extra ( |
5484 | cbi, | 5608 | cbi, |
5485 | msg_size, | 5609 | msg_size, |
@@ -5605,6 +5729,9 @@ backtalker_monotime_cb (void *cls, | |||
5605 | mt = GNUNET_TIME_absolute_ntoh (*mtbe); | 5729 | mt = GNUNET_TIME_absolute_ntoh (*mtbe); |
5606 | if (mt.abs_value_us > b->monotonic_time.abs_value_us) | 5730 | if (mt.abs_value_us > b->monotonic_time.abs_value_us) |
5607 | { | 5731 | { |
5732 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
5733 | "Backtalker message from %s dropped, monotime in the past\n", | ||
5734 | GNUNET_i2s (&b->pid)); | ||
5608 | GNUNET_STATISTICS_update ( | 5735 | GNUNET_STATISTICS_update ( |
5609 | GST_stats, | 5736 | GST_stats, |
5610 | "# Backchannel messages dropped: monotonic time not increasing", | 5737 | "# Backchannel messages dropped: monotonic time not increasing", |
@@ -5699,6 +5826,9 @@ handle_backchannel_encapsulation ( | |||
5699 | if (0 != GNUNET_memcmp (&be->target, &GST_my_identity)) | 5826 | if (0 != GNUNET_memcmp (&be->target, &GST_my_identity)) |
5700 | { | 5827 | { |
5701 | /* not for me, try to route to target */ | 5828 | /* not for me, try to route to target */ |
5829 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
5830 | "Forwarding backtalk to %s\n", | ||
5831 | GNUNET_i2s (&be->target)); | ||
5702 | route_message (&be->target, | 5832 | route_message (&be->target, |
5703 | GNUNET_copy_message (&be->header), | 5833 | GNUNET_copy_message (&be->header), |
5704 | RMO_DV_ALLOWED); | 5834 | RMO_DV_ALLOWED); |
@@ -5729,6 +5859,9 @@ handle_backchannel_encapsulation ( | |||
5729 | bc_decrypt (&key, &body, &hdr[sizeof (ppay)], hdr_len - sizeof (ppay)); | 5859 | bc_decrypt (&key, &body, &hdr[sizeof (ppay)], hdr_len - sizeof (ppay)); |
5730 | bc_key_clean (&key); | 5860 | bc_key_clean (&key); |
5731 | monotime = GNUNET_TIME_absolute_ntoh (ppay.monotonic_time); | 5861 | monotime = GNUNET_TIME_absolute_ntoh (ppay.monotonic_time); |
5862 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
5863 | "Decrypted backtalk from %s\n", | ||
5864 | GNUNET_i2s (&ppay.sender)); | ||
5732 | b = GNUNET_CONTAINER_multipeermap_get (backtalkers, &ppay.sender); | 5865 | b = GNUNET_CONTAINER_multipeermap_get (backtalkers, &ppay.sender); |
5733 | if ((NULL != b) && (monotime.abs_value_us < b->monotonic_time.abs_value_us)) | 5866 | if ((NULL != b) && (monotime.abs_value_us < b->monotonic_time.abs_value_us)) |
5734 | { | 5867 | { |
@@ -5854,8 +5987,14 @@ activate_core_visible_dv_path (struct DistanceVectorHop *hop) | |||
5854 | { | 5987 | { |
5855 | /* Link was already up, remember dv is also now available and we are done */ | 5988 | /* Link was already up, remember dv is also now available and we are done */ |
5856 | vl->dv = dv; | 5989 | vl->dv = dv; |
5990 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
5991 | "Virtual link to %s could now also use DV!\n", | ||
5992 | GNUNET_i2s (&dv->target)); | ||
5857 | return; | 5993 | return; |
5858 | } | 5994 | } |
5995 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
5996 | "Creating new virtual link to %s using DV!\n", | ||
5997 | GNUNET_i2s (&dv->target)); | ||
5859 | vl = GNUNET_new (struct VirtualLink); | 5998 | vl = GNUNET_new (struct VirtualLink); |
5860 | vl->target = dv->target; | 5999 | vl->target = dv->target; |
5861 | vl->dv = dv; | 6000 | vl->dv = dv; |
@@ -5874,6 +6013,9 @@ activate_core_visible_dv_path (struct DistanceVectorHop *hop) | |||
5874 | } | 6013 | } |
5875 | 6014 | ||
5876 | 6015 | ||
6016 | // FIXME: add logging logic from here! | ||
6017 | |||
6018 | |||
5877 | /** | 6019 | /** |
5878 | * We have learned a @a path through the network to some other peer, add it to | 6020 | * We have learned a @a path through the network to some other peer, add it to |
5879 | * our DV data structure (returning #GNUNET_YES on success). | 6021 | * our DV data structure (returning #GNUNET_YES on success). |
@@ -7114,8 +7256,14 @@ handle_validation_response ( | |||
7114 | { | 7256 | { |
7115 | /* Link was already up, remember n is also now available and we are done */ | 7257 | /* Link was already up, remember n is also now available and we are done */ |
7116 | vl->n = n; | 7258 | vl->n = n; |
7259 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
7260 | "Virtual link to %s could now also direct neighbour!\n", | ||
7261 | GNUNET_i2s (&vs->pid)); | ||
7117 | return; | 7262 | return; |
7118 | } | 7263 | } |
7264 | GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, | ||
7265 | "Creating new virtual link to %s using direct neighbour!\n", | ||
7266 | GNUNET_i2s (&vs->pid)); | ||
7119 | vl = GNUNET_new (struct VirtualLink); | 7267 | vl = GNUNET_new (struct VirtualLink); |
7120 | vl->target = n->pid; | 7268 | vl->target = n->pid; |
7121 | vl->n = n; | 7269 | vl->n = n; |