Bug 1290365: added extensive logging for TURN TCP
MozReview-Commit-ID: 4LBZe4SoVOL
--- a/media/mtransport/third_party/nICEr/src/ice/ice_candidate.c
+++ b/media/mtransport/third_party/nICEr/src/ice/ice_candidate.c
@@ -792,21 +792,24 @@ static int nr_ice_start_relay_turn(nr_ic
cand->u.relayed.server->password,
&cand->stun_server_addr,
&cand->u.relayed.turn))
ABORT(r);
if(r=nr_socket_turn_set_ctx(cand->osock, cand->u.relayed.turn))
ABORT(r);
+ r_log(LOG_ICE,LOG_INFO,"ICE(%s)/CAND(%s): delay for nr_ice_start_relay_turn_timer_cb (%d)", cand->ctx->label, cand->label,cand->stream->ctx->stun_delay);
NR_ASYNC_TIMER_SET(cand->stream->ctx->stun_delay,nr_ice_start_relay_turn_timer_cb,cand,&cand->delay_timer);
cand->stream->ctx->stun_delay += cand->stream->ctx->Ta;
_status=0;
abort:
+ if (_status)
+ r_log(LOG_ICE,LOG_ERR,"ICE(%s)/CAND(%s): %s failed with status: %d", cand->ctx->label, cand->label, __FUNCTION__, _status);
return(_status);
}
#endif /* USE_TURN */
static void nr_ice_srvrflx_stun_finished_cb(NR_SOCKET sock, int how, void *cb_arg)
{
int _status;
nr_ice_candidate *cand=cb_arg;
--- a/media/mtransport/third_party/nICEr/src/stun/nr_socket_buffered_stun.c
+++ b/media/mtransport/third_party/nICEr/src/stun/nr_socket_buffered_stun.c
@@ -251,16 +251,17 @@ abort:
static void nr_socket_buffered_stun_failed(nr_socket_buffered_stun *sock)
{
NR_SOCKET fd;
sock->read_state = NR_ICE_SOCKET_READ_FAILED;
/* Cancel waiting on the socket */
if (sock->inner && !nr_socket_getfd(sock->inner, &fd)) {
+ r_log(LOG_GENERIC, LOG_INFO, "%s canceling RW callbacks", __FUNCTION__);
NR_ASYNC_CANCEL(fd, NR_ASYNC_WAIT_WRITE);
NR_ASYNC_CANCEL(fd, NR_ASYNC_WAIT_READ);
}
}
static int nr_socket_buffered_stun_recvfrom(void *obj,void * restrict buf,
size_t maxlen, size_t *len, int flags, nr_transport_addr *from)
{
@@ -340,16 +341,17 @@ reread:
if (!nr_transport_addr_is_wildcard(&sock->remote_addr)) {
if ((r=nr_transport_addr_copy(from, &sock->remote_addr)))
ABORT(r);
}
_status=0;
abort:
if (_status && (_status != R_WOULDBLOCK)) {
+ r_log(LOG_GENERIC, LOG_ERR, "Read failure in %s: %d", __FUNCTION__, _status);
nr_socket_buffered_stun_failed(sock);
}
return(_status);
}
static int nr_socket_buffered_stun_getfd(void *obj, NR_SOCKET *fd)
{
@@ -405,18 +407,20 @@ static int nr_socket_buffered_stun_accep
static void nr_socket_buffered_stun_connected_cb(NR_SOCKET s, int how, void *arg)
{
nr_socket_buffered_stun *sock = (nr_socket_buffered_stun *)arg;
assert(!sock->connected);
sock->connected = 1;
if (sock->pending) {
- r_log(LOG_GENERIC, LOG_INFO, "Invoking writable_cb on connected (%u)", (uint32_t) sock->pending);
+ r_log(LOG_GENERIC, LOG_INFO, "Socket (%p) invoking writable_cb on connected (%u)", sock, (uint32_t) sock->pending);
nr_socket_buffered_stun_writable_cb(s, how, arg);
+ } else {
+ r_log(LOG_GENERIC, LOG_INFO, "Socket (%p) connected with no pending data", sock);
}
}
static int nr_socket_buffered_stun_connect(void *obj, nr_transport_addr *addr)
{
nr_socket_buffered_stun *sock = (nr_socket_buffered_stun *)obj;
int r, _status;
@@ -428,16 +432,17 @@ static int nr_socket_buffered_stun_conne
NR_SOCKET fd;
if ((r=nr_socket_getfd(sock->inner, &fd)))
ABORT(r);
NR_ASYNC_WAIT(fd, NR_ASYNC_WAIT_WRITE, nr_socket_buffered_stun_connected_cb, sock);
ABORT(R_WOULDBLOCK);
}
+ r_log(LOG_GENERIC, LOG_ERR, "%s socket (%p) connect failed with r: %d", __FUNCTION__, sock, r);
ABORT(r);
} else {
r_log(LOG_GENERIC, LOG_INFO, "Connected without blocking");
sock->connected = 1;
}
_status=0;
abort:
@@ -508,16 +513,18 @@ static int nr_socket_buffered_stun_write
sock->pending += len;
}
if (sock->pending) {
if (!already_armed) {
if ((r=nr_socket_buffered_stun_arm_writable_cb(sock)))
ABORT(r);
+ } else {
+ r_log(LOG_GENERIC, LOG_INFO, "Assuming socket is still/already armed with connect callback - connected (%d)", sock->connected);
}
r_log(LOG_GENERIC, LOG_INFO, "Write buffer not empty for %s %u - %s armed (@%p),%s connected",
sock->remote_addr.as_string, (uint32_t)sock->pending,
already_armed ? "already" : "", &sock->pending,
sock->connected ? "" : " not");
}
*written = original_len;