Bug 1771479 - Add histograms for SSL_HANDSHAKE_RESULT and SSL_TIME_UNTIL_READY for connections using ECH. r=dragana

Differential Revision: https://phabricator.services.mozilla.com/D147498

security/manager/ssl/nsNSSIOLayer.cpp

@@ -134,7 +134,7 @@ nsNSSSocketInfo::nsNSSSocketInfo(SharedSSLState& aState, uint32_t providerFlags,
       mFalseStarted(false),
       mIsFullHandshake(false),
       mNotedTimeUntilReady(false),
-      mEchGreaseUsed(false),
+      mEchExtensionStatus(EchExtensionStatus::kNotPresent),
       mIsShortWritePending(false),
       mShortWritePendingByte(0),
       mShortWriteOriginalAmount(-1),
@@ -189,9 +189,22 @@ void nsNSSSocketInfo::NoteTimeUntilReady() {
 
   mNotedTimeUntilReady = true;
 
+  Telemetry::HistogramID time_histogram;
+  switch (GetEchExtensionStatus()) {
+    case EchExtensionStatus::kNotPresent:
+      time_histogram = Telemetry::SSL_TIME_UNTIL_READY;
+      break;
+    case EchExtensionStatus::kGREASE:
+      time_histogram = Telemetry::SSL_TIME_UNTIL_READY_ECH_GREASE;
+      break;
+    case EchExtensionStatus::kReal:
+      time_histogram = Telemetry::SSL_TIME_UNTIL_READY_ECH;
+      break;
+  }
   // This will include TCP and proxy tunnel wait time
-  Telemetry::AccumulateTimeDelta(Telemetry::SSL_TIME_UNTIL_READY,
+  Telemetry::AccumulateTimeDelta(time_histogram, mSocketCreationTimestamp,
-                                 mSocketCreationTimestamp, TimeStamp::Now());
+                                 TimeStamp::Now());
+
   MOZ_LOG(gPIPNSSLog, LogLevel::Debug,
           ("[%p] nsNSSSocketInfo::NoteTimeUntilReady\n", mFd));
 }
@@ -768,6 +781,7 @@ nsNSSSocketInfo::SetEchConfig(const nsACString& aEchConfig) {
                PR_ErrorToName(PR_GetError())));
       return NS_OK;
     }
+    UpdateEchExtensionStatus(EchExtensionStatus::kReal);
   }
   return NS_OK;
 }
@@ -975,7 +989,7 @@ bool retryDueToTLSIntolerance(PRErrorCode err, nsNSSSocketInfo* socketInfo) {
   // Note this only happens during the initial SSL handshake.
 
   if (StaticPrefs::security_tls_ech_disable_grease_on_fallback() &&
-      socketInfo->WasEchGreaseUsed()) {
+      socketInfo->GetEchExtensionStatus() == EchExtensionStatus::kGREASE) {
     // Don't record any intolerances if we used ECH GREASE but force a retry.
     return true;
   }
@@ -1075,7 +1089,8 @@ static_assert((mozilla::pkix::ERROR_BASE - mozilla::pkix::END_OF_LIST) < 31,
               "too many moz::pkix errors");
 
 static void reportHandshakeResult(int32_t bytesTransferred, bool wasReading,
-                                  PRErrorCode err) {
+                                  PRErrorCode err,
+                                  EchExtensionStatus aEchExtensionStatus) {
   uint32_t bucket;
 
   // A negative bytesTransferred or a 0 read are errors.
@@ -1100,7 +1115,19 @@ static void reportHandshakeResult(int32_t bytesTransferred, bool wasReading,
     bucket = 671;
   }
 
-  Telemetry::Accumulate(Telemetry::SSL_HANDSHAKE_RESULT, bucket);
+  Telemetry::HistogramID result_histogram;
+  switch (aEchExtensionStatus) {
+    case EchExtensionStatus::kNotPresent:
+      result_histogram = Telemetry::SSL_HANDSHAKE_RESULT;
+      break;
+    case EchExtensionStatus::kGREASE:
+      result_histogram = Telemetry::SSL_HANDSHAKE_RESULT_ECH_GREASE;
+      break;
+    case EchExtensionStatus::kReal:
+      result_histogram = Telemetry::SSL_HANDSHAKE_RESULT_ECH;
+      break;
+  }
+  Telemetry::Accumulate(result_histogram, bucket);
 }
 
 int32_t checkHandshake(int32_t bytesTransfered, bool wasReading,
@@ -1174,7 +1201,8 @@ int32_t checkHandshake(int32_t bytesTransfered, bool wasReading,
     // Report the result once for each handshake. Note that this does not
     // get handshakes which are cancelled before any reads or writes
     // happen.
-    reportHandshakeResult(bytesTransfered, wasReading, originalError);
+    reportHandshakeResult(bytesTransfered, wasReading, originalError,
+                          socketInfo->GetEchExtensionStatus());
     socketInfo->SetHandshakeNotPending();
   }
 
@@ -2717,7 +2745,7 @@ static nsresult nsSSLIOLayerSetOptions(PRFileDesc* fd, bool forSTARTTLS,
         return NS_ERROR_FAILURE;
       }
     }
-    infoObject->SetEchGreaseUsed();
+    infoObject->UpdateEchExtensionStatus(EchExtensionStatus::kGREASE);
   }
 
   // Include a modest set of named groups.

