Commit 80973c09 authored by Philip Withnall's avatar Philip Withnall

conncheck: add more debug information

Add a more debug details, specifically in some places, it is interesting
to have the src and dst IP addresses of the pairs being checked, and
also to make the difference between log related to different stream ids.
Reviewed-by: default avatarPhilip Withnall <philip@tecnocode.co.uk>
Differential Revision: https://phabricator.freedesktop.org/D803
parent 41ab61de
...@@ -290,7 +290,13 @@ static gboolean priv_conn_check_tick_stream (NiceStream *stream, NiceAgent *agen ...@@ -290,7 +290,13 @@ static gboolean priv_conn_check_tick_stream (NiceStream *stream, NiceAgent *agen
case STUN_USAGE_TIMER_RETURN_TIMEOUT: case STUN_USAGE_TIMER_RETURN_TIMEOUT:
{ {
/* case: error, abort processing */ /* case: error, abort processing */
gchar tmpbuf1[INET6_ADDRSTRLEN], tmpbuf2[INET6_ADDRSTRLEN];
nice_address_to_string (&p->local->addr, tmpbuf1);
nice_address_to_string (&p->remote->addr, tmpbuf2);
nice_debug ("Agent %p : Retransmissions failed, giving up on connectivity check %p", agent, p); nice_debug ("Agent %p : Retransmissions failed, giving up on connectivity check %p", agent, p);
nice_debug ("Agent %p : Failed pair is [%s]:%u --> [%s]:%u", agent,
tmpbuf1, nice_address_get_port (&p->local->addr),
tmpbuf2, nice_address_get_port (&p->remote->addr));
candidate_check_pair_fail (stream, agent, p); candidate_check_pair_fail (stream, agent, p);
break; break;
...@@ -299,8 +305,9 @@ static gboolean priv_conn_check_tick_stream (NiceStream *stream, NiceAgent *agen ...@@ -299,8 +305,9 @@ static gboolean priv_conn_check_tick_stream (NiceStream *stream, NiceAgent *agen
{ {
/* case: not ready, so schedule a new timeout */ /* case: not ready, so schedule a new timeout */
unsigned int timeout = stun_timer_remainder (&p->timer); unsigned int timeout = stun_timer_remainder (&p->timer);
nice_debug ("Agent %p :STUN transaction retransmitted (timeout %dms).", nice_debug ("Agent %p :STUN transaction retransmitted on pair %p "
agent, timeout); "(timeout %dms, delay=%dms, retrans=%d).",
agent, p, timeout, p->timer.delay, p->timer.retransmissions);
agent_socket_send (p->sockptr, &p->remote->addr, agent_socket_send (p->sockptr, &p->remote->addr,
stun_message_length (&p->stun_message), stun_message_length (&p->stun_message),
...@@ -385,9 +392,9 @@ static gboolean priv_conn_check_tick_stream (NiceStream *stream, NiceAgent *agen ...@@ -385,9 +392,9 @@ static gboolean priv_conn_check_tick_stream (NiceStream *stream, NiceAgent *agen
{ {
static int tick_counter = 0; static int tick_counter = 0;
if (tick_counter++ % 50 == 0 || keep_timer_going != TRUE) if (tick_counter++ % 50 == 0 || keep_timer_going != TRUE)
nice_debug ("Agent %p : timer tick #%u: %u frozen, %u in-progress, " nice_debug ("Agent %p : stream %u: timer tick #%u: %u frozen, %u in-progress, "
"%u waiting, %u succeeded, %u discovered, %u nominated, " "%u waiting, %u succeeded, %u discovered, %u nominated, "
"%u waiting-for-nom.", agent, "%u waiting-for-nom.", agent, stream->id,
tick_counter, frozen, s_inprogress, waiting, s_succeeded, tick_counter, frozen, s_inprogress, waiting, s_succeeded,
s_discovered, s_nominated, s_waiting_for_nomination); s_discovered, s_nominated, s_waiting_for_nomination);
} }
...@@ -1399,6 +1406,15 @@ static void priv_add_new_check_pair (NiceAgent *agent, guint stream_id, NiceComp ...@@ -1399,6 +1406,15 @@ static void priv_add_new_check_pair (NiceAgent *agent, guint stream_id, NiceComp
pair->priority = agent_candidate_pair_priority (agent, local, remote); pair->priority = agent_candidate_pair_priority (agent, local, remote);
pair->state = initial_state; pair->state = initial_state;
nice_debug ("Agent %p : creating new pair %p state %d", agent, pair, initial_state); nice_debug ("Agent %p : creating new pair %p state %d", agent, pair, initial_state);
{
gchar tmpbuf1[INET6_ADDRSTRLEN];
gchar tmpbuf2[INET6_ADDRSTRLEN];
nice_address_to_string (&pair->local->addr, tmpbuf1);
nice_address_to_string (&pair->remote->addr, tmpbuf2);
nice_debug ("Agent %p : new pair %p : [%s]:%u --> [%s]:%u", agent, pair,
tmpbuf1, nice_address_get_port (&pair->local->addr),
tmpbuf2, nice_address_get_port (&pair->remote->addr));
}
pair->nominated = use_candidate; pair->nominated = use_candidate;
pair->controlling = agent->controlling_mode; pair->controlling = agent->controlling_mode;
...@@ -1436,8 +1452,9 @@ static void priv_conn_check_add_for_candidate_pair_matched (NiceAgent *agent, ...@@ -1436,8 +1452,9 @@ static void priv_conn_check_add_for_candidate_pair_matched (NiceAgent *agent,
guint stream_id, NiceComponent *component, NiceCandidate *local, guint stream_id, NiceComponent *component, NiceCandidate *local,
NiceCandidate *remote, NiceCheckState initial_state) NiceCandidate *remote, NiceCheckState initial_state)
{ {
nice_debug ("Agent %p, Adding check pair between %s and %s", agent, nice_debug ("Agent %p : Adding check pair between %s and %s for s%d/c%d",
local->foundation, remote->foundation); agent, local->foundation, remote->foundation,
stream_id, component->id);
priv_add_new_check_pair (agent, stream_id, component, local, remote, priv_add_new_check_pair (agent, stream_id, component, local, remote,
initial_state, FALSE); initial_state, FALSE);
if (component->state == NICE_COMPONENT_STATE_CONNECTED || if (component->state == NICE_COMPONENT_STATE_CONNECTED ||
...@@ -1811,6 +1828,9 @@ static unsigned int priv_compute_conncheck_timer (NiceAgent *agent, ...@@ -1811,6 +1828,9 @@ static unsigned int priv_compute_conncheck_timer (NiceAgent *agent,
rto = agent->timer_ta * waiting_and_in_progress; rto = agent->timer_ta * waiting_and_in_progress;
/* We assume non-reliable streams are RTP, so we use 100 as the max */ /* We assume non-reliable streams are RTP, so we use 100 as the max */
nice_debug ("Agent %p : timer set to %dms (waiting+in_progress=%d)",
agent, agent->reliable ? MAX (rto, 500) : MAX (rto, 100),
waiting_and_in_progress);
if (agent->reliable) if (agent->reliable)
return MAX (rto, 500); return MAX (rto, 500);
else else
...@@ -1863,13 +1883,15 @@ int conn_check_send (NiceAgent *agent, CandidateCheckPair *pair) ...@@ -1863,13 +1883,15 @@ int conn_check_send (NiceAgent *agent, CandidateCheckPair *pair)
} }
if (nice_debug_is_enabled ()) { if (nice_debug_is_enabled ()) {
gchar tmpbuf[INET6_ADDRSTRLEN]; gchar tmpbuf1[INET6_ADDRSTRLEN];
nice_address_to_string (&pair->remote->addr, tmpbuf); gchar tmpbuf2[INET6_ADDRSTRLEN];
nice_debug ("Agent %p : STUN-CC REQ to '%s:%u', socket=%u, " nice_address_to_string (&pair->local->addr, tmpbuf1);
nice_address_to_string (&pair->remote->addr, tmpbuf2);
nice_debug ("Agent %p : STUN-CC REQ [%s]:%u --> [%s]:%u, socket=%u, "
"pair=%s (c-id:%u), tie=%llu, username='%.*s' (%" G_GSIZE_FORMAT "), " "pair=%s (c-id:%u), tie=%llu, username='%.*s' (%" G_GSIZE_FORMAT "), "
"password='%.*s' (%" G_GSIZE_FORMAT "), priority=%u.", agent, "password='%.*s' (%" G_GSIZE_FORMAT "), priority=%u.", agent,
tmpbuf, tmpbuf1, nice_address_get_port (&pair->local->addr),
nice_address_get_port (&pair->remote->addr), tmpbuf2, nice_address_get_port (&pair->remote->addr),
pair->sockptr->fileno ? g_socket_get_fd(pair->sockptr->fileno) : -1, pair->sockptr->fileno ? g_socket_get_fd(pair->sockptr->fileno) : -1,
pair->foundation, pair->component_id, pair->foundation, pair->component_id,
(unsigned long long)agent->tie_breaker, (unsigned long long)agent->tie_breaker,
...@@ -2218,7 +2240,16 @@ static CandidateCheckPair *priv_add_peer_reflexive_pair (NiceAgent *agent, guint ...@@ -2218,7 +2240,16 @@ static CandidateCheckPair *priv_add_peer_reflexive_pair (NiceAgent *agent, guint
pair->remote = parent_pair->remote; pair->remote = parent_pair->remote;
pair->sockptr = local_cand->sockptr; pair->sockptr = local_cand->sockptr;
pair->state = NICE_CHECK_DISCOVERED; pair->state = NICE_CHECK_DISCOVERED;
nice_debug ("Agent %p : pair %p state DISCOVERED", agent, pair); nice_debug ("Agent %p : new pair %p state DISCOVERED", agent, pair);
{
gchar tmpbuf1[INET6_ADDRSTRLEN];
gchar tmpbuf2[INET6_ADDRSTRLEN];
nice_address_to_string (&pair->local->addr, tmpbuf1);
nice_address_to_string (&pair->remote->addr, tmpbuf2);
nice_debug ("Agent %p : new pair %p : [%s]:%u --> [%s]:%u", agent, pair,
tmpbuf1, nice_address_get_port (&pair->local->addr),
tmpbuf2, nice_address_get_port (&pair->remote->addr));
}
g_snprintf (pair->foundation, NICE_CANDIDATE_PAIR_MAX_FOUNDATION, "%s:%s", g_snprintf (pair->foundation, NICE_CANDIDATE_PAIR_MAX_FOUNDATION, "%s:%s",
local_cand->foundation, parent_pair->remote->foundation); local_cand->foundation, parent_pair->remote->foundation);
if (agent->controlling_mode == TRUE) if (agent->controlling_mode == TRUE)
......
...@@ -1368,12 +1368,17 @@ nice_udp_turn_socket_parse_recv (NiceSocket *sock, NiceSocket **from_sock, ...@@ -1368,12 +1368,17 @@ nice_udp_turn_socket_parse_recv (NiceSocket *sock, NiceSocket **from_sock,
} peer; } peer;
socklen_t peer_len = sizeof(peer); socklen_t peer_len = sizeof(peer);
NiceAddress to; NiceAddress to;
gchar tmpbuf[INET6_ADDRSTRLEN];
nice_debug ("got response for CreatePermission");
stun_message_find_xor_addr ( stun_message_find_xor_addr (
&current_create_permission_msg->message, &current_create_permission_msg->message,
STUN_ATTRIBUTE_XOR_PEER_ADDRESS, &peer.storage, &peer_len); STUN_ATTRIBUTE_XOR_PEER_ADDRESS, &peer.storage, &peer_len);
nice_address_set_from_sockaddr (&to, &peer.addr); nice_address_set_from_sockaddr (&to, &peer.addr);
nice_address_to_string (&to, tmpbuf);
nice_debug ("TURN: got response for CreatePermission "
"with XOR_PEER_ADDRESS=[%s]:%u : %s",
tmpbuf, nice_address_get_port (&to),
stun_message_get_class (&msg) == STUN_ERROR ? "unauthorized" : "ok");
/* unathorized => resend with realm and nonce */ /* unathorized => resend with realm and nonce */
if (stun_message_get_class (&msg) == STUN_ERROR) { if (stun_message_get_class (&msg) == STUN_ERROR) {
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment