PVer4: Add UMA metrics for time taken to: load DB, do prefix check,

components/safe_browsing_db/v4_local_database_manager.cc

Index: components/safe_browsing_db/v4_local_database_manager.cc
diff --git a/components/safe_browsing_db/v4_local_database_manager.cc b/components/safe_browsing_db/v4_local_database_manager.cc
index 5798bf2af85f7031247620061388d09ce9695088..f3706a7daaab33e92dafc7d5ff544636fa135b46 100644
--- a/components/safe_browsing_db/v4_local_database_manager.cc
+++ b/components/safe_browsing_db/v4_local_database_manager.cc
@@ -13,10 +13,12 @@
 #include "base/callback.h"
 #include "base/memory/ptr_util.h"
 #include "base/memory/ref_counted.h"
+#include "base/metrics/histogram_macros.h"
 #include "components/safe_browsing_db/v4_feature_list.h"
 #include "content/public/browser/browser_thread.h"
 
 using content::BrowserThread;
+using base::TimeTicks;
 
 namespace safe_browsing {
 
@@ -337,7 +339,9 @@ bool V4LocalDatabaseManager::GetPrefixMatches(
   DCHECK(enabled_);
   DCHECK(v4_database_);
   DCHECK_GT(ClientCallbackType::CHECK_MAX, check->client_callback_type);
+  full_hash_to_store_and_hash_prefixes->clear();
 
+  const base::TimeTicks before = TimeTicks::Now();
   if (check->client_callback_type == ClientCallbackType::CHECK_BROWSE_URL) {
     std::unordered_set<FullHash> full_hashes;
     V4ProtocolManagerUtil::UrlToFullHashes(check->url, &full_hashes);
@@ -352,14 +356,14 @@ bool V4LocalDatabaseManager::GetPrefixMatches(
             matched_store_and_hash_prefixes;
       }
     }
-
-    // No hash prefixes found in the local database so that resource must be
-    // safe.
-    return !full_hash_to_store_and_hash_prefixes->empty();
+  } else {
+    NOTREACHED() << "Unexpected client_callback_type encountered";
   }
 
-  NOTREACHED() << "Unexpected client_callback_type encountered";
-  return false;
+  // TODO(vakh): Consider changing the following histogram name to be
+  // SafeBrowsing.V4GetPrefixMatches.Time once PVer3 code is removed.
+  UMA_HISTOGRAM_TIMES("SB2.FilterCheck", TimeTicks::Now() - before);

[Nathan Parker, 2016/10/21 20:21:19]

This is almost always < 1 ms.  I think we should log it like this for comparison
to pver3, but maybe also log it to your suggested new metric in microseconds. 
The latter would be useful to detect/measure any performance changes in this
code.

[vakh (use Gerrit instead), 2016/10/21 22:54:04]

Done.

+  return !full_hash_to_store_and_hash_prefixes->empty();
 }
 
 void V4LocalDatabaseManager::GetSeverestThreatTypeAndMetadata(
@@ -409,6 +413,10 @@ void V4LocalDatabaseManager::OnFullHashResponse(
     return;
   }
 
+  // TODO(vakh): Consider changing the following histogram name to be
+  // SafeBrowsing.V4GetFullHashOverNetwork.Time once PVer3 code is removed.

[Nathan Parker, 2016/10/21 20:21:19]

an aside: There is a SafeBrowsing.GetV4HashResult.  Maybe that should be
V4GetFullHash.Result?

Feel free to lay these out in the spreadsheet. It's helpful to see them all in
one place to make it clear what the patterns are.

[vakh (use Gerrit instead), 2016/10/21 22:54:04]

Yes, I need to correct the metrics in that file. On my radar.
Ack.

+  UMA_HISTOGRAM_LONG_TIMES("SB2.Network",
+                           TimeTicks::Now() - pending_check->start);
   auto it = pending_clients_.find(pending_check->client);
   if (it == pending_clients_.end()) {
     // The check has since been cancelled.
@@ -434,6 +442,9 @@ void V4LocalDatabaseManager::PerformFullHashCheck(
 
   pending_clients_.insert(check->client);
 
+  // Set the start time for the network request.
+  check->start = TimeTicks::Now();
+
   v4_get_hash_protocol_manager_->GetFullHashes(
       full_hash_to_store_and_hash_prefixes,
       base::Bind(&V4LocalDatabaseManager::OnFullHashResponse,