diff --git a/media/mtransport/nricectx.cpp b/media/mtransport/nricectx.cpp index 4c97f95311b0..d6b3d32aebe6 100644 --- a/media/mtransport/nricectx.cpp +++ b/media/mtransport/nricectx.cpp @@ -686,17 +686,51 @@ void NrIceCtx::internal_SetTimerAccelarator(int divider) { ctx_->test_timer_divider = divider; } -NrIceCtx::~NrIceCtx() { +void NrIceCtx::AccumulateStats(const NrIceStats& stats) { + nr_ice_accumulate_count(&(ctx_->stats.stun_retransmits), + stats.stun_retransmits); + nr_ice_accumulate_count(&(ctx_->stats.turn_401s), stats.turn_401s); + nr_ice_accumulate_count(&(ctx_->stats.turn_403s), stats.turn_403s); + nr_ice_accumulate_count(&(ctx_->stats.turn_438s), stats.turn_438s); +} + +NrIceStats NrIceCtx::Destroy() { + // designed to be called more than once so if stats are desired, this can be + // called just prior to the destructor MOZ_MTLOG(ML_DEBUG, "Destroying ICE ctx '" << name_ <<"'"); for (auto stream = streams_.begin(); stream != streams_.end(); stream++) { if (*stream) { (*stream)->Close(); } } - nr_ice_peer_ctx_destroy(&peer_); - nr_ice_ctx_destroy(&ctx_); + + NrIceStats stats; + if (ctx_) { + stats.stun_retransmits = ctx_->stats.stun_retransmits; + stats.turn_401s = ctx_->stats.turn_401s; + stats.turn_403s = ctx_->stats.turn_403s; + stats.turn_438s = ctx_->stats.turn_438s; + } + + if (peer_) { + nr_ice_peer_ctx_destroy(&peer_); + } + if (ctx_) { + nr_ice_ctx_destroy(&ctx_); + } + delete ice_handler_vtbl_; delete ice_handler_; + + ice_handler_vtbl_ = 0; + ice_handler_ = 0; + streams_.clear(); + + return stats; +} + +NrIceCtx::~NrIceCtx() { + Destroy(); } void diff --git a/media/mtransport/nricectx.h b/media/mtransport/nricectx.h index 11835e5116d4..d33a37430018 100644 --- a/media/mtransport/nricectx.h +++ b/media/mtransport/nricectx.h @@ -192,6 +192,14 @@ class NrIceProxyServer { class TestNat; +class NrIceStats { + public: + uint16_t stun_retransmits; + uint16_t turn_401s; + uint16_t turn_403s; + uint16_t turn_438s; +}; + class NrIceCtx { friend class NrIceCtxHandler; public: @@ -322,6 +330,9 @@ class NrIceCtx { // more forking. nsresult Finalize(); + void AccumulateStats(const NrIceStats& stats); + NrIceStats Destroy(); + // Are we trickling? bool generating_trickle() const { return trickle_; } diff --git a/media/mtransport/nricectxhandler.cpp b/media/mtransport/nricectxhandler.cpp index 4cea6c2c1551..a1884b1550d1 100644 --- a/media/mtransport/nricectxhandler.cpp +++ b/media/mtransport/nricectxhandler.cpp @@ -141,6 +141,12 @@ NrIceCtxHandler::BeginIceRestart(RefPtr new_ctx) void NrIceCtxHandler::FinalizeIceRestart() { + if (old_ctx) { + // Fixup the telemetry by transferring old stats to current ctx. + NrIceStats stats = old_ctx->Destroy(); + current_ctx->AccumulateStats(stats); + } + // no harm calling this even if we're not in the middle of restarting old_ctx = nullptr; } @@ -156,5 +162,30 @@ NrIceCtxHandler::RollbackIceRestart() old_ctx = nullptr; } +NrIceStats NrIceCtxHandler::Destroy() +{ + NrIceStats stats; + + // designed to be called more than once so if stats are desired, this can be + // called just prior to the destructor + if (old_ctx && current_ctx) { + stats = old_ctx->Destroy(); + current_ctx->AccumulateStats(stats); + } + + if (current_ctx) { + stats = current_ctx->Destroy(); + } + + old_ctx = nullptr; + current_ctx = nullptr; + + return stats; +} + +NrIceCtxHandler::~NrIceCtxHandler() +{ + Destroy(); +} } // close namespace diff --git a/media/mtransport/nricectxhandler.h b/media/mtransport/nricectxhandler.h index 492a19ccf8a2..56ad46d231de 100644 --- a/media/mtransport/nricectxhandler.h +++ b/media/mtransport/nricectxhandler.h @@ -31,6 +31,7 @@ public: void FinalizeIceRestart(); void RollbackIceRestart(); + NrIceStats Destroy(); NS_INLINE_DECL_THREADSAFE_REFCOUNTING(NrIceCtxHandler) @@ -39,7 +40,7 @@ private: bool offerer, NrIceCtx::Policy policy); NrIceCtxHandler() = delete; - ~NrIceCtxHandler() {} + ~NrIceCtxHandler(); DISALLOW_COPY_ASSIGN(NrIceCtxHandler); RefPtr current_ctx; diff --git a/media/mtransport/third_party/nICEr/src/ice/ice_candidate.c b/media/mtransport/third_party/nICEr/src/ice/ice_candidate.c index 879b77933e3c..d72a99c938f5 100644 --- a/media/mtransport/third_party/nICEr/src/ice/ice_candidate.c +++ b/media/mtransport/third_party/nICEr/src/ice/ice_candidate.c @@ -321,6 +321,20 @@ int nr_ice_candidate_destroy(nr_ice_candidate **candp) break; #ifdef USE_TURN case RELAYED: + // record stats back to the ice ctx on destruction + if (cand->u.relayed.turn) { + nr_ice_accumulate_count(&(cand->ctx->stats.turn_401s), cand->u.relayed.turn->cnt_401s); + nr_ice_accumulate_count(&(cand->ctx->stats.turn_403s), cand->u.relayed.turn->cnt_403s); + nr_ice_accumulate_count(&(cand->ctx->stats.turn_438s), cand->u.relayed.turn->cnt_438s); + + nr_turn_stun_ctx* stun_ctx; + stun_ctx = STAILQ_FIRST(&cand->u.relayed.turn->stun_ctxs); + while (stun_ctx) { + nr_ice_accumulate_count(&(cand->ctx->stats.stun_retransmits), stun_ctx->stun->retransmit_ct); + + stun_ctx = STAILQ_NEXT(stun_ctx, entry); + } + } if (cand->u.relayed.turn_handle) nr_ice_socket_deregister(cand->isock, cand->u.relayed.turn_handle); if (cand->u.relayed.srvflx_candidate) diff --git a/media/mtransport/third_party/nICEr/src/ice/ice_candidate_pair.c b/media/mtransport/third_party/nICEr/src/ice/ice_candidate_pair.c index 6c07ae2a6c3a..b220cdfefbb7 100644 --- a/media/mtransport/third_party/nICEr/src/ice/ice_candidate_pair.c +++ b/media/mtransport/third_party/nICEr/src/ice/ice_candidate_pair.c @@ -152,6 +152,11 @@ int nr_ice_candidate_pair_destroy(nr_ice_cand_pair **pairp) pair=*pairp; *pairp=0; + // record stats back to the ice ctx on destruction + if (pair->stun_client) { + nr_ice_accumulate_count(&(pair->local->ctx->stats.stun_retransmits), pair->stun_client->retransmit_ct); + } + RFREE(pair->as_string); RFREE(pair->foundation); nr_ice_socket_deregister(pair->local->isock,pair->stun_client_handle); diff --git a/media/mtransport/third_party/nICEr/src/ice/ice_ctx.c b/media/mtransport/third_party/nICEr/src/ice/ice_ctx.c index 08810a92dc3a..b4ae8c8ea3cb 100644 --- a/media/mtransport/third_party/nICEr/src/ice/ice_ctx.c +++ b/media/mtransport/third_party/nICEr/src/ice/ice_ctx.c @@ -1055,3 +1055,16 @@ int nr_ice_get_new_ice_pwd(char** pwd) return(_status); } +#ifndef UINT2_MAX +#define UINT2_MAX ((UINT2)(65535U)) +#endif + +void nr_ice_accumulate_count(UINT2* orig_count, UINT2 new_count) + { + if (UINT2_MAX - new_count < *orig_count) { + // don't rollover, just stop accumulating at MAX value + *orig_count = UINT2_MAX; + } else { + *orig_count += new_count; + } + } diff --git a/media/mtransport/third_party/nICEr/src/ice/ice_ctx.h b/media/mtransport/third_party/nICEr/src/ice/ice_ctx.h index 1e815ac2ac39..371e5659838e 100644 --- a/media/mtransport/third_party/nICEr/src/ice/ice_ctx.h +++ b/media/mtransport/third_party/nICEr/src/ice/ice_ctx.h @@ -112,6 +112,13 @@ typedef struct nr_ice_stun_id_ { typedef STAILQ_HEAD(nr_ice_stun_id_head_,nr_ice_stun_id_) nr_ice_stun_id_head; +typedef struct nr_ice_stats_ { + UINT2 stun_retransmits; + UINT2 turn_401s; + UINT2 turn_403s; + UINT2 turn_438s; +} nr_ice_stats; + struct nr_ice_ctx_ { UINT4 flags; char *label; @@ -155,6 +162,7 @@ struct nr_ice_ctx_ { void *trickle_cb_arg; char force_net_interface[MAXIFNAME]; + nr_ice_stats stats; }; int nr_ice_ctx_create(char *label, UINT4 flags, nr_ice_ctx **ctxp); @@ -192,6 +200,8 @@ int nr_ice_ctx_set_trickle_cb(nr_ice_ctx *ctx, nr_ice_trickle_candidate_cb cb, v int nr_ice_ctx_hide_candidate(nr_ice_ctx *ctx, nr_ice_candidate *cand); int nr_ice_get_new_ice_ufrag(char** ufrag); int nr_ice_get_new_ice_pwd(char** pwd); +// accumulate a count without worrying about rollover +void nr_ice_accumulate_count(UINT2* orig_count, UINT2 new_count); #define NR_ICE_MAX_ATTRIBUTE_SIZE 256 diff --git a/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.c b/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.c index e8d91982b712..fd9d0c21f6ca 100644 --- a/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.c +++ b/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.c @@ -252,6 +252,9 @@ static void nr_stun_client_timer_expired_cb(NR_SOCKET s, int b, void *cb_arg) if (ctx->state != NR_STUN_CLIENT_STATE_RUNNING) ABORT(R_NOT_PERMITTED); + // track retransmits for ice telemetry + nr_ice_accumulate_count(&(ctx->retransmit_ct), 1); + /* as a side effect will reset the timer */ nr_stun_client_send_request(ctx); diff --git a/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.h b/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.h index 179f16cbaa6f..93abbded04bb 100644 --- a/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.h +++ b/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.h @@ -168,6 +168,7 @@ struct nr_stun_client_ctx_ { char *realm; void *timer_handle; int request_ct; + UINT2 retransmit_ct; UINT4 rto_ms; /* retransmission time out */ double retransmission_backoff_factor; UINT4 maximum_transmits; diff --git a/media/mtransport/third_party/nICEr/src/stun/turn_client_ctx.c b/media/mtransport/third_party/nICEr/src/stun/turn_client_ctx.c index c873f6faf007..ebdc2498877b 100644 --- a/media/mtransport/third_party/nICEr/src/stun/turn_client_ctx.c +++ b/media/mtransport/third_party/nICEr/src/stun/turn_client_ctx.c @@ -255,8 +255,16 @@ static void nr_turn_stun_ctx_cb(NR_SOCKET s, int how, void *arg) paradigm. After that, we fail */ /* TODO(ekr@rtfm.com): 401 needs a #define */ /* TODO(ekr@rtfm.com): Add alternate-server (Mozilla bug 857688) */ + if (ctx->stun->error_code == 438) { + // track 438s for ice telemetry + nr_ice_accumulate_count(&(ctx->tctx->cnt_438s), 1); + } if (ctx->stun->error_code == 401 || ctx->stun->error_code == 438) { if (ctx->retry_ct > 0) { + if (ctx->stun->error_code == 401) { + // track 401s for ice telemetry + nr_ice_accumulate_count(&(ctx->tctx->cnt_401s), 1); + } r_log(NR_LOG_TURN, LOG_WARNING, "TURN(%s): Exceeded the number of retries", ctx->tctx->label); ABORT(R_FAILED); } @@ -606,6 +614,8 @@ static void nr_turn_client_permission_error_cb(NR_SOCKET s, int how, void *arg) nr_turn_stun_ctx *ctx = (nr_turn_stun_ctx *)arg; if (ctx->last_error_code == 403) { + // track 403s for ice telemetry + nr_ice_accumulate_count(&(ctx->tctx->cnt_403s), 1); r_log(NR_LOG_TURN, LOG_WARNING, "TURN(%s): mode %d, permission denied", ctx->tctx->label, ctx->mode); diff --git a/media/mtransport/third_party/nICEr/src/stun/turn_client_ctx.h b/media/mtransport/third_party/nICEr/src/stun/turn_client_ctx.h index c50e79d3b489..8dfc8952a4ad 100644 --- a/media/mtransport/third_party/nICEr/src/stun/turn_client_ctx.h +++ b/media/mtransport/third_party/nICEr/src/stun/turn_client_ctx.h @@ -101,6 +101,11 @@ typedef struct nr_turn_client_ctx_ { void *connected_timer_handle; void *refresh_timer_handle; + + // ice telemetry + UINT2 cnt_401s; + UINT2 cnt_403s; + UINT2 cnt_438s; } nr_turn_client_ctx; extern int NR_LOG_TURN; diff --git a/media/webrtc/signaling/src/peerconnection/PeerConnectionMedia.cpp b/media/webrtc/signaling/src/peerconnection/PeerConnectionMedia.cpp index 1878df88dc02..710f8b89e5ae 100644 --- a/media/webrtc/signaling/src/peerconnection/PeerConnectionMedia.cpp +++ b/media/webrtc/signaling/src/peerconnection/PeerConnectionMedia.cpp @@ -53,6 +53,7 @@ #include "MediaStreamList.h" #include "nsIScriptGlobalObject.h" #include "mozilla/Preferences.h" +#include "mozilla/Telemetry.h" #include "mozilla/dom/RTCStatsReportBinding.h" #include "MediaStreamTrack.h" #include "VideoStreamTrack.h" @@ -791,6 +792,11 @@ PeerConnectionMedia::RollbackIceRestart_s() mIceCtxHdlr->RollbackIceRestart(); ConnectSignals(mIceCtxHdlr->ctx().get(), restartCtx.get()); + + // Fixup the telemetry by transferring abandoned ctx stats to current ctx. + NrIceStats stats = restartCtx->Destroy(); + restartCtx = nullptr; + mIceCtxHdlr->ctx()->AccumulateStats(stats); } bool @@ -1101,6 +1107,25 @@ PeerConnectionMedia::ShutdownMediaTransport_s() disconnect_all(); mTransportFlows.clear(); + +#if !defined(MOZILLA_EXTERNAL_LINKAGE) + NrIceStats stats = mIceCtxHdlr->Destroy(); + + CSFLogDebug(logTag, "Ice Telemetry: stun (retransmits: %d)" + " turn (401s: %d 403s: %d 438s: %d)", + stats.stun_retransmits, stats.turn_401s, stats.turn_403s, + stats.turn_438s); + + Telemetry::ScalarAdd(Telemetry::ScalarID::WEBRTC_NICER_STUN_RETRANSMITS, + stats.stun_retransmits); + Telemetry::ScalarAdd(Telemetry::ScalarID::WEBRTC_NICER_TURN_401S, + stats.turn_401s); + Telemetry::ScalarAdd(Telemetry::ScalarID::WEBRTC_NICER_TURN_403S, + stats.turn_403s); + Telemetry::ScalarAdd(Telemetry::ScalarID::WEBRTC_NICER_TURN_438S, + stats.turn_438s); +#endif + mIceCtxHdlr = nullptr; mMainThread->Dispatch(WrapRunnable(this, &PeerConnectionMedia::SelfDestruct_m), diff --git a/toolkit/components/telemetry/Scalars.yaml b/toolkit/components/telemetry/Scalars.yaml index 46183cb4c797..930624ac46c5 100644 --- a/toolkit/components/telemetry/Scalars.yaml +++ b/toolkit/components/telemetry/Scalars.yaml @@ -366,3 +366,90 @@ telemetry.test: - telemetry-client-dev@mozilla.com record_in_processes: - 'all_childs' + +# The following section contains WebRTC nICEr scalars +# For more info on ICE, see https://tools.ietf.org/html/rfc5245 +# For more info on STUN, see https://tools.ietf.org/html/rfc5389 +# For more info on TURN, see https://tools.ietf.org/html/rfc5766 +webrtc.nicer: + stun_retransmits: + bug_numbers: + - 1325536 + description: > + The count of STUN message retransmissions during a WebRTC call. + When sending STUN request messages over UDP, messages may be + dropped by the network. Retransmissions are the mechanism used to + accomplish reliability of the STUN request/response transaction. + This can happen during both successful and unsuccessful WebRTC + calls. + For more info on ICE, see https://tools.ietf.org/html/rfc5245 + For more info on STUN, see https://tools.ietf.org/html/rfc5389 + For more info on TURN, see https://tools.ietf.org/html/rfc5766 + expires: "57" + kind: uint + notification_emails: + - webrtc-ice-telemetry-alerts@mozilla.com + release_channel_collection: opt-in + record_in_processes: + - 'main' + - 'content' + + turn_401s: + bug_numbers: + - 1325536 + description: > + The count of TURN 401 (Unauthorized) responses to allocation + requests. Only 401 responses beyond the first, expected 401 are + counted. More than one 401 repsonse indicates the client is + experiencing difficulty authenticating with the TURN server. This + can happen during both successful and unsuccessful WebRTC calls. + For more info on ICE, see https://tools.ietf.org/html/rfc5245 + For more info on STUN, see https://tools.ietf.org/html/rfc5389 + For more info on TURN, see https://tools.ietf.org/html/rfc5766 + expires: "57" + kind: uint + notification_emails: + - webrtc-ice-telemetry-alerts@mozilla.com + release_channel_collection: opt-in + record_in_processes: + - 'main' + - 'content' + + turn_403s: + bug_numbers: + - 1325536 + description: > + The count of TURN 403 (Forbidden) responses to CreatePermission or + ChannelBind requests. This indicates that the TURN server is + refusing the request for an IP address or IP address/port + combination, likely due to administrative restrictions. + For more info on ICE, see https://tools.ietf.org/html/rfc5245 + For more info on STUN, see https://tools.ietf.org/html/rfc5389 + For more info on TURN, see https://tools.ietf.org/html/rfc5766 + expires: "57" + kind: uint + notification_emails: + - webrtc-ice-telemetry-alerts@mozilla.com + release_channel_collection: opt-in + record_in_processes: + - 'main' + - 'content' + + turn_438s: + bug_numbers: + - 1325536 + description: > + The count of TURN 438 (Stale Nonce) responses to allocation + requests. This can happen during both successful and unsuccessful + WebRTC calls. + For more info on ICE, see https://tools.ietf.org/html/rfc5245 + For more info on STUN, see https://tools.ietf.org/html/rfc5389 + For more info on TURN, see https://tools.ietf.org/html/rfc5766 + expires: "57" + kind: uint + notification_emails: + - webrtc-ice-telemetry-alerts@mozilla.com + release_channel_collection: opt-in + record_in_processes: + - 'main' + - 'content'