Add UMA metrics for WebSocket SafeBrowsing lookups

Add the following metrics for WebSocket SafeBrowsing lookups:

* SafeBrowsing.WebSocket.Result is recorded for every WebSocket handshake that
  is checked.
* - SafeBrowsing.WebSocket.Elapsed.Safe
  - SafeBrowsing.WebSocket.Elapsed.Blocked
  - SafeBrowsing.WebSocket.Elapsed.Abandoned
  Record the time in milliseconds spent performing the SafeBrowsing lookup,
  including time spent on the interstitial page if applicable, broken down by
  result.

Because clicking "Back to safety" on the interstitial results in navigating away
from the page, it is recorded as "Abandoned", not "Blocked" as might be
expected. I haven't found a circumstance in which "Blocked" is recorded.

Tested manually with about:histograms.

Bug: 644744
Change-Id: I4ec902e122f48482c6c4d54537ce8035bbac92fc
Reviewed-on: https://chromium-review.googlesource.com/569942Reviewed-by: Varun Khaneja <vakh@chromium.org>
Reviewed-by: Ilya Sherman <isherman@chromium.org>
Commit-Queue: Adam Rice <ricea@chromium.org>
Cr-Commit-Position: refs/heads/master@{#488107}

components/safe_browsing/renderer/websocket_sb_handshake_throttle.cc

@@ -8,6 +8,7 @@
 
 #include "base/bind.h"
 #include "base/logging.h"
+#include "base/metrics/histogram_macros.h"
 #include "base/strings/stringprintf.h"
 #include "content/public/common/resource_type.h"
 #include "content/public/renderer/render_frame.h"
@@ -20,9 +21,25 @@ namespace safe_browsing {
 
 WebSocketSBHandshakeThrottle::WebSocketSBHandshakeThrottle(
     mojom::SafeBrowsing* safe_browsing)
-    : callbacks_(nullptr), safe_browsing_(safe_browsing), weak_factory_(this) {}
+    : callbacks_(nullptr),
+      safe_browsing_(safe_browsing),
+      result_(Result::UNKNOWN),
+      weak_factory_(this) {}
 
-WebSocketSBHandshakeThrottle::~WebSocketSBHandshakeThrottle() {}
+WebSocketSBHandshakeThrottle::~WebSocketSBHandshakeThrottle() {
+  // ThrottleHandshake() should always be called, but since that is done all the
+  // way over in Blink, just avoid logging if it is not called rather than
+  // DCHECK()ing.
+  if (start_time_.is_null())
+    return;
+  if (result_ == Result::UNKNOWN) {
+    result_ = Result::ABANDONED;
+    UMA_HISTOGRAM_TIMES("SafeBrowsing.WebSocket.Elapsed.Abandoned",
+                        base::TimeTicks::Now() - start_time_);
+  }
+  UMA_HISTOGRAM_ENUMERATION("SafeBrowsing.WebSocket.Result", result_,
+                            Result::RESULT_COUNT);
+}
 
 void WebSocketSBHandshakeThrottle::ThrottleHandshake(
     const blink::WebURL& url,
@@ -38,6 +55,7 @@ void WebSocketSBHandshakeThrottle::ThrottleHandshake(
         content::RenderFrame::FromWebFrame(web_local_frame)->GetRoutingID();
   }
   int load_flags = 0;
+  start_time_ = base::TimeTicks::Now();
   safe_browsing_->CreateCheckerAndCheck(
       render_frame_id, mojo::MakeRequest(&url_checker_), url, load_flags,
       content::RESOURCE_TYPE_SUB_RESOURCE,
@@ -46,9 +64,17 @@ void WebSocketSBHandshakeThrottle::ThrottleHandshake(
 }
 
 void WebSocketSBHandshakeThrottle::OnCheckResult(bool safe) {
+  DCHECK(!start_time_.is_null());
+  base::TimeDelta elapsed = base::TimeTicks::Now() - start_time_;
   if (safe) {
+    result_ = Result::SAFE;
+    UMA_HISTOGRAM_TIMES("SafeBrowsing.WebSocket.Elapsed.Safe", elapsed);
     callbacks_->OnSuccess();
   } else {
+    // When the insterstitial is dismissed the page is navigated and this object
+    // is destroyed before reaching here.
+    result_ = Result::BLOCKED;
+    UMA_HISTOGRAM_TIMES("SafeBrowsing.WebSocket.Elapsed.Blocked", elapsed);
     callbacks_->OnError(blink::WebString::FromUTF8(base::StringPrintf(
         "WebSocket connection to %s failed safe browsing check",
         url_.spec().c_str())));

components/safe_browsing/renderer/websocket_sb_handshake_throttle.h

@@ -12,6 +12,7 @@
 #include <memory>
 
 #include "base/macros.h"
+#include "base/time/time.h"
 #include "components/safe_browsing/common/safe_browsing.mojom.h"
 #include "third_party/WebKit/public/platform/WebCallbacks.h"
 #include "third_party/WebKit/public/platform/WebSocketHandshakeThrottle.h"
@@ -30,12 +31,22 @@ class WebSocketSBHandshakeThrottle : public blink::WebSocketHandshakeThrottle {
       blink::WebCallbacks<void, const blink::WebString&>* callbacks) override;
 
  private:
+  // These values are logged to UMA so do not renumber or reuse.
+  enum class Result {
+    UNKNOWN = 0,
+    SAFE = 1,
+    BLOCKED = 2,
+    ABANDONED = 3,
+    RESULT_COUNT
+  };
   void OnCheckResult(bool safe);
 
   GURL url_;
   blink::WebCallbacks<void, const blink::WebString&>* callbacks_;
   mojom::SafeBrowsingUrlCheckerPtr url_checker_;
   mojom::SafeBrowsing* safe_browsing_;
+  base::TimeTicks start_time_;
+  Result result_;
 
   base::WeakPtrFactory<WebSocketSBHandshakeThrottle> weak_factory_;
 

tools/metrics/histograms/enums.xml

@@ -32475,6 +32475,13 @@ from previous Chrome versions.
   <int value="4" label="UNABLE_TO_RENAME_FAILURE"/>
 </enum>
 
+<enum name="SafeBrowsingWebSocketResult">
+  <int value="0" label="UNKNOWN"/>
+  <int value="1" label="SAFE"/>
+  <int value="2" label="BLOCKED"/>
+  <int value="3" label="ABANDONED"/>
+</enum>
+
 <enum name="SavePasswordPromptResponseType">
   <int value="0" label="NO_RESPONSE"/>
   <int value="1" label="REMEMBER_PASSWORD"/>

tools/metrics/histograms/histograms.xml

@@ -65120,6 +65120,25 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries.
   </summary>
 </histogram>
 
+<histogram base="true" name="SafeBrowsing.WebSocket.Elapsed" units="ms">
+  <owner>ricea@chromium.org</owner>
+  <summary>
+    Time spent on SafeBrowsing lookup. Since this includes any time spent on the
+    interstitial page the average may not be useful.
+  </summary>
+</histogram>
+
+<histogram name="SafeBrowsing.WebSocket.Result"
+    enum="SafeBrowsingWebSocketResult">
+  <owner>ricea@chromium.org</owner>
+  <summary>
+    Results of a SafeBrowsing lookup for a WebSocket handshake. All lookups are
+    counted. Note: the &quot;ABANDONED&quot; bucket contains both connections
+    that were abandoned before the check completed and those that were cancelled
+    when the user navigated away from the SafeBrowsing interstitial.
+  </summary>
+</histogram>
+
 <histogram name="SB.BloomFilter" units="ms">
   <obsolete>
     Has not been generated for years (7/8/14).
@@ -97639,6 +97658,17 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries.
   <affected-histogram name="SafeBrowsing.Pref.Scout.SetPref"/>
 </histogram_suffixes>
 
+<histogram_suffixes name="SafeBrowsingWebSocketElapsed" separator=".">
+  <suffix name="Safe"
+      label="Passed SafeBrowsing check, or blocked and interstitial clicked
+             through"/>
+  <suffix name="Blocked" label="Failed SafeBrowsing check and blocked"/>
+  <suffix name="Abandoned"
+      label="Connection abandoned, or interstitial displayed and user did not
+             proceed to site"/>
+  <affected-histogram name="SafeBrowsing.WebSocket.Elapsed"/>
+</histogram_suffixes>
+
 <histogram_suffixes name="SameVersionStartupCounts" separator=".">
   <suffix name="1" label="1st startup with same version"/>
   <suffix name="2" label="2nd startup with same version"/>