Add experiment to measure time to hash extension content as we read it

chrome/browser/extensions/extension_protocols.cc

Index: chrome/browser/extensions/extension_protocols.cc
diff --git a/chrome/browser/extensions/extension_protocols.cc b/chrome/browser/extensions/extension_protocols.cc
index e3e9865cb89f808ed4bd5c33ea136bf0525567ce..7efb81b98d66b76219a939a0e420a0337f83097d 100644
--- a/chrome/browser/extensions/extension_protocols.cc
+++ b/chrome/browser/extensions/extension_protocols.cc
@@ -14,6 +14,7 @@
 #include "base/logging.h"
 #include "base/memory/weak_ptr.h"
 #include "base/message_loop/message_loop.h"
+#include "base/metrics/field_trial.h"
 #include "base/metrics/histogram.h"
 #include "base/path_service.h"
 #include "base/sha1.h"
@@ -33,6 +34,8 @@
 #include "chrome/common/url_constants.h"
 #include "content/public/browser/browser_thread.h"
 #include "content/public/browser/resource_request_info.h"
+#include "crypto/secure_hash.h"
+#include "crypto/sha2.h"
 #include "extensions/browser/info_map.h"
 #include "extensions/common/constants.h"
 #include "extensions/common/extension.h"
@@ -45,6 +48,7 @@
 #include "extensions/common/manifest_handlers/web_accessible_resources_info.h"
 #include "extensions/common/manifest_handlers/webview_info.h"
 #include "grit/component_extension_resources_map.h"
+#include "net/base/io_buffer.h"
 #include "net/base/mime_util.h"
 #include "net/base/net_errors.h"
 #include "net/http/http_request_headers.h"
@@ -285,20 +289,31 @@ class URLRequestExtensionJob : public net::URLRequestFileJob {
                          const std::string& content_security_policy,
                          bool send_cors_header,
                          bool follow_symlinks_anywhere)
-    : net::URLRequestFileJob(
-          request, network_delegate, base::FilePath(),
-          BrowserThread::GetBlockingPool()->GetTaskRunnerWithShutdownBehavior(
-                  base::SequencedWorkerPool::SKIP_ON_SHUTDOWN)),
-      directory_path_(directory_path),
-      // TODO(tc): Move all of these files into resources.pak so we don't break
-      // when updating on Linux.
-      resource_(extension_id, directory_path, relative_path),
-      content_security_policy_(content_security_policy),
-      send_cors_header_(send_cors_header),
-      weak_factory_(this) {
+      : net::URLRequestFileJob(
+            request,
+            network_delegate,
+            base::FilePath(),
+            BrowserThread::GetBlockingPool()->GetTaskRunnerWithShutdownBehavior(
+                base::SequencedWorkerPool::SKIP_ON_SHUTDOWN)),
+        seek_position_(0),
+        bytes_read_(0),
+        directory_path_(directory_path),
+        // TODO(tc): Move all of these files into resources.pak so we don't
+        // break when updating on Linux.
+        resource_(extension_id, directory_path, relative_path),
+        content_security_policy_(content_security_policy),
+        send_cors_header_(send_cors_header),
+        weak_factory_(this) {
     if (follow_symlinks_anywhere) {
       resource_.set_follow_symlinks_anywhere();
     }
+    const std::string& group =
+        base::FieldTrialList::FindFullName("ExtensionContentHashMeasurement");
+    if (group == "Yes") {
+      base::ElapsedTimer timer;
+      hash_.reset(crypto::SecureHash::Create(crypto::SecureHash::SHA256));
+      hashing_time_ += timer.Elapsed();

[rvargas (doing something else), 2014/04/08 16:53:45]

hashing_time_ = 

[asargent_no_longer_on_chrome, 2014/04/09 20:59:59]

Done.

+    }
   }
 
   virtual void GetResponseInfo(net::HttpResponseInfo* info) OVERRIDE {
@@ -310,7 +325,8 @@ class URLRequestExtensionJob : public net::URLRequestFileJob {
     base::Time* last_modified_time = new base::Time();
     bool posted = BrowserThread::PostBlockingPoolTaskAndReply(
         FROM_HERE,
-        base::Bind(&ReadResourceFilePathAndLastModifiedTime, resource_,
+        base::Bind(&ReadResourceFilePathAndLastModifiedTime,
+                   resource_,
                    directory_path_,
                    base::Unretained(read_file_path),
                    base::Unretained(last_modified_time)),
@@ -321,8 +337,36 @@ class URLRequestExtensionJob : public net::URLRequestFileJob {
     DCHECK(posted);
   }
 
+  virtual void OnSeekComplete(int64 result) OVERRIDE {
+    DCHECK_EQ(seek_position_, 0);
+    seek_position_ = result;
+  }
+
+  virtual void OnReadComplete(net::IOBuffer* buffer, int result) OVERRIDE {
+    UMA_HISTOGRAM_COUNTS("ExtensionUrlRequest.OnReadCompleteResult", result);

[rvargas (doing something else), 2014/04/08 16:53:45]

What do you expect to get out of this histogram?

[asargent_no_longer_on_chrome, 2014/04/09 20:59:59]

I'm interested to see the distribution of common read sizes, as that may inform
the block size we pick for signing content hashes. (The
ExtensionUrlRequest.TotalKbRead value below may have more impact on that
decision, but having both numbers seems interesting). 

+    if (result > 0) {
+      bytes_read_ += result;
+      if (hash_.get()) {
+        base::ElapsedTimer timer;
+        hash_->Update(buffer->data(), result);
+        hashing_time_ += timer.Elapsed();
+      }
+    }
+  }
+
  private:
-  virtual ~URLRequestExtensionJob() {}
+  virtual ~URLRequestExtensionJob() {
+    if (hash_.get()) {
+      base::ElapsedTimer timer;
+      std::string hash_bytes(crypto::kSHA256Length, 0);
+      hash_->Finish(string_as_array(&hash_bytes), hash_bytes.size());
+      hashing_time_ += timer.Elapsed();
+      UMA_HISTOGRAM_TIMES("ExtensionUrlRequest.HashTimeMs", hashing_time_);
+    }
+    UMA_HISTOGRAM_COUNTS("ExtensionUrlRequest.TotalKbRead",
+                         bytes_read_ / 1024);
+    UMA_HISTOGRAM_COUNTS("ExtensionUrlRequest.SeekPosition", seek_position_);
+  }
 
   void OnFilePathAndLastModifiedTimeRead(base::FilePath* read_file_path,
                                          base::Time* last_modified_time) {
@@ -334,6 +378,18 @@ class URLRequestExtensionJob : public net::URLRequestFileJob {
     URLRequestFileJob::Start();
   }
 
+  // A hash of the contents we've read from the file.
+  scoped_ptr<crypto::SecureHash> hash_;
+
+  // The position we seeked to in the file.
+  int64 seek_position_;
+
+  // The number of bytes of content we read from the file.
+  int bytes_read_;
+
+  // Used to count the total time it takes to do hashing operations.
+  base::TimeDelta hashing_time_;
+
   net::HttpResponseInfo response_info_;
   base::FilePath directory_path_;
   extensions::ExtensionResource resource_;