Add detailed UMA metrics for v4_store, broken down by storeid.

components/safe_browsing_db/v4_store.cc

Index: components/safe_browsing_db/v4_store.cc
diff --git a/components/safe_browsing_db/v4_store.cc b/components/safe_browsing_db/v4_store.cc
index 13303830dbd348b6a4d74b5ffed3ecc57f6181cd..83f3b999b5e45e383a41f14d2098f39cfd45f9a8 100644
--- a/components/safe_browsing_db/v4_store.cc
+++ b/components/safe_browsing_db/v4_store.cc
@@ -22,8 +22,24 @@ namespace safe_browsing {
 
 namespace {
 
-const uint32_t kFileMagic = 0x600D71FE;
+// UMA related strings.
+// Part 1: Represent the overall operation being performed.
+const char kProcessFullUpdate[] = "SafeBrowsing.V4ProcessFullUpdate";
+const char kProcessPartialUpdate[] = "SafeBrowsing.V4ProcessPartialUpdate";
+const char kReadFromDisk[] = "SafeBrowsing.V4ReadFromDisk";
+// Part 2: Represent the sub-operation being performed as part of the larger
+// operation from part 1.
+const char kApplyUpdate[] = ".ApplyUpdate";
+const char kDecodeAdditions[] = ".DecodeAdditions";
+const char kDecodeRemovals[] = ".DecodeRemovals";
+const char kMergeUpdate[] = ".MergeUpdate";
+// Part 3: Represent the unit of value being measured and logged.
+const char kResult[] = ".Result";
+const char kTime[] = ".Time";
+// UMA metric names for this file are generated by appending one value each,
+// in order, from parts 1, 2, and 3.

[Nathan Parker, 2016/10/14 20:48:32]

nit: You're missing part 2.5, which is the store name.

[vakh (use Gerrit instead), 2016/10/15 00:09:04]

Done.

 
+const uint32_t kFileMagic = 0x600D71FE;
 const uint32_t kFileVersion = 9;
 
 std::string GetUmaSuffixForStore(const base::FilePath& file_path) {
@@ -31,16 +47,16 @@ std::string GetUmaSuffixForStore(const base::FilePath& file_path) {
       ".%" PRIsFP, file_path.BaseName().RemoveExtension().value().c_str());
 }
 
-void RecordTimeWithAndWithoutStore(const std::string& metric,
-                                   base::TimeDelta time,
-                                   const base::FilePath& file_path) {
+void RecordTimeWithAndWithoutSuffix(const std::string& metric,
+                                    base::TimeDelta time,
+                                    const base::FilePath& file_path) {
   // The histograms below are a modified expansion of the
   // UMA_HISTOGRAM_LONG_TIMES macro adapted to allow for a dynamically suffixed
   // histogram name.
   // Note: The factory creates and owns the histogram.
   const int kBucketCount = 100;
   base::HistogramBase* histogram = base::Histogram::FactoryTimeGet(
-      metric, base::TimeDelta::FromMilliseconds(1),
+      metric + kTime, base::TimeDelta::FromMilliseconds(1),
       base::TimeDelta::FromMinutes(1), kBucketCount,
       base::HistogramBase::kUmaTargetedHistogramFlag);
   if (histogram) {
@@ -49,7 +65,7 @@ void RecordTimeWithAndWithoutStore(const std::string& metric,
 
   std::string suffix = GetUmaSuffixForStore(file_path);
   base::HistogramBase* histogram_suffix = base::Histogram::FactoryTimeGet(
-      metric + suffix, base::TimeDelta::FromMilliseconds(1),
+      metric + suffix + kTime, base::TimeDelta::FromMilliseconds(1),
       base::TimeDelta::FromMinutes(1), kBucketCount,
       base::HistogramBase::kUmaTargetedHistogramFlag);
   if (histogram_suffix) {
@@ -57,74 +73,87 @@ void RecordTimeWithAndWithoutStore(const std::string& metric,
   }
 }
 
+void RecordEnumWithAndWithoutSuffix(const std::string& metric,
+                                    int32_t value,
+                                    int32_t maximum,
+                                    const base::FilePath& file_path) {
+  // The histograms below are an expansion of the UMA_HISTOGRAM_ENUMERATION
+  // macro adapted to allow for a dynamically suffixed histogram name.
+  // Note: The factory creates and owns the histogram.
+  base::HistogramBase* histogram = base::LinearHistogram::FactoryGet(
+      metric + kResult, 1, maximum, maximum + 1,
+      base::HistogramBase::kUmaTargetedHistogramFlag);
+  if (histogram) {
+    histogram->Add(value);
+  }
+
+  std::string suffix = GetUmaSuffixForStore(file_path);
+  base::HistogramBase* histogram_suffix = base::LinearHistogram::FactoryGet(
+      metric + suffix + kResult, 1, maximum, maximum + 1,
+      base::HistogramBase::kUmaTargetedHistogramFlag);
+  if (histogram_suffix) {
+    histogram_suffix->Add(value);
+  }
+}
+
 void RecordAddUnlumpedHashesTime(base::TimeDelta time) {
-  UMA_HISTOGRAM_LONG_TIMES("SafeBrowsing.V4AddUnlumpedHashesTime", time);
+  UMA_HISTOGRAM_LONG_TIMES("SafeBrowsing.V4AddUnlumpedHashes.Time", time);
 }
 
-void RecordApplyUpdateResult(ApplyUpdateResult result) {
-  UMA_HISTOGRAM_ENUMERATION("SafeBrowsing.V4ApplyUpdateResult", result,
-                            APPLY_UPDATE_RESULT_MAX);
+void RecordApplyUpdateResult(const std::string& base_metric,
+                             ApplyUpdateResult result,
+                             const base::FilePath& file_path) {
+  RecordEnumWithAndWithoutSuffix(base_metric + kApplyUpdate, result,
+                                 APPLY_UPDATE_RESULT_MAX, file_path);
 }
 
-void RecordApplyUpdateResultWhenReadingFromDisk(ApplyUpdateResult result) {
-  UMA_HISTOGRAM_ENUMERATION(
-      "SafeBrowsing.V4ApplyUpdateResultWhenReadingFromDisk", result,
-      APPLY_UPDATE_RESULT_MAX);
+void RecordApplyUpdateTime(const std::string& base_metric,
+                           base::TimeDelta time,
+                           const base::FilePath& file_path) {
+  RecordTimeWithAndWithoutSuffix(base_metric + kApplyUpdate, time, file_path);
 }
 
-void RecordDecodeAdditionsResult(V4DecodeResult result) {
-  UMA_HISTOGRAM_ENUMERATION("SafeBrowsing.V4DecodeAdditionsResult", result,
-                            DECODE_RESULT_MAX);
+void RecordDecodeAdditionsResult(const std::string& base_metric,
+                                 V4DecodeResult result,
+                                 const base::FilePath& file_path) {
+  RecordEnumWithAndWithoutSuffix(base_metric + kDecodeAdditions, result,
+                                 DECODE_RESULT_MAX, file_path);
 }
 
-void RecordDecodeAdditionsTime(base::TimeDelta time,
+void RecordDecodeAdditionsTime(const std::string& base_metric,
+                               base::TimeDelta time,
                                const base::FilePath& file_path) {
-  RecordTimeWithAndWithoutStore("SafeBrowsing.V4DecodeAdditionsTime", time,
-                                file_path);
+  RecordTimeWithAndWithoutSuffix(base_metric + kDecodeAdditions, time,
+                                 file_path);
 }
 
-void RecordDecodeRemovalsResult(V4DecodeResult result) {
-  UMA_HISTOGRAM_ENUMERATION("SafeBrowsing.V4DecodeRemovalsResult", result,
-                            DECODE_RESULT_MAX);
+void RecordDecodeRemovalsResult(const std::string& base_metric,
+                                V4DecodeResult result,
+                                const base::FilePath& file_path) {
+  RecordEnumWithAndWithoutSuffix(base_metric + kDecodeRemovals, result,
+                                 DECODE_RESULT_MAX, file_path);
 }
 
-void RecordDecodeRemovalsTime(base::TimeDelta time,
+void RecordDecodeRemovalsTime(const std::string& base_metric,
+                              base::TimeDelta time,
                               const base::FilePath& file_path) {
-  RecordTimeWithAndWithoutStore("SafeBrowsing.V4DecodeRemovalsTime", time,
-                                file_path);
+  RecordTimeWithAndWithoutSuffix(base_metric + kDecodeRemovals, time,
+                                 file_path);
 }
 
-void RecordMergeUpdateTime(base::TimeDelta time,
+void RecordMergeUpdateTime(const std::string& base_metric,
+                           base::TimeDelta time,
                            const base::FilePath& file_path) {
-  RecordTimeWithAndWithoutStore("SafeBrowsing.V4MergeUpdateTime", time,
-                                file_path);
-}
-
-void RecordProcessFullUpdateTime(base::TimeDelta time,
-                                 const base::FilePath& file_path) {
-  RecordTimeWithAndWithoutStore("SafeBrowsing.V4ProcessFullUpdateTime", time,
-                                file_path);
-}
-
-void RecordProcessPartialUpdateTime(base::TimeDelta time,
-                                    const base::FilePath& file_path) {
-  RecordTimeWithAndWithoutStore("SafeBrowsing.V4ProcessPartialUpdateTime", time,
-                                file_path);
-}
-
-void RecordReadFromDiskTime(base::TimeDelta time,
-                            const base::FilePath& file_path) {
-  RecordTimeWithAndWithoutStore("SafeBrowsing.V4ReadFromDiskTime", time,
-                                file_path);
+  RecordTimeWithAndWithoutSuffix(base_metric + kMergeUpdate, time, file_path);
 }
 
 void RecordStoreReadResult(StoreReadResult result) {
-  UMA_HISTOGRAM_ENUMERATION("SafeBrowsing.V4StoreReadResult", result,
+  UMA_HISTOGRAM_ENUMERATION("SafeBrowsing.V4StoreRead.Result", result,
                             STORE_READ_RESULT_MAX);
 }
 
 void RecordStoreWriteResult(StoreWriteResult result) {
-  UMA_HISTOGRAM_ENUMERATION("SafeBrowsing.V4StoreWriteResult", result,
+  UMA_HISTOGRAM_ENUMERATION("SafeBrowsing.V4StoreWrite.Result", result,
                             STORE_WRITE_RESULT_MAX);
 }
 
@@ -182,33 +211,29 @@ void V4Store::Reset() {
 }
 
 ApplyUpdateResult V4Store::ProcessPartialUpdateAndWriteToDisk(
+    const std::string& metric,
     const HashPrefixMap& hash_prefix_map_old,
     std::unique_ptr<ListUpdateResponse> response) {
   DCHECK(response->has_response_type());
   DCHECK_EQ(ListUpdateResponse::PARTIAL_UPDATE, response->response_type());
 
-  TimeTicks before = TimeTicks::Now();
-  ApplyUpdateResult result = ProcessUpdate(hash_prefix_map_old, response);
-  if (result == APPLY_UPDATE_SUCCESS) {
-    RecordProcessPartialUpdateTime(TimeTicks::Now() - before, store_path_);
-    // TODO(vakh): Create a ListUpdateResponse containing RICE encoded
-    // hash prefixes and response_type as FULL_UPDATE, and write that to disk.
-  }
+  ApplyUpdateResult result =
+      ProcessUpdate(metric, hash_prefix_map_old, response);
   return result;
 }
 
 ApplyUpdateResult V4Store::ProcessFullUpdateAndWriteToDisk(
+    const std::string& metric,
     std::unique_ptr<ListUpdateResponse> response) {
-  TimeTicks before = TimeTicks::Now();
-  ApplyUpdateResult result = ProcessFullUpdate(response);
+  ApplyUpdateResult result = ProcessFullUpdate(metric, response);
   if (result == APPLY_UPDATE_SUCCESS) {
-    RecordProcessFullUpdateTime(TimeTicks::Now() - before, store_path_);
     RecordStoreWriteResult(WriteToDisk(std::move(response)));
   }
   return result;
 }
 
 ApplyUpdateResult V4Store::ProcessFullUpdate(
+    const std::string& metric,
     const std::unique_ptr<ListUpdateResponse>& response) {
   DCHECK(response->has_response_type());
   DCHECK_EQ(ListUpdateResponse::FULL_UPDATE, response->response_type());
@@ -217,10 +242,11 @@ ApplyUpdateResult V4Store::ProcessFullUpdate(
   // checksum. It might save some CPU cycles to store the full update as-is and
   // walk the list of hash prefixes in lexographical order only for checksum
   // calculation.
-  return ProcessUpdate(HashPrefixMap(), response);
+  return ProcessUpdate(metric, HashPrefixMap(), response);
 }
 
 ApplyUpdateResult V4Store::ProcessUpdate(
+    const std::string& metric,
     const HashPrefixMap& hash_prefix_map_old,
     const std::unique_ptr<ListUpdateResponse>& response) {
   const RepeatedField<int32>* raw_removals = nullptr;
@@ -242,11 +268,11 @@ ApplyUpdateResult V4Store::ProcessUpdate(
           rice_indices.num_entries(), rice_indices.encoded_data(),
           &rice_removals);
 
-      RecordDecodeRemovalsResult(decode_result);
+      RecordDecodeRemovalsResult(metric, decode_result, store_path_);
       if (decode_result != DECODE_SUCCESS) {
         return RICE_DECODING_FAILURE;
       }
-      RecordDecodeRemovalsTime(TimeTicks::Now() - before, store_path_);
+      RecordDecodeRemovalsTime(metric, TimeTicks::Now() - before, store_path_);
       raw_removals = &rice_removals;
     } else {
       NOTREACHED() << "Unexpected compression_type type: " << compression_type;
@@ -255,8 +281,8 @@ ApplyUpdateResult V4Store::ProcessUpdate(
   }
 
   HashPrefixMap hash_prefix_map;
-  ApplyUpdateResult apply_update_result =
-      UpdateHashPrefixMapFromAdditions(response->additions(), &hash_prefix_map);
+  ApplyUpdateResult apply_update_result = UpdateHashPrefixMapFromAdditions(
+      metric, response->additions(), &hash_prefix_map);
   if (apply_update_result != APPLY_UPDATE_SUCCESS) {
     return apply_update_result;
   }
@@ -272,7 +298,7 @@ ApplyUpdateResult V4Store::ProcessUpdate(
   if (apply_update_result != APPLY_UPDATE_SUCCESS) {
     return apply_update_result;
   }
-  RecordMergeUpdateTime(TimeTicks::Now() - before, store_path_);
+  RecordMergeUpdateTime(metric, TimeTicks::Now() - before, store_path_);
 
   state_ = response->new_client_state();
   return APPLY_UPDATE_SUCCESS;
@@ -282,15 +308,18 @@ void V4Store::ApplyUpdate(
     std::unique_ptr<ListUpdateResponse> response,
     const scoped_refptr<base::SingleThreadTaskRunner>& callback_task_runner,
     UpdatedStoreReadyCallback callback) {
-  std::unique_ptr<V4Store> new_store(
-      new V4Store(this->task_runner_, this->store_path_));
+  std::unique_ptr<V4Store> new_store(new V4Store(task_runner_, store_path_));
   ApplyUpdateResult apply_update_result;
+  std::string metric;
+  TimeTicks before = TimeTicks::Now();
   if (response->response_type() == ListUpdateResponse::PARTIAL_UPDATE) {
+    metric = kProcessPartialUpdate;
     apply_update_result = new_store->ProcessPartialUpdateAndWriteToDisk(
-        hash_prefix_map_, std::move(response));
+        metric, hash_prefix_map_, std::move(response));
   } else if (response->response_type() == ListUpdateResponse::FULL_UPDATE) {
+    metric = kProcessFullUpdate;
     apply_update_result =
-        new_store->ProcessFullUpdateAndWriteToDisk(std::move(response));
+        new_store->ProcessFullUpdateAndWriteToDisk(metric, std::move(response));
   } else {
     apply_update_result = UNEXPECTED_RESPONSE_TYPE_FAILURE;
     NOTREACHED() << "Failure: Unexpected response type: "
@@ -298,6 +327,7 @@ void V4Store::ApplyUpdate(
   }
 
   if (apply_update_result == APPLY_UPDATE_SUCCESS) {
+    RecordApplyUpdateTime(metric, TimeTicks::Now() - before, store_path_);
     // new_store is done updating, pass it to the callback.
     callback_task_runner->PostTask(
         FROM_HERE, base::Bind(callback, base::Passed(&new_store)));
@@ -308,10 +338,11 @@ void V4Store::ApplyUpdate(
     callback_task_runner->PostTask(FROM_HERE, base::Bind(callback, nullptr));
   }
 
-  RecordApplyUpdateResult(apply_update_result);
+  RecordApplyUpdateResult(metric, apply_update_result, store_path_);
 }
 
 ApplyUpdateResult V4Store::UpdateHashPrefixMapFromAdditions(
+    const std::string& metric,
     const RepeatedPtrField<ThreatEntrySet>& additions,
     HashPrefixMap* additions_map) {
   for (const auto& addition : additions) {
@@ -333,11 +364,12 @@ ApplyUpdateResult V4Store::UpdateHashPrefixMapFromAdditions(
       V4DecodeResult decode_result = V4RiceDecoder::DecodePrefixes(
           rice_hashes.first_value(), rice_hashes.rice_parameter(),
           rice_hashes.num_entries(), rice_hashes.encoded_data(), &raw_hashes);
-      RecordDecodeAdditionsResult(decode_result);
+      RecordDecodeAdditionsResult(metric, decode_result, store_path_);
       if (decode_result != DECODE_SUCCESS) {
         return RICE_DECODING_FAILURE;
       } else {
-        RecordDecodeAdditionsTime(TimeTicks::Now() - before, store_path_);
+        RecordDecodeAdditionsTime(metric, TimeTicks::Now() - before,
+                                  store_path_);
         char* raw_hashes_start = reinterpret_cast<char*>(raw_hashes.data());
         size_t raw_hashes_size = sizeof(uint32_t) * raw_hashes.size();
 
@@ -627,13 +659,14 @@ StoreReadResult V4Store::ReadFromDisk() {
 
   std::unique_ptr<ListUpdateResponse> response(new ListUpdateResponse);
   response->Swap(file_format.mutable_list_update_response());
-  ApplyUpdateResult apply_update_result = ProcessFullUpdate(response);
-  RecordApplyUpdateResultWhenReadingFromDisk(apply_update_result);
+  ApplyUpdateResult apply_update_result =
+      ProcessFullUpdate(kReadFromDisk, response);
+  RecordApplyUpdateResult(kReadFromDisk, apply_update_result, store_path_);
   if (apply_update_result != APPLY_UPDATE_SUCCESS) {
     hash_prefix_map_.clear();
     return HASH_PREFIX_MAP_GENERATION_FAILURE;
   }
-  RecordReadFromDiskTime(TimeTicks::Now() - before, store_path_);
+  RecordApplyUpdateTime(kReadFromDisk, TimeTicks::Now() - before, store_path_);
 
   return READ_SUCCESS;
 }
@@ -750,7 +783,8 @@ bool V4Store::VerifyChecksum() {
   checksum_ctx->Finish(checksum, sizeof(checksum));
   for (size_t i = 0; i < crypto::kSHA256Length; i++) {
     if (checksum[i] != expected_checksum_[i]) {
-      RecordApplyUpdateResultWhenReadingFromDisk(CHECKSUM_MISMATCH_FAILURE);
+      RecordApplyUpdateResult(kReadFromDisk, CHECKSUM_MISMATCH_FAILURE,
+                              store_path_);
 #if DCHECK_IS_ON()
       std::string checksum_b64, expected_checksum_b64;
       base::Base64Encode(base::StringPiece(checksum, arraysize(checksum)),