Bug 1342523 - Part 2: Add some better ICE duration telemetry. r=drno, r=bsmedberg
MozReview-Commit-ID: 7qRd1v6rUHl
--- a/media/mtransport/nricectx.cpp
+++ b/media/mtransport/nricectx.cpp
@@ -39,16 +39,17 @@ DATA, OR PROFITS; OR BUSINESS INTERRUPTI
THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
(INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
*/
#include <string>
#include <vector>
+#include "mozilla/Telemetry.h"
#include "mozilla/UniquePtr.h"
#include "logging.h"
#include "nspr.h"
#include "nss.h"
#include "pk11pub.h"
#include "plbase64.h"
@@ -705,16 +706,31 @@ NrIceStats NrIceCtx::Destroy() {
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 (!ice_start_time_.IsNull()) {
+ TimeDuration time_delta = TimeStamp::Now() - ice_start_time_;
+ ice_start_time_ = TimeStamp(); // null out
+
+ if (offerer_) {
+ Telemetry::Accumulate(
+ Telemetry::WEBRTC_ICE_OFFERER_ABORT_TIME,
+ time_delta.ToMilliseconds());
+ } else {
+ Telemetry::Accumulate(
+ Telemetry::WEBRTC_ICE_ANSWERER_ABORT_TIME,
+ time_delta.ToMilliseconds());
+ }
+ }
+
if (peer_) {
nr_ice_peer_ctx_destroy(&peer_);
}
if (ctx_) {
nr_ice_ctx_destroy(&ctx_);
}
delete ice_handler_vtbl_;
@@ -965,16 +981,17 @@ nsresult NrIceCtx::ParseGlobalAttributes
return NS_OK;
}
nsresult NrIceCtx::StartChecks(bool offerer) {
int r;
offerer_ = offerer;
+ ice_start_time_ = TimeStamp::Now();
r=nr_ice_peer_ctx_pair_candidates(peer_);
if (r) {
MOZ_MTLOG(ML_ERROR, "Couldn't pair candidates on "
<< name_ << "'");
SetConnectionState(ICE_CTX_FAILED);
return NS_ERROR_FAILURE;
}
@@ -1023,16 +1040,57 @@ void NrIceCtx::UpdateNetworkState(bool o
nr_ice_peer_ctx_disconnect_all_streams(peer_);
}
}
void NrIceCtx::SetConnectionState(ConnectionState state) {
if (state == connection_state_)
return;
+ if (!ice_start_time_.IsNull() && (state > ICE_CTX_CHECKING)) {
+ TimeDuration time_delta = TimeStamp::Now() - ice_start_time_;
+ ice_start_time_ = TimeStamp();
+
+ switch (state) {
+ case ICE_CTX_INIT:
+ case ICE_CTX_CHECKING:
+ MOZ_CRASH();
+ break;
+ case ICE_CTX_CONNECTED:
+ case ICE_CTX_COMPLETED:
+ if (offerer_) {
+ Telemetry::Accumulate(
+ Telemetry::WEBRTC_ICE_OFFERER_SUCCESS_TIME,
+ time_delta.ToMilliseconds());
+ } else {
+ Telemetry::Accumulate(
+ Telemetry::WEBRTC_ICE_ANSWERER_SUCCESS_TIME,
+ time_delta.ToMilliseconds());
+ }
+ break;
+ case ICE_CTX_FAILED:
+ if (offerer_) {
+ Telemetry::Accumulate(
+ Telemetry::WEBRTC_ICE_OFFERER_FAILURE_TIME,
+ time_delta.ToMilliseconds());
+ } else {
+ Telemetry::Accumulate(
+ Telemetry::WEBRTC_ICE_ANSWERER_FAILURE_TIME,
+ time_delta.ToMilliseconds());
+ }
+ break;
+ case ICE_CTX_DISCONNECTED:
+ MOZ_CRASH("Transition from checking->disconnected should never happen");
+ break;
+ case ICE_CTX_CLOSED:
+ // This doesn't seem to be used...
+ break;
+ }
+ }
+
MOZ_MTLOG(ML_INFO, "NrIceCtx(" << name_ << "): state " <<
connection_state_ << "->" << state);
connection_state_ = state;
if (connection_state_ == ICE_CTX_FAILED) {
MOZ_MTLOG(ML_INFO, "NrIceCtx(" << name_ << "): dumping r_log ringbuffer... ");
std::deque<std::string> logs;
RLogConnector::GetInstance()->GetAny(0, &logs);
--- a/media/mtransport/nricectx.h
+++ b/media/mtransport/nricectx.h
@@ -381,16 +381,17 @@ private:
// Set the state
void SetGatheringState(GatheringState state);
ConnectionState connection_state_;
GatheringState gathering_state_;
const std::string name_;
bool offerer_;
+ TimeStamp ice_start_time_;
bool ice_controlling_set_;
std::vector<RefPtr<NrIceMediaStream> > streams_;
nr_ice_ctx *ctx_;
nr_ice_peer_ctx *peer_;
nr_ice_handler_vtbl* ice_handler_vtbl_; // Must be pointer
nr_ice_handler* ice_handler_; // Must be pointer
bool trickle_;
nsCOMPtr<nsIEventTarget> sts_target_; // The thread to run on
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -7173,16 +7173,70 @@
"alert_emails": ["webrtc-ice-telemetry-alerts@mozilla.com"],
"bug_numbers": [1319268],
"expires_in_version": "58",
"kind": "exponential",
"high": 10000,
"n_buckets": 20,
"description": "The length of time (in milliseconds) that a trickle candidate took to arrive after the start of ICE, given that it arrived after ICE failed."
},
+ "WEBRTC_ICE_OFFERER_SUCCESS_TIME": {
+ "alert_emails": ["webrtc-ice-telemetry-alerts@mozilla.com"],
+ "bug_numbers": [1342523],
+ "expires_in_version": "60",
+ "kind": "exponential",
+ "high": 10000,
+ "n_buckets": 20,
+ "description": "The length of time (in milliseconds) it took for the offerer to complete ICE, given that ICE succeeded."
+ },
+ "WEBRTC_ICE_OFFERER_ABORT_TIME": {
+ "alert_emails": ["webrtc-ice-telemetry-alerts@mozilla.com"],
+ "bug_numbers": [1342523],
+ "expires_in_version": "60",
+ "kind": "exponential",
+ "high": 10000,
+ "n_buckets": 20,
+ "description": "The length of time (in milliseconds) it took for the offerer to abort ICE due to some external factor (eg; PeerConnection torn down). Does not count cases where StartChecks() was never called."
+ },
+ "WEBRTC_ICE_OFFERER_FAILURE_TIME": {
+ "alert_emails": ["webrtc-ice-telemetry-alerts@mozilla.com"],
+ "bug_numbers": [1342523],
+ "expires_in_version": "60",
+ "kind": "exponential",
+ "high": 10000,
+ "n_buckets": 20,
+ "description": "The length of time (in milliseconds) it took for the offerer to complete ICE, given that it failed. Does not count cases where StartChecks() was never called."
+ },
+ "WEBRTC_ICE_ANSWERER_SUCCESS_TIME": {
+ "alert_emails": ["webrtc-ice-telemetry-alerts@mozilla.com"],
+ "bug_numbers": [1342523],
+ "expires_in_version": "60",
+ "kind": "exponential",
+ "high": 10000,
+ "n_buckets": 20,
+ "description": "The length of time (in milliseconds) it took for the answerer to complete ICE, given that ICE succeeded."
+ },
+ "WEBRTC_ICE_ANSWERER_ABORT_TIME": {
+ "alert_emails": ["webrtc-ice-telemetry-alerts@mozilla.com"],
+ "bug_numbers": [1342523],
+ "expires_in_version": "60",
+ "kind": "exponential",
+ "high": 10000,
+ "n_buckets": 20,
+ "description": "The length of time (in milliseconds) it took for the answerer to abort ICE due to some external factor (eg; PeerConnection torn down). Does not count cases where StartChecks() was never called."
+ },
+ "WEBRTC_ICE_ANSWERER_FAILURE_TIME": {
+ "alert_emails": ["webrtc-ice-telemetry-alerts@mozilla.com"],
+ "bug_numbers": [1342523],
+ "expires_in_version": "60",
+ "kind": "exponential",
+ "high": 10000,
+ "n_buckets": 20,
+ "description": "The length of time (in milliseconds) it took for the answerer to complete ICE, given that it failed. Does not count cases where StartChecks() was never called."
+ },
"WEBRTC_ICE_SUCCESS_TIME": {
"alert_emails": ["webrtc-ice-telemetry-alerts@mozilla.com"],
"bug_numbers": [1319268],
"expires_in_version": "58",
"kind": "exponential",
"high": 10000,
"n_buckets": 20,
"description": "The length of time (in milliseconds) it took for ICE to complete, given that ICE succeeded."