Bug 1336182 - Part 1: Add DTLS handshake time telemetry. r=bsmedberg,drno
authorByron Campen [:bwc] <docfaraday@gmail.com>
Fri, 03 Feb 2017 17:01:05 -0600
changeset 342613 98b4c49e8a389dc43469f46dcc435607e2b189d6
parent 342612 7b243c8dac97dfe534257d267dfcd88929fd28aa
child 342614 8b899017b08a14fd711bf45c275df949cbd6932d
push id31359
push usercbook@mozilla.com
push dateTue, 14 Feb 2017 12:32:03 +0000
treeherdermozilla-central@cb86d9e08672 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersbsmedberg, drno
bugs1336182
milestone54.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 1336182 - Part 1: Add DTLS handshake time telemetry. r=bsmedberg,drno MozReview-Commit-ID: JczL8eFuzMg
media/mtransport/transportlayerdtls.cpp
media/mtransport/transportlayerdtls.h
toolkit/components/telemetry/Histograms.json
--- a/media/mtransport/transportlayerdtls.cpp
+++ b/media/mtransport/transportlayerdtls.cpp
@@ -11,16 +11,17 @@
 #include <algorithm>
 #include <queue>
 #include <sstream>
 
 #include "dtlsidentity.h"
 #include "keyhi.h"
 #include "logging.h"
 #include "mozilla/Move.h"
+#include "mozilla/Telemetry.h"
 #include "mozilla/UniquePtr.h"
 #include "mozilla/Unused.h"
 #include "nsCOMPtr.h"
 #include "nsComponentManagerUtils.h"
 #include "nsComponentManagerUtils.h"
 #include "nsIEventTarget.h"
 #include "nsNetCID.h"
 #include "nsServiceManagerUtils.h"
@@ -863,16 +864,18 @@ void TransportLayerDtls::StateChange(Tra
       break;
   }
 }
 
 void TransportLayerDtls::Handshake() {
   // Clear the retransmit timer
   timer_->Cancel();
 
+  MOZ_ASSERT(state_ == TS_CONNECTING);
+
   SECStatus rv = SSL_ForceHandshake(ssl_fd_.get());
 
   if (rv == SECSuccess) {
     MOZ_MTLOG(ML_NOTICE,
               LAYER_INFO << "****** SSL handshake completed ******");
     if (!cert_ok_) {
       MOZ_MTLOG(ML_ERROR, LAYER_INFO << "Certificate check never occurred");
       TL_SET_STATE(TS_ERROR);
@@ -1028,16 +1031,44 @@ void TransportLayerDtls::PacketReceived(
           MOZ_MTLOG(ML_NOTICE, LAYER_INFO << "NSS Error " << err);
           TL_SET_STATE(TS_ERROR);
         }
       }
     } while (rv > 0);
   }
 }
 
