#define LOG(kind,...) GNUNET_log_from (kind, "transport-api",__VA_ARGS__)
+/**
+ * If we could not send any payload to a peer for this amount of
+ * time, we print a warning.
+ */
+#define UNREADY_WARN_TIME GNUNET_TIME_UNIT_MINUTES
+
/**
* How large to start with for the hashmap of neighbours.
*/
*/
void *notify_cls;
+ /**
+ * Time at which this request was originally scheduled.
+ */
+ struct GNUNET_TIME_Absolute request_start;
+
/**
* Timeout for this request, 0 for control messages.
*/
* Task to trigger request timeout if the request is stalled due to
* congestion.
*/
- struct GNUNET_SCHEDULER_Task * timeout_task;
+ struct GNUNET_SCHEDULER_Task *timeout_task;
/**
* How many bytes is our notify callback waiting for?
*/
struct GNUNET_CONTAINER_HeapNode *hn;
+ /**
+ * Last time when this peer received payload from us.
+ */
+ struct GNUNET_TIME_Absolute last_payload;
+
+ /**
+ * Task to trigger warnings if we do not get SEND_OK after a while.
+ */
+ struct GNUNET_SCHEDULER_Task *unready_warn_task;
+
/**
* Is this peer currently ready to receive a message?
*/
/**
* Task for calling the HelloUpdateCallback when we already have a HELLO
*/
- struct GNUNET_SCHEDULER_Task * notify_task;
+ struct GNUNET_SCHEDULER_Task *notify_task;
/**
* Closure for @e rec.
* Heap sorting peers with pending messages by the timestamps that
* specify when we could next send a message to the respective peer.
* Excludes control messages (which can always go out immediately).
- * Maps time stamps to 'struct Neighbour' entries.
+ * Maps time stamps to `struct Neighbour` entries.
*/
struct GNUNET_CONTAINER_Heap *ready_heap;
/**
* ID of the task trying to reconnect to the service.
*/
- struct GNUNET_SCHEDULER_Task * reconnect_task;
+ struct GNUNET_SCHEDULER_Task *reconnect_task;
/**
* ID of the task trying to trigger transmission for a peer while
* maintaining bandwidth quotas. In use if there are no control
- * messages and the smallest entry in the 'ready_heap' has a time
+ * messages and the smallest entry in the @e ready_heap has a time
* stamp in the future.
*/
- struct GNUNET_SCHEDULER_Task * quota_task;
+ struct GNUNET_SCHEDULER_Task *quota_task;
/**
* Delay until we try to reconnect.
disconnect_and_schedule_reconnect (struct GNUNET_TRANSPORT_Handle *h);
+/**
+ * A neighbour has not gotten a SEND_OK in a while. Print a warning.
+ *
+ * @param cls the `struct Neighbour`
+ * @param tc scheduler context
+ */
+static void
+do_warn_unready (void *cls,
+ const struct GNUNET_SCHEDULER_TaskContext *tc)
+{
+ struct Neighbour *n = cls;
+ struct GNUNET_TIME_Relative delay;
+
+ delay = GNUNET_TIME_absolute_get_duration (n->last_payload);
+ GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
+ "Lacking SEND_OK, no payload could be send to %s for %s\n",
+ GNUNET_i2s (&n->id),
+ GNUNET_STRINGS_relative_time_to_string (delay,
+ GNUNET_YES));
+ n->unready_warn_task
+ = GNUNET_SCHEDULER_add_delayed (UNREADY_WARN_TIME,
+ &do_warn_unready,
+ n);
+}
+
+
/**
* Get the neighbour list entry for the given peer
*
delay = GNUNET_BANDWIDTH_tracker_get_delay (&n->out_tracker,
n->th->notify_size + n->traffic_overhead);
LOG (GNUNET_ERROR_TYPE_DEBUG,
- "New outbound delay %llu us\n",
+ "New outbound delay %s us\n",
GNUNET_STRINGS_relative_time_to_string (delay,
GNUNET_NO));
GNUNET_CONTAINER_heap_update_cost (n->h->ready_heap,
struct Neighbour *n;
LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Creating entry for neighbour `%4s'.\n",
+ "Creating entry for neighbour `%s'.\n",
GNUNET_i2s (pid));
n = GNUNET_new (struct Neighbour);
n->id = *pid;
struct GNUNET_TRANSPORT_Handle *handle = cls;
struct Neighbour *n = value;
+ LOG (GNUNET_ERROR_TYPE_DEBUG,
+ "Dropping entry for neighbour `%s'.\n",
+ GNUNET_i2s (key));
GNUNET_BANDWIDTH_tracker_notification_stop (&n->out_tracker);
if (NULL != handle->nd_cb)
handle->nd_cb (handle->cls,
&n->id);
+ if (NULL != n->unready_warn_task)
+ {
+ GNUNET_SCHEDULER_cancel (n->unready_warn_task);
+ n->unready_warn_task = NULL;
+ }
GNUNET_assert (NULL == n->th);
GNUNET_assert (NULL == n->hn);
GNUNET_assert (GNUNET_YES ==
break;
}
LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Receiving (my own) HELLO message (%u bytes), I am `%4s'.\n",
+ "Receiving (my own) HELLO message (%u bytes), I am `%s'.\n",
(unsigned int) size,
GNUNET_i2s (&me));
GNUNET_free_non_null (h->my_hello);
break;
}
LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Receiving CONNECT message for `%4s'.\n",
+ "Receiving CONNECT message for `%s'.\n",
GNUNET_i2s (&cim->id));
n = neighbour_find (h, &cim->id);
if (NULL != n)
n = neighbour_add (h,
&cim->id);
LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Receiving CONNECT message for `%4s' with quota %u\n",
+ "Receiving CONNECT message for `%s' with quota %u\n",
GNUNET_i2s (&cim->id),
ntohl (cim->quota_out.value__));
GNUNET_BANDWIDTH_tracker_update_quota (&n->out_tracker,
dim = (const struct DisconnectInfoMessage *) msg;
GNUNET_break (ntohl (dim->reserved) == 0);
LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Receiving DISCONNECT message for `%4s'.\n",
+ "Receiving DISCONNECT message for `%s'.\n",
GNUNET_i2s (&dim->peer));
n = neighbour_find (h, &dim->peer);
if (NULL == n)
"Receiving SEND_OK message, transmission %s.\n",
ntohl (okm->success) == GNUNET_OK ? "succeeded" : "failed");
- n = neighbour_find (h, &okm->peer);
+ n = neighbour_find (h,
+ &okm->peer);
if (NULL == n)
+ {
+ /* we should never get a 'SEND_OK' for a peer that we are not
+ connected to */
+ GNUNET_break (0);
break;
-
+ }
if (bytes_physical >= bytes_msg)
{
LOG (GNUNET_ERROR_TYPE_DEBUG,
}
GNUNET_break (GNUNET_NO == n->is_ready);
n->is_ready = GNUNET_YES;
+ if (NULL != n->unready_warn_task)
+ {
+ GNUNET_SCHEDULER_cancel (n->unready_warn_task);
+ n->unready_warn_task = NULL;
+ }
if ((NULL != n->th) && (NULL == n->hn))
{
GNUNET_assert (NULL != n->th->timeout_task);
break;
}
LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Received message of type %u from `%4s'.\n",
+ "Received message of type %u from `%s'.\n",
ntohs (imm->type), GNUNET_i2s (&im->peer));
n = neighbour_find (h, &im->peer);
if (NULL == n)
if (NULL == n)
break;
LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Receiving SET_QUOTA message for `%4s' with quota %u\n",
+ "Receiving SET_QUOTA message for `%s' with quota %u\n",
GNUNET_i2s (&qm->peer),
ntohl (qm->quota.value__));
GNUNET_BANDWIDTH_tracker_update_quota (&n->out_tracker,
{
struct GNUNET_TRANSPORT_TransmitHandle *th = cls;
struct Neighbour *n = th->neighbour;
+ struct GNUNET_TIME_Relative delay;
n->th->timeout_task = NULL;
+ delay = GNUNET_TIME_absolute_get_duration (th->request_start);
+ LOG (GNUNET_ERROR_TYPE_WARNING,
+ "Discarding %u bytes of payload message after %s delay due to congestion\n",
+ th->notify_size,
+ GNUNET_STRINGS_relative_time_to_string (delay,
+ GNUNET_YES));
GNUNET_assert (th == n->th);
GNUNET_assert (NULL == n->hn);
n->th = NULL;
{
struct GNUNET_TRANSPORT_Handle *h = cls;
struct GNUNET_TRANSPORT_TransmitHandle *th;
+ struct GNUNET_TIME_Relative delay;
struct Neighbour *n;
char *cbuf;
struct OutboundMessage obm;
GNUNET_CONTAINER_DLL_remove (h->control_head,
h->control_tail,
th);
- nret = th->notify (th->notify_cls, size, &cbuf[ret]);
- LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Added %u bytes of control message at %u\n",
- nret,
- ret);
+ nret = th->notify (th->notify_cls,
+ size,
+ &cbuf[ret]);
+ delay = GNUNET_TIME_absolute_get_duration (th->request_start);
+ if (delay.rel_value_us > 1000 * 1000)
+ LOG (GNUNET_ERROR_TYPE_WARNING,
+ "Added %u bytes of control message at %u after %s delay\n",
+ nret,
+ ret,
+ GNUNET_STRINGS_relative_time_to_string (delay,
+ GNUNET_YES));
+ else
+ LOG (GNUNET_ERROR_TYPE_DEBUG,
+ "Added %u bytes of control message at %u after %s delay\n",
+ nret,
+ ret,
+ GNUNET_STRINGS_relative_time_to_string (delay,
+ GNUNET_YES));
GNUNET_free (th);
ret += nret;
size -= nret;
}
/* then, if possible and no control messages pending, send data messages */
- while ((NULL == h->control_head) &&
- (NULL != (n = GNUNET_CONTAINER_heap_peek (h->ready_heap))))
+ while ( (NULL == h->control_head) &&
+ (NULL != (n = GNUNET_CONTAINER_heap_peek (h->ready_heap))) )
{
if (GNUNET_YES != n->is_ready)
{
GNUNET_assert (n == GNUNET_CONTAINER_heap_remove_root (h->ready_heap));
n->hn = NULL;
GNUNET_assert (NULL == n->th->timeout_task);
- n->th->timeout_task =
- GNUNET_SCHEDULER_add_delayed (GNUNET_TIME_absolute_get_remaining
+ n->th->timeout_task
+ = GNUNET_SCHEDULER_add_delayed (GNUNET_TIME_absolute_get_remaining
(n->th->timeout),
&timeout_request_due_to_congestion,
n->th);
GNUNET_assert (n == GNUNET_CONTAINER_heap_remove_root (h->ready_heap));
n->hn = NULL;
n->th = NULL;
- n->is_ready = GNUNET_NO;
GNUNET_assert (size >= sizeof (struct OutboundMessage));
- mret =
- th->notify (th->notify_cls, size - sizeof (struct OutboundMessage),
- &cbuf[ret + sizeof (struct OutboundMessage)]);
+ mret = th->notify (th->notify_cls,
+ size - sizeof (struct OutboundMessage),
+ &cbuf[ret + sizeof (struct OutboundMessage)]);
GNUNET_assert (mret <= size - sizeof (struct OutboundMessage));
- if (mret != 0)
+ if (0 == mret)
{
- GNUNET_assert (mret + sizeof (struct OutboundMessage) <
- GNUNET_SERVER_MAX_MESSAGE_SIZE);
- obm.header.type = htons (GNUNET_MESSAGE_TYPE_TRANSPORT_SEND);
- obm.header.size = htons (mret + sizeof (struct OutboundMessage));
- obm.reserved = htonl (0);
- obm.timeout =
- GNUNET_TIME_relative_hton (GNUNET_TIME_absolute_get_remaining
- (th->timeout));
- obm.peer = n->id;
- memcpy (&cbuf[ret], &obm, sizeof (struct OutboundMessage));
- ret += (mret + sizeof (struct OutboundMessage));
- size -= (mret + sizeof (struct OutboundMessage));
- GNUNET_BANDWIDTH_tracker_consume (&n->out_tracker, mret);
+ GNUNET_free (th);
+ continue;
}
+ if (NULL != n->unready_warn_task)
+ n->unready_warn_task
+ = GNUNET_SCHEDULER_add_delayed (UNREADY_WARN_TIME,
+ &do_warn_unready,
+ n);
+ n->last_payload = GNUNET_TIME_absolute_get ();
+ n->is_ready = GNUNET_NO;
+ GNUNET_assert (mret + sizeof (struct OutboundMessage) <
+ GNUNET_SERVER_MAX_MESSAGE_SIZE);
+ obm.header.type = htons (GNUNET_MESSAGE_TYPE_TRANSPORT_SEND);
+ obm.header.size = htons (mret + sizeof (struct OutboundMessage));
+ obm.reserved = htonl (0);
+ obm.timeout =
+ GNUNET_TIME_relative_hton (GNUNET_TIME_absolute_get_remaining
+ (th->timeout));
+ obm.peer = n->id;
+ memcpy (&cbuf[ret],
+ &obm,
+ sizeof (struct OutboundMessage));
+ ret += (mret + sizeof (struct OutboundMessage));
+ size -= (mret + sizeof (struct OutboundMessage));
+ GNUNET_BANDWIDTH_tracker_consume (&n->out_tracker,
+ mret);
+ delay = GNUNET_TIME_absolute_get_duration (th->request_start);
+ if (delay.rel_value_us > 1000 * 1000)
+ LOG (GNUNET_ERROR_TYPE_WARNING,
+ "Added %u bytes of payload message at %u after %s delay\n",
+ mret,
+ ret,
+ GNUNET_STRINGS_relative_time_to_string (delay,
+ GNUNET_YES));
+ else
+ LOG (GNUNET_ERROR_TYPE_DEBUG,
+ "Added %u bytes of payload message at %u after %s delay\n",
+ mret,
+ ret,
+ GNUNET_STRINGS_relative_time_to_string (delay,
+ GNUNET_YES));
GNUNET_free (th);
+ break;
}
/* if there are more pending messages, try to schedule those */
schedule_transmission (h);
h->quota_task = NULL;
GNUNET_assert (NULL != h->client);
/* destroy all requests that have timed out */
- while ((NULL != (n = GNUNET_CONTAINER_heap_peek (h->ready_heap))) &&
- (0 == GNUNET_TIME_absolute_get_remaining (n->th->timeout).rel_value_us))
+ while ( (NULL != (n = GNUNET_CONTAINER_heap_peek (h->ready_heap))) &&
+ (0 == GNUNET_TIME_absolute_get_remaining (n->th->timeout).rel_value_us) )
{
/* notify client that the request could not be satisfied within
* the given time constraints */
LOG (GNUNET_ERROR_TYPE_DEBUG,
"Signalling timeout for transmission to peer %s due to congestion\n",
GNUNET_i2s (&n->id));
- GNUNET_assert (0 == th->notify (th->notify_cls, 0, NULL));
+ GNUNET_assert (0 == th->notify (th->notify_cls,
+ 0,
+ NULL));
GNUNET_free (th);
}
if (NULL != h->cth)
}
LOG (GNUNET_ERROR_TYPE_DEBUG,
"Calling notify_transmit_ready\n");
- h->cth =
- GNUNET_CLIENT_notify_transmit_ready (h->client, size,
+ h->cth
+ = GNUNET_CLIENT_notify_transmit_ready (h->client,
+ size,
GNUNET_TIME_UNIT_FOREVER_REL,
- GNUNET_NO, &transport_notify_ready,
+ GNUNET_NO,
+ &transport_notify_ready,
h);
GNUNET_assert (NULL != h->cth);
}
struct Neighbour *n;
GNUNET_assert (NULL != h->client);
- if (h->quota_task != NULL)
+ if (NULL != h->quota_task)
{
GNUNET_SCHEDULER_cancel (h->quota_task);
h->quota_task = NULL;
return; /* no work to be done */
LOG (GNUNET_ERROR_TYPE_DEBUG,
"Scheduling next transmission to service in %s\n",
- GNUNET_STRINGS_relative_time_to_string (delay, GNUNET_YES));
+ GNUNET_STRINGS_relative_time_to_string (delay,
+ GNUNET_YES));
h->quota_task =
- GNUNET_SCHEDULER_add_delayed (delay, &schedule_transmission_task, h);
+ GNUNET_SCHEDULER_add_delayed (delay,
+ &schedule_transmission_task,
+ h);
}
th->notify = notify;
th->notify_cls = notify_cls;
th->notify_size = size;
- GNUNET_CONTAINER_DLL_insert_tail (h->control_head, h->control_tail, th);
+ th->request_start = GNUNET_TIME_absolute_get ();
+ GNUNET_CONTAINER_DLL_insert_tail (h->control_head,
+ h->control_tail,
+ th);
schedule_transmission (h);
return th;
}
* @return number of bytes copied to @a buf
*/
static size_t
-send_start (void *cls, size_t size, void *buf)
+send_start (void *cls,
+ size_t size,
+ void *buf)
{
struct GNUNET_TRANSPORT_Handle *h = cls;
struct StartMessage s;
options = 0;
if (h->check_self)
options |= 1;
- if (h->rec != NULL)
+ if (NULL != h->rec)
options |= 2;
s.options = htonl (options);
s.self = h->self;
if (NULL == buf)
{
LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Discarding `%s' request to `%4s' due to error in transport service connection.\n",
+ "Discarding `%s' request to `%s' due to error in transport service connection.\n",
"REQUEST_CONNECT",
GNUNET_i2s (&tch->pid));
if (NULL != tch->cb)
return 0;
}
LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Transmitting `%s' request with respect to `%4s'.\n",
+ "Transmitting `%s' request with respect to `%s'.\n",
"REQUEST_CONNECT",
GNUNET_i2s (&tch->pid));
GNUNET_assert (size >= sizeof (struct TransportRequestConnectMessage));
if (NULL == buf)
{
LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Discarding `%s' request to `%4s' due to error in transport service connection.\n",
+ "Discarding `%s' request to `%s' due to error in transport service connection.\n",
"REQUEST_DISCONNECT",
GNUNET_i2s (&tdh->pid));
if (NULL != tdh->cb)
return 0;
}
LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Transmitting `%s' request with respect to `%4s'.\n",
+ "Transmitting `%s' request with respect to `%s'.\n",
"REQUEST_DISCONNECT",
GNUNET_i2s (&tdh->pid));
GNUNET_assert (size >= sizeof (struct TransportRequestDisconnectMessage));
msg = GNUNET_malloc (size);
memcpy (msg, hello, size);
LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Offering `%s' message of `%4s' to transport for validation.\n", "HELLO",
+ "Offering HELLO message of `%s' to transport for validation.\n",
GNUNET_i2s (&peer));
ohh = GNUNET_new (struct GNUNET_TRANSPORT_OfferHelloHandle);
/**
* Cancel the request to transport to offer the HELLO message
*
- * @param ohh the GNUNET_TRANSPORT_OfferHelloHandle to cancel
+ * @param ohh the handle for the operation to cancel
*/
void
GNUNET_TRANSPORT_offer_hello_cancel (struct GNUNET_TRANSPORT_OfferHelloHandle *ohh)
hwl->rec = rec;
hwl->rec_cls = rec_cls;
hwl->handle = handle;
- GNUNET_CONTAINER_DLL_insert (handle->hwl_head, handle->hwl_tail, hwl);
+ GNUNET_CONTAINER_DLL_insert (handle->hwl_head,
+ handle->hwl_tail,
+ hwl);
if (NULL != handle->my_hello)
hwl->notify_task = GNUNET_SCHEDULER_add_now (&call_hello_update_cb_async,
hwl);
LOG (GNUNET_ERROR_TYPE_DEBUG,
"Transport disconnect called!\n");
/* this disconnects all neighbours... */
- if (handle->reconnect_task == NULL)
+ if (NULL == handle->reconnect_task)
disconnect_and_schedule_reconnect (handle);
/* and now we stop trying to connect again... */
- if (handle->reconnect_task != NULL)
+ if (NULL != handle->reconnect_task)
{
GNUNET_SCHEDULER_cancel (handle->reconnect_task);
handle->reconnect_task = NULL;
}
GNUNET_CONTAINER_multipeermap_destroy (handle->neighbours);
handle->neighbours = NULL;
- if (handle->quota_task != NULL)
+ if (NULL != handle->quota_task)
{
GNUNET_SCHEDULER_cancel (handle->quota_task);
handle->quota_task = NULL;
th->neighbour = n;
th->notify = notify;
th->notify_cls = notify_cls;
+ th->request_start = GNUNET_TIME_absolute_get ();
th->timeout = GNUNET_TIME_relative_to_absolute (timeout);
th->notify_size = size;
n->th = th;
n->traffic_overhead = 0;
if (delay.rel_value_us > timeout.rel_value_us)
delay.rel_value_us = 0; /* notify immediately (with failure) */
- LOG (GNUNET_ERROR_TYPE_DEBUG,
- "Bandwidth tracker allows next transmission to peer %s in %s\n",
- GNUNET_i2s (target),
- GNUNET_STRINGS_relative_time_to_string (delay,
- GNUNET_YES));
+ if (delay.rel_value_us > GNUNET_TIME_UNIT_SECONDS.rel_value_us)
+ LOG (GNUNET_ERROR_TYPE_WARNING,
+ "At bandwidth %u byte/s next transmission to %s in %s\n",
+ (unsigned int) n->out_tracker.available_bytes_per_s__,
+ GNUNET_i2s (target),
+ GNUNET_STRINGS_relative_time_to_string (delay,
+ GNUNET_YES));
+ else
+ LOG (GNUNET_ERROR_TYPE_DEBUG,
+ "At bandwidth %u byte/s next transmission to %s in %s\n",
+ (unsigned int) n->out_tracker.available_bytes_per_s__,
+ GNUNET_i2s (target),
+ GNUNET_STRINGS_relative_time_to_string (delay,
+ GNUNET_YES));
n->hn = GNUNET_CONTAINER_heap_insert (handle->ready_heap,
n,
delay.rel_value_us);