Add UMA histograms for each operation in ResourceCache.

This should help to understand perfomance of ResourceCache operations.

Bug: 807068
Change-Id: I58b5c0da38b46c9497a3a878327a25dca58b5995
Reviewed-on: https://chromium-review.googlesource.com/c/1296489
Commit-Queue: Nikita Podguzov <nikitapodguzov@google.com>
Reviewed-by: Sergey Poromov <poromov@chromium.org>
Reviewed-by: Jesse Doherty <jwd@chromium.org>
Reviewed-by: Maksim Ivanov <emaxx@chromium.org>
Reviewed-by: Sean Kau <skau@chromium.org>
Cr-Commit-Position: refs/heads/master@{#605648}

components/policy/core/common/cloud/resource_cache.cc

@@ -11,6 +11,7 @@
 #include "base/files/file_path.h"
 #include "base/files/file_util.h"
 #include "base/logging.h"
+#include "base/metrics/histogram_macros.h"
 #include "base/numerics/safe_conversions.h"
 #include "base/sequenced_task_runner.h"
 
@@ -65,6 +66,7 @@ bool ResourceCache::Store(const std::string& key,
                           const std::string& subkey,
                           const std::string& data) {
   DCHECK(task_runner_->RunsTasksInCurrentSequence());
+  SCOPED_UMA_HISTOGRAM_TIMER("Enterprise.ResourceCacheTiming.Store");
   base::FilePath subkey_path;
   if (!VerifyKeyPathAndGetSubkeyPath(key, true, subkey, &subkey_path))
     return false;
@@ -84,6 +86,7 @@ bool ResourceCache::Load(const std::string& key,
                          const std::string& subkey,
                          std::string* data) {
   DCHECK(task_runner_->RunsTasksInCurrentSequence());
+  SCOPED_UMA_HISTOGRAM_TIMER("Enterprise.ResourceCacheTiming.Load");
   base::FilePath subkey_path;
   // Only read from |subkey_path| if it is not a symlink.
   if (!VerifyKeyPathAndGetSubkeyPath(key, false, subkey, &subkey_path) ||
@@ -98,6 +101,7 @@ void ResourceCache::LoadAllSubkeys(
     const std::string& key,
     std::map<std::string, std::string>* contents) {
   DCHECK(task_runner_->RunsTasksInCurrentSequence());
+  SCOPED_UMA_HISTOGRAM_TIMER("Enterprise.ResourceCacheTiming.LoadAllSubkeys");
   contents->clear();
   base::FilePath key_path;
   if (!VerifyKeyPath(key, false, &key_path))
@@ -123,6 +127,7 @@ void ResourceCache::LoadAllSubkeys(
 
 void ResourceCache::Delete(const std::string& key, const std::string& subkey) {
   DCHECK(task_runner_->RunsTasksInCurrentSequence());
+  SCOPED_UMA_HISTOGRAM_TIMER("Enterprise.ResourceCacheTiming.Delete");
   base::FilePath subkey_path;
   if (VerifyKeyPathAndGetSubkeyPath(key, false, subkey, &subkey_path))
     DeleteCacheFile(subkey_path, false);
@@ -136,6 +141,7 @@ void ResourceCache::Delete(const std::string& key, const std::string& subkey) {
 
 void ResourceCache::Clear(const std::string& key) {
   DCHECK(task_runner_->RunsTasksInCurrentSequence());
+  SCOPED_UMA_HISTOGRAM_TIMER("Enterprise.ResourceCacheTiming.Clear");
   base::FilePath key_path;
   if (VerifyKeyPath(key, false, &key_path))
     DeleteCacheFile(key_path, true);
@@ -144,6 +150,7 @@ void ResourceCache::Clear(const std::string& key) {
 void ResourceCache::FilterSubkeys(const std::string& key,
                                   const SubkeyFilter& test) {
   DCHECK(task_runner_->RunsTasksInCurrentSequence());
+  SCOPED_UMA_HISTOGRAM_TIMER("Enterprise.ResourceCacheTiming.FilterSubkeys");
 
   base::FilePath key_path;
   if (!VerifyKeyPath(key, false, &key_path))
@@ -171,6 +178,7 @@ void ResourceCache::FilterSubkeys(const std::string& key,
 
 void ResourceCache::PurgeOtherKeys(const std::set<std::string>& keys_to_keep) {
   DCHECK(task_runner_->RunsTasksInCurrentSequence());
+  SCOPED_UMA_HISTOGRAM_TIMER("Enterprise.ResourceCacheTiming.PurgeOtherKeys");
   std::set<std::string> encoded_keys_to_keep;
   if (!Base64UrlEncode(keys_to_keep, &encoded_keys_to_keep))
     return;
@@ -189,6 +197,8 @@ void ResourceCache::PurgeOtherSubkeys(
     const std::string& key,
     const std::set<std::string>& subkeys_to_keep) {
   DCHECK(task_runner_->RunsTasksInCurrentSequence());
+  SCOPED_UMA_HISTOGRAM_TIMER(
+      "Enterprise.ResourceCacheTiming.PurgeOtherSubkeys");
   base::FilePath key_path;
   if (!VerifyKeyPath(key, false, &key_path))
     return;
@@ -250,6 +260,7 @@ bool ResourceCache::VerifyKeyPathAndGetSubkeyPath(const std::string& key,
 
 void ResourceCache::InitCurrentCacheSize() {
   DCHECK(task_runner_->RunsTasksInCurrentSequence());
+  SCOPED_UMA_HISTOGRAM_TIMER("Enterprise.ResourceCacheTiming.Init");
   current_cache_size_ = GetCacheDirectoryOrFileSize(cache_dir_);
 }
 

tools/metrics/histograms/histograms.xml

@@ -25732,6 +25732,11 @@ uploading your change for review.
   </summary>
 </histogram>
 
+<histogram name="Enterprise.ResourceCacheTiming" units="ms">
+  <owner>nikitapodguzov@chromium.org</owner>
+  <summary>The time to perform operations on the ResourceCache object.</summary>
+</histogram>
+
 <histogram base="true" name="Enterprise.RetrievePolicyResponse"
     enum="EnterpriseRetrievePolicyResponseType">
 <!-- Name completed by histogram_suffixes name="EnterpriseRetrievePolicyResponse" -->
@@ -127278,6 +127283,37 @@ uploading your change for review.
   <affected-histogram name="SiteEngagementService.EngagementScoreBucket"/>
 </histogram_suffixes>
 
+<histogram_suffixes name="Enterprise.ResourceCacheTiming" separator=".">
+  <suffix name="Clear"
+      label="The time to perform the 'clear' operation on a ResourceCache,
+             which deletes all subkeys of given key."/>
+  <suffix name="Delete"
+      label="The time to perform the 'delete' operation on a ResourceCache,
+             which deletes given subkey."/>
+  <suffix name="FilterSubkeys"
+      label="The time to perform the 'filterSubkeys' operation on a
+             ResourceCache, which deletes filtered subkeys of given key."/>
+  <suffix name="Init"
+      label="The time to perform the initialization of a ResourceCache."/>
+  <suffix name="Load"
+      label="The time to perform the 'load' operation on a ResourceCache,
+             which loads the content of given key."/>
+  <suffix name="LoadAllSubkeys"
+      label="The time to perform the 'loadAllSubkeys' operation on a
+             ResourceCache, which loads the content of all subkeys of given
+             key."/>
+  <suffix name="PurgeOtherKeys"
+      label="The time to perform the 'purgeOtherKeys' operation on a
+             ResourceCache, which deletes all keys except given."/>
+  <suffix name="PurgeOtherSubkeys"
+      label="The time to perform the 'purgeOtherSubkeys' operation on a
+             ResourceCache, which deletes all subkeys except given."/>
+  <suffix name="Store"
+      label="The time to perform the 'store' operation on a ResourceCache,
+             which stores data under given key."/>
+  <affected-histogram name="Enterprise.ResourceCacheTiming"/>
+</histogram_suffixes>
+
 <histogram_suffixes name="EnterpriseAutoEnrollmentType" separator=".">
   <suffix name="ForcedReenrollment" label="Forced Re-Enrollment"/>
   <suffix name="InitialEnrollment" label="Initial Enrollment Exchange"/>