+void TransportLayerDtls::SetState(State state,
+                                  const char *file,
+                                  unsigned line) {
+  if (state > state_) {
+    switch (state) {
+      case TS_NONE:
+      case TS_INIT:
+        MOZ_ASSERT(false);
+        break;
+      case TS_CONNECTING:
+        handshake_started_ = TimeStamp::Now();
+        break;
+      case TS_OPEN:
+      case TS_CLOSED:
+      case TS_ERROR:
+        timer_->Cancel();
+        if (state_ == TS_CONNECTING) {
+          RecordHandshakeCompletionTelemetry(state);
+        }
+        break;
+    }
+  } else {
+    MOZ_ASSERT(false, "Invalid state transition");
+  }
+
+  TransportLayer::SetState(state, file, line);
+}
+
 TransportResult TransportLayerDtls::SendPacket(const unsigned char *data,
                                                size_t len) {
   CheckThread();
   if (state_ != TS_OPEN) {
     MOZ_MTLOG(ML_ERROR, LAYER_INFO << "Can't call SendPacket() in state "
               << state_);
     return TE_ERROR;
   }
@@ -1252,9 +1283,45 @@ SECStatus TransportLayerDtls::AuthCertif
 void TransportLayerDtls::TimerCallback(nsITimer *timer, void *arg) {
   TransportLayerDtls *dtls = reinterpret_cast<TransportLayerDtls *>(arg);
 
   MOZ_MTLOG(ML_DEBUG, "DTLS timer expired");
 
   dtls->Handshake();
 }
 
+void
+TransportLayerDtls::RecordHandshakeCompletionTelemetry(
+    TransportLayer::State endState) {
+  int32_t delta = (TimeStamp::Now() - handshake_started_).ToMilliseconds();
+
+  switch (endState) {
+    case TransportLayer::State::TS_OPEN:
+      if (role_ == TransportLayerDtls::CLIENT) {
+        Telemetry::Accumulate(Telemetry::WEBRTC_DTLS_CLIENT_SUCCESS_TIME,
+                              delta);
+      } else {
+        Telemetry::Accumulate(Telemetry::WEBRTC_DTLS_SERVER_SUCCESS_TIME,
+                              delta);
+      }
+      return;
+    case TransportLayer::State::TS_ERROR:
+      if (role_ == TransportLayerDtls::CLIENT) {
+        Telemetry::Accumulate(Telemetry::WEBRTC_DTLS_CLIENT_FAILURE_TIME,
+                              delta);
+      } else {
+        Telemetry::Accumulate(Telemetry::WEBRTC_DTLS_SERVER_FAILURE_TIME,
+                              delta);
+      }
+      return;
+    case TransportLayer::State::TS_CLOSED:
+      if (role_ == TransportLayerDtls::CLIENT) {
+        Telemetry::Accumulate(Telemetry::WEBRTC_DTLS_CLIENT_ABORT_TIME, delta);
+      } else {
+        Telemetry::Accumulate(Telemetry::WEBRTC_DTLS_SERVER_ABORT_TIME, delta);
+      }
+      return;
+    default:
+      MOZ_ASSERT(false);
+  }
+}
+
 }  // close namespace
--- a/media/mtransport/transportlayerdtls.h
+++ b/media/mtransport/transportlayerdtls.h
@@ -11,16 +11,17 @@
 
 #include <queue>
 #include <set>
 
 #include "sigslot.h"
 
 #include "mozilla/RefPtr.h"
 #include "mozilla/UniquePtr.h"
+#include "mozilla/TimeStamp.h"
 #include "nsCOMPtr.h"
 #include "nsIEventTarget.h"
 #include "nsITimer.h"
 #include "ScopedNSSTypes.h"
 #include "m_cpp_utils.h"
 #include "dtlsidentity.h"
 #include "transportflow.h"
 #include "transportlayer.h"
@@ -101,16 +102,19 @@ class TransportLayerDtls final : public 
   void PacketReceived(TransportLayer* layer, const unsigned char *data,
                       size_t len);
 
   // For testing use only.  Returns the fd.
   PRFileDesc* internal_fd() { CheckThread(); return ssl_fd_.get(); }
 
   TRANSPORT_LAYER_ID("dtls")
 
+  protected:
+  void SetState(State state, const char *file, unsigned line) override;
+
   private:
   DISALLOW_COPY_ASSIGN(TransportLayerDtls);
 
   // A single digest to check
   class VerificationDigest {
    public:
     VerificationDigest(std::string algorithm,
                        const unsigned char *value, size_t len) {
@@ -152,16 +156,18 @@ class TransportLayerDtls final : public 
                                 PRBool checksig,
                                 PRBool isServer);
 
   static void TimerCallback(nsITimer *timer, void *arg);
 
   SECStatus CheckDigest(const RefPtr<VerificationDigest>& digest,
                         UniqueCERTCertificate& cert) const;
 
+  void RecordHandshakeCompletionTelemetry(TransportLayer::State endState);
+
   RefPtr<DtlsIdentity> identity_;
   // What ALPN identifiers are permitted.
   std::set<std::string> alpn_allowed_;
   // What ALPN identifier is used if ALPN is not supported.
   // The empty string indicates that ALPN is required.
   std::string alpn_default_;
   // What ALPN string was negotiated.
   std::string alpn_;
@@ -174,13 +180,14 @@ class TransportLayerDtls final : public 
   // Must delete nspr_io_adapter after ssl_fd_ b/c ssl_fd_ causes an alert
   // (ssl_fd_ contains an un-owning pointer to nspr_io_adapter_)
   UniquePtr<TransportLayerNSPRAdapter> nspr_io_adapter_;
   UniquePRFileDesc ssl_fd_;
 
   nsCOMPtr<nsITimer> timer_;
   bool auth_hook_called_;
   bool cert_ok_;
+  TimeStamp handshake_started_;
 };
 
 
 }  // close namespace
 #endif
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -6938,16 +6938,70 @@
     "description": "The H.264 profile number (profile_idc) as extracted from the decoded SPS."
   },
   "VIDEO_H264_SPS_MAX_NUM_REF_FRAMES": {
     "expires_in_version": "55",
     "kind": "enumerated",
     "n_values": 17,
     "description": "SPS.max_num_ref_frames indicates how deep the H.264 queue is going to be, and as such the minimum memory usage by the decoder, from 0 to 16. 17 indicates an invalid value."
   },