security/manager/ssl/nsNSSIOLayer.h

@@ -34,6 +34,13 @@ using mozilla::OriginAttributes;
 
 class nsIObserver;
 
+// Order matters for UpdateEchExtensioNStatus.
+enum class EchExtensionStatus {
+  kNotPresent,  // No ECH Extension was sent
+  kGREASE,      // A GREASE ECH Extension was sent
+  kReal         // A 'real' ECH Extension was sent
+};
+
 class nsNSSSocketInfo final : public CommonSocketControl {
  public:
   nsNSSSocketInfo(mozilla::psm::SharedSSLState& aState, uint32_t providerFlags,
@@ -95,10 +102,12 @@ class nsNSSSocketInfo final : public CommonSocketControl {
   void SetFullHandshake() { mIsFullHandshake = true; }
   bool IsFullHandshake() const { return mIsFullHandshake; }
 
-  void SetEchGreaseUsed() { mEchGreaseUsed = true; }
+  void UpdateEchExtensionStatus(EchExtensionStatus aEchExtensionStatus) {
-
+    mEchExtensionStatus = std::max(aEchExtensionStatus, mEchExtensionStatus);
-  bool WasEchUsed() const { return mEchConfig.Length() > 0; }
+  }
-  bool WasEchGreaseUsed() const { return mEchGreaseUsed; }
+  EchExtensionStatus GetEchExtensionStatus() const {
+    return mEchExtensionStatus;
+  }
 
   bool GetJoined() { return mJoined; }
   void SetSentClientCert() { mSentClientCert = true; }
@@ -201,7 +210,7 @@ class nsNSSSocketInfo final : public CommonSocketControl {
   bool mFalseStarted;
   bool mIsFullHandshake;
   bool mNotedTimeUntilReady;
-  bool mEchGreaseUsed;
+  EchExtensionStatus mEchExtensionStatus;  // Currently only used for telemetry.
 
   // True when SSL layer has indicated an "SSL short write", i.e. need
   // to call on send one or more times to push all pending data to write.

toolkit/components/telemetry/Histograms.json

@@ -3092,6 +3092,28 @@
     "n_values": 672,
     "description": "SSL handshake result, 0=success, 1-255=NSS error offset, 256-511=SEC error offset + 256, 512-639=NSPR error offset + 512, 640-670=PKIX error, 671=unknown err"
   },
+  "SSL_HANDSHAKE_RESULT_ECH": {
+    "record_in_processes": ["main", "content"],
+    "products": ["firefox", "fennec"],
+    "alert_emails": ["seceng-telemetry@mozilla.com"],
+    "bug_numbers": [1771479],
+    "releaseChannelCollection": "opt-out",
+    "expires_in_version": "never",
+    "kind": "enumerated",
+    "n_values": 672,
+    "description": "SSL handshake result for connections which used ECH 'Real', 0=success, 1-255=NSS error offset, 256-511=SEC error offset + 256, 512-639=NSPR error offset + 512, 640-670=PKIX error, 671=unknown err"
+  },
+  "SSL_HANDSHAKE_RESULT_ECH_GREASE": {
+    "record_in_processes": ["main", "content"],
+    "products": ["firefox", "fennec"],
+    "alert_emails": ["seceng-telemetry@mozilla.com"],
+    "bug_numbers": [1771479],
+    "releaseChannelCollection": "opt-out",
+    "expires_in_version": "never",
+    "kind": "enumerated",
+    "n_values": 672,
+    "description": "SSL handshake result for connections which used ECH GREASE, 0=success, 1-255=NSS error offset, 256-511=SEC error offset + 256, 512-639=NSPR error offset + 512, 640-670=PKIX error, 671=unknown err"
+  },
   "SSL_TIME_UNTIL_READY": {
     "record_in_processes": ["main", "content"],
     "products": ["firefox", "fennec"],
@@ -3104,6 +3126,30 @@
     "n_buckets": 200,
     "description": "ms of SSL wait time including TCP and proxy tunneling"
   },
+  "SSL_TIME_UNTIL_READY_ECH": {
+    "record_in_processes": ["main", "content"],
+    "products": ["firefox", "fennec"],
+    "alert_emails": ["seceng-telemetry@mozilla.com"],
+    "bug_numbers": [1771479],
+    "releaseChannelCollection": "opt-out",
+    "expires_in_version": "never",
+    "kind": "exponential",
+    "high": 60000,
+    "n_buckets": 200,
+    "description": "ms of SSL wait time including TCP and proxy tunneling for connections using ECH 'Real'"
+  },
+  "SSL_TIME_UNTIL_READY_ECH_GREASE": {
+    "record_in_processes": ["main", "content"],
+    "products": ["firefox", "fennec"],
+    "alert_emails": ["seceng-telemetry@mozilla.com"],
+    "bug_numbers": [1771479],
+    "releaseChannelCollection": "opt-out",
+    "expires_in_version": "never",
+    "kind": "exponential",
+    "high": 60000,
+    "n_buckets": 200,
+    "description": "ms of SSL wait time including TCP and proxy tunneling for connections using ECH GREASE"
+  },
   "SSL_TIME_UNTIL_HANDSHAKE_FINISHED_KEYED_BY_KA": {
     "record_in_processes": ["main", "content"],
     "products": ["firefox", "fennec"],

toolkit/components/telemetry/histogram-allowlists.json

@@ -930,6 +930,8 @@
     "SYSTEM_FONT_FALLBACK_SCRIPT",
     "HTTP_REQUEST_PER_PAGE_FROM_CACHE",
     "SSL_TIME_UNTIL_READY",
+    "SSL_TIME_UNTIL_READY_ECH",
+    "SSL_TIME_UNTIL_READY_ECH_GREASE",
     "SSL_TIME_UNTIL_HANDSHAKE_FINISHED_KEYED_BY_KA",
     "CERT_VALIDATION_HTTP_REQUEST_CANCELED_TIME",
     "CERT_VALIDATION_HTTP_REQUEST_SUCCEEDED_TIME",
@@ -994,6 +996,8 @@
     "SSL_CIPHER_SUITE_FULL",
     "SSL_CIPHER_SUITE_RESUMED",
     "SSL_HANDSHAKE_RESULT",
+    "SSL_HANDSHAKE_RESULT_ECH",
+    "SSL_HANDSHAKE_RESULT_ECH_GREASE",
     "SSL_REASONS_FOR_NOT_FALSE_STARTING",
     "SSL_CERT_VERIFICATION_ERRORS",
     "CERT_VALIDATION_SUCCESS_BY_CA",