Bug 1627206 - Upgrade failure telemetry for HTTPS Only Mode. r=ckerschb,jcj,dragana

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

dom/security/nsHTTPSOnlyStreamListener.cpp

@@ -4,22 +4,27 @@
  * License, v. 2.0. If a copy of the MPL was not distributed with this
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
-#include "nsHTTPSOnlyStreamListener.h"
 #include "nsHTTPSOnlyUtils.h"
+#include "NSSErrorsService.h"
+#include "mozilla/Telemetry.h"
+#include "mozilla/TimeStamp.h"
+#include "mozpkix/pkixnss.h"
 #include "nsCOMPtr.h"
+#include "nsHTTPSOnlyStreamListener.h"
 #include "nsIChannel.h"
 #include "nsIRequest.h"
 #include "nsITransportSecurityInfo.h"
 #include "nsIURI.h"
 #include "nsPrintfCString.h"
+#include "secerr.h"
+#include "sslerr.h"
 
 NS_IMPL_ISUPPORTS(nsHTTPSOnlyStreamListener, nsIStreamListener,
                   nsIRequestObserver)
 
 nsHTTPSOnlyStreamListener::nsHTTPSOnlyStreamListener(
-    nsIStreamListener* aListener) {
-  mListener = aListener;
-}
+    nsIStreamListener* aListener)
+    : mListener(aListener), mCreationStart(mozilla::TimeStamp::Now()) {}
 
 NS_IMETHODIMP
 nsHTTPSOnlyStreamListener::OnDataAvailable(nsIRequest* aRequest,
@@ -36,31 +41,103 @@ nsHTTPSOnlyStreamListener::OnStartRequest(nsIRequest* request) {
 NS_IMETHODIMP
 nsHTTPSOnlyStreamListener::OnStopRequest(nsIRequest* request,
                                          nsresult aStatus) {
-  // If the request failed we'll log it to the console with the error-code
-  if (NS_FAILED(aStatus)) {
-    nsresult rv;
-    // Try to query for the channel-object
-    nsCOMPtr<nsIChannel> channel = do_QueryInterface(request, &rv);
-    if (NS_SUCCEEDED(rv)) {
-      nsCOMPtr<nsILoadInfo> loadInfo = channel->LoadInfo();
-      uint32_t innerWindowId = loadInfo->GetInnerWindowID();
-
-      nsCOMPtr<nsIURI> uri;
-      rv = channel->GetURI(getter_AddRefs(uri));
-      if (NS_SUCCEEDED(rv)) {
-        // Logging URI as well as Module- and Error-Code
-        AutoTArray<nsString, 2> params = {
-            NS_ConvertUTF8toUTF16(uri->GetSpecOrDefault()),
-            NS_ConvertUTF8toUTF16(nsPrintfCString("M%u-C%u",
-                                                  NS_ERROR_GET_MODULE(aStatus),
-                                                  NS_ERROR_GET_CODE(aStatus)))};
-        nsHTTPSOnlyUtils::LogLocalizedString(
-            "HTTPSOnlyFailedRequest", params, nsIScriptError::errorFlag,
-            innerWindowId, !!loadInfo->GetOriginAttributes().mPrivateBrowsingId,
-            uri);
-      }
-    }
+  // DNS errors are unrelated to the HTTPS-Only mode, so they can be ignored.
+  if (aStatus != NS_ERROR_UNKNOWN_HOST) {
+    RecordUpgradeTelemetry(request, aStatus);
+    LogUpgradeFailure(request, aStatus);
   }
 
   return mListener->OnStopRequest(request, aStatus);
 }
+
+void nsHTTPSOnlyStreamListener::RecordUpgradeTelemetry(nsIRequest* request,
+                                                       nsresult aStatus) {
+  // 1. Get time between now and when the initial upgrade request started
+  int64_t duration =
+      (mozilla::TimeStamp::Now() - mCreationStart).ToMilliseconds();
+
+  // 2. Assemble the category string
+  // [!] All strings have to be present in Histograms.json
+  nsresult rv;
+  nsCOMPtr<nsIChannel> channel = do_QueryInterface(request, &rv);
+  if (NS_FAILED(rv)) {
+    return;
+  }
+
+  nsAutoCString category;
+  nsCOMPtr<nsILoadInfo> loadInfo = channel->LoadInfo();
+
+  if (loadInfo->InternalContentPolicyType() ==
+      nsIContentPolicy::TYPE_DOCUMENT) {
+    category.AppendLiteral("top_");
+  } else {
+    category.AppendLiteral("sub_");
+  }
+
+  if (NS_SUCCEEDED(aStatus)) {
+    category.AppendLiteral("successful");
+  } else {
+    int32_t code = -1 * NS_ERROR_GET_CODE(aStatus);
+
+    if (aStatus == NS_ERROR_REDIRECT_LOOP) {
+      category.AppendLiteral("f_redirectloop");
+    } else if (aStatus == NS_ERROR_NET_TIMEOUT) {
+      category.AppendLiteral("f_timeout");
+    } else if (aStatus == NS_BINDING_ABORTED) {
+      category.AppendLiteral("f_aborted");
+    } else if (aStatus == NS_ERROR_CONNECTION_REFUSED) {
+      category.AppendLiteral("f_cxnrefused");
+    } else if (mozilla::psm::IsNSSErrorCode(code)) {
+      switch (code) {
+        case mozilla::pkix::MOZILLA_PKIX_ERROR_SELF_SIGNED_CERT:
+          category.AppendLiteral("f_ssl_selfsignd");
+          break;
+        case SSL_ERROR_BAD_CERT_DOMAIN:
+          category.AppendLiteral("f_ssl_badcertdm");
+          break;
+        case SEC_ERROR_UNKNOWN_ISSUER:
+          category.AppendLiteral("f_ssl_unkwnissr");
+          break;
+        default:
+          category.AppendLiteral("f_ssl_other");
+          break;
+      }
+    } else {
+      category.AppendLiteral("f_other");
+    }
+  }
+
+  mozilla::Telemetry::Accumulate(
+      mozilla::Telemetry::HTTPS_ONLY_MODE_UPGRADE_TIME_MS, category, duration);
+}
+
+void nsHTTPSOnlyStreamListener::LogUpgradeFailure(nsIRequest* request,
+                                                  nsresult aStatus) {
+  // If the request failed we'll log it to the console with the error-code
+  if (NS_SUCCEEDED(aStatus)) {
+    return;
+  }
+  nsresult rv;
+  // Try to query for the channel-object
+  nsCOMPtr<nsIChannel> channel = do_QueryInterface(request, &rv);
+  if (NS_FAILED(rv)) {
+    return;
+  }
+  nsCOMPtr<nsILoadInfo> loadInfo = channel->LoadInfo();
+  uint32_t innerWindowId = loadInfo->GetInnerWindowID();
+
+  nsCOMPtr<nsIURI> uri;
+  rv = channel->GetURI(getter_AddRefs(uri));
+  if (NS_FAILED(rv)) {
+    return;
+  }
+  // Logging URI as well as Module- and Error-Code
+  AutoTArray<nsString, 2> params = {
+      NS_ConvertUTF8toUTF16(uri->GetSpecOrDefault()),
+      NS_ConvertUTF8toUTF16(nsPrintfCString("M%u-C%u",
+                                            NS_ERROR_GET_MODULE(aStatus),
+                                            NS_ERROR_GET_CODE(aStatus)))};
+  nsHTTPSOnlyUtils::LogLocalizedString(
+      "HTTPSOnlyFailedRequest", params, nsIScriptError::errorFlag,
+      innerWindowId, !!loadInfo->GetOriginAttributes().mPrivateBrowsingId, uri);
+}

dom/security/nsHTTPSOnlyStreamListener.h

@@ -7,8 +7,9 @@
 #ifndef nsHTTPSOnlyStreamListener_h___
 #define nsHTTPSOnlyStreamListener_h___
 
-#include "nsIStreamListener.h"
+#include "mozilla/TimeStamp.h"
 #include "nsCOMPtr.h"
+#include "nsIStreamListener.h"
 
 /**
  * This event listener gets registered for requests that have been upgraded
@@ -26,7 +27,21 @@ class nsHTTPSOnlyStreamListener : public nsIStreamListener {
  private:
   virtual ~nsHTTPSOnlyStreamListener() = default;
 
+  /**
+   * Records telemetry about the upgraded request.
+   * @param aStatus Request object
+   */
+  void RecordUpgradeTelemetry(nsIRequest* request, nsresult aStatus);
+
+  /**
+   * Logs information to the console if the request failed.
+   * @param request Request object
+   * @param aStatus Status of request
+   */
+  void LogUpgradeFailure(nsIRequest* request, nsresult aStatus);
+
   nsCOMPtr<nsIStreamListener> mListener;
+  mozilla::TimeStamp mCreationStart;
 };
 
 #endif /* nsHTTPSOnlyStreamListener_h___ */

dom/security/test/https-only/browser_console_logging.js

@@ -19,7 +19,7 @@ let tests = [
     ],
   },
   {
-    description: "Top-Level upgrade failure should get logged",
+    description: "iFrame upgrade failure should get logged",
     expectLogLevel: Ci.nsIConsoleMessage.error,
     expectIncludes: [
       "Upgrading insecure request",
@@ -57,9 +57,11 @@ const testPathUpgradeable = getRootDirectory(gTestPath).replace(
   "chrome://mochitests/content",
   "http://example.com"
 );
+// DNS errors are not logged as HTTPS-Only Mode upgrade failures, so we have to
+// upgrade to a domain that exists but fails.
 const testPathNotUpgradeable = getRootDirectory(gTestPath).replace(
   "chrome://mochitests/content",
-  "http://mochi.test:8888"
+  "http://self-signed.example.com"
 );
 const kTestURISuccess = testPathUpgradeable + "file_console_logging.html";
 const kTestURIFail = testPathNotUpgradeable + "file_console_logging.html";
@@ -82,11 +84,7 @@ add_task(async function() {
   xhr.open("GET", kTestURIExempt, true);
   xhr.channel.loadInfo.httpsOnlyStatus |= Ci.nsILoadInfo.HTTPS_ONLY_EXEMPT;
   xhr.send();
-  // Wait for logging of 1 and 2
-  await BrowserTestUtils.waitForCondition(() => tests.length === 1);
-  // 3. Failing upgrade to https://
-  await BrowserTestUtils.loadURI(gBrowser.selectedBrowser, kTestURIFail);
-  // Wait for logging of 3
+
   await BrowserTestUtils.waitForCondition(() => tests.length === 0);
 
   // Clean up

dom/security/test/https-only/file_console_logging.html

@@ -9,6 +9,8 @@
   <!-- This request can get upgraded. -->
   <img src="http://example.com/file_1.jpg">
   <!-- This request can't get upgraded -->
-  <img src="http://mochi.test:8888/file_2.jpg">
+  <img src="http://self-signed.example.com/file_2.jpg">
+
+  <iframe src="http://self-signed.example.com/browser/dom/security/test/https-only/file_console_logging.html"></iframe>
 </body>
 </html>

toolkit/components/telemetry/Histograms.json

@@ -5678,6 +5678,41 @@
     "kind": "count",
     "description": "Number of unique pages that contain an unsafe-eval CSP directive"
   },
+  "HTTPS_ONLY_MODE_UPGRADE_TIME_MS": {
+    "record_in_processes": ["main"],
+    "products": ["firefox", "geckoview"],
+    "alert_emails": ["julianwels@mozilla.com", "seceng-telemetry@mozilla.com"],
+    "bug_numbers": [1627206],
+    "expires_in_version": "never",
+    "kind": "exponential",
+    "low": 50,
+    "high": 300000,
+    "n_buckets": 30,
+    "keyed": true,
+    "keys": [
+      "top_successful",
+      "sub_successful",
+      "top_f_redirectloop",
+      "sub_f_redirectloop",
+      "top_f_timeout",
+      "sub_f_timeout",
+      "top_f_aborted",
+      "sub_f_aborted",
+      "top_f_cxnrefused",
+      "sub_f_cxnrefused",
+      "top_f_ssl_selfsignd",
+      "sub_f_ssl_selfsignd",
+      "top_f_ssl_badcertdm",
+      "sub_f_ssl_badcertdm",
+      "top_f_ssl_unkwnissr",
+      "sub_f_ssl_unkwnissr",
+      "top_f_ssl_other",
+      "sub_f_ssl_other",
+      "top_f_other",
+      "sub_f_other"
+    ],
+    "description": "Time it takes for a request that has been upgraded with HTTPS-Only Mode to complete, broken down by top-level (top) / sub-resource (sub) and status"
+  },
   "PLACES_DATABASE_CORRUPTION_HANDLING_STAGE": {
     "record_in_processes": ["main"],
     "products": ["firefox", "fennec", "geckoview", "thunderbird"],