+  "WEBRTC_DTLS_CLIENT_SUCCESS_TIME": {
+    "alert_emails": ["webrtc-dtls-telemetry-alerts@mozilla.com"],
+    "bug_numbers": [1336182],
+    "expires_in_version": "60",
+    "kind": "exponential",
+    "high": 10000,
+    "n_buckets": 20,
+    "description": "The length of time (in milliseconds) it took for a client DTLS handshake to complete, given that DTLS succeeded."
+  },
+  "WEBRTC_DTLS_CLIENT_ABORT_TIME": {
+    "alert_emails": ["webrtc-dtls-telemetry-alerts@mozilla.com"],
+    "bug_numbers": [1336182],
+    "expires_in_version": "60",
+    "kind": "exponential",
+    "high": 10000,
+    "n_buckets": 20,
+    "description": "The length of time (in milliseconds) it took for a client DTLS handshake to be aborted due to some external factor (eg; PeerConnection torn down)."
+  },
+  "WEBRTC_DTLS_CLIENT_FAILURE_TIME": {
+    "alert_emails": ["webrtc-dtls-telemetry-alerts@mozilla.com"],
+    "bug_numbers": [1336182],
+    "expires_in_version": "60",
+    "kind": "exponential",
+    "high": 10000,
+    "n_buckets": 20,
+    "description": "The length of time (in milliseconds) it took for a client DTLS handshake to complete, given that it failed."
+  },
+  "WEBRTC_DTLS_SERVER_SUCCESS_TIME": {
+    "alert_emails": ["webrtc-dtls-telemetry-alerts@mozilla.com"],
+    "bug_numbers": [1336182],
+    "expires_in_version": "60",
+    "kind": "exponential",
+    "high": 10000,
+    "n_buckets": 20,
+    "description": "The length of time (in milliseconds) it took for a server DTLS handshake to complete, given that DTLS succeeded."
+  },
+  "WEBRTC_DTLS_SERVER_ABORT_TIME": {
+    "alert_emails": ["webrtc-dtls-telemetry-alerts@mozilla.com"],
+    "bug_numbers": [1336182],
+    "expires_in_version": "60",
+    "kind": "exponential",
+    "high": 10000,
+    "n_buckets": 20,
+    "description": "The length of time (in milliseconds) it took for a server DTLS handshake to be aborted due to some external factor (eg; PeerConnection torn down)."
+  },
+  "WEBRTC_DTLS_SERVER_FAILURE_TIME": {
+    "alert_emails": ["webrtc-dtls-telemetry-alerts@mozilla.com"],
+    "bug_numbers": [1336182],
+    "expires_in_version": "60",
+    "kind": "exponential",
+    "high": 10000,
+    "n_buckets": 20,
+    "description": "The length of time (in milliseconds) it took for a server DTLS handshake to complete, given that it failed."
+  },
   "WEBRTC_ICE_FINAL_CONNECTION_STATE": {
     "alert_emails": ["webrtc-ice-telemetry-alerts@mozilla.com"],
     "bug_numbers": [1319268],
     "expires_in_version": "58",
     "kind": "enumerated",
     "n_values": 7,
     "description": "The ICE connection state when the PC was closed"
   },