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

chrome/browser/extensions/extension_protocols.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "chrome/browser/extensions/extension_protocols.h"
 
 #include <algorithm>
 
 #include "base/base64.h"
 #include "base/compiler_specific.h"
 #include "base/file_util.h"
 #include "base/files/file_path.h"
 #include "base/format_macros.h"
 #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"
 #include "base/strings/string_number_conversions.h"
 #include "base/strings/string_util.h"
 #include "base/strings/stringprintf.h"
 #include "base/strings/utf_string_conversions.h"
 #include "base/threading/sequenced_worker_pool.h"
 #include "base/threading/thread_restrictions.h"
 #include "base/timer/elapsed_timer.h"
 #include "build/build_config.h"
 #include "chrome/browser/extensions/extension_renderer_state.h"
 #include "chrome/browser/extensions/image_loader.h"
 #include "chrome/common/chrome_paths.h"
 #include "chrome/common/extensions/manifest_handlers/icons_handler.h"
 #include "chrome/common/extensions/manifest_url_handler.h"
 #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"
 #include "extensions/common/extension_resource.h"
 #include "extensions/common/file_util.h"
 #include "extensions/common/manifest_handlers/background_info.h"
 #include "extensions/common/manifest_handlers/csp_info.h"
 #include "extensions/common/manifest_handlers/incognito_info.h"
 #include "extensions/common/manifest_handlers/shared_module_info.h"
 #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"
 #include "net/http/http_response_headers.h"
 #include "net/http/http_response_info.h"
 #include "net/url_request/url_request_error_job.h"
 #include "net/url_request/url_request_file_job.h"
 #include "net/url_request/url_request_simple_job.h"
 #include "ui/base/resource/resource_bundle.h"
 #include "url/url_util.h"
@@ skipping 220 matching lines @@
 class URLRequestExtensionJob : public net::URLRequestFileJob {
  public:
   URLRequestExtensionJob(net::URLRequest* request,
                          net::NetworkDelegate* network_delegate,
                          const std::string& extension_id,
                          const base::FilePath& directory_path,
                          const base::FilePath& relative_path,
                          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 {
     *info = response_info_;
   }
 
   virtual void Start() OVERRIDE {
     base::FilePath* read_file_path = new base::FilePath;
     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)),
         base::Bind(&URLRequestExtensionJob::OnFilePathAndLastModifiedTimeRead,
                    weak_factory_.GetWeakPtr(),
                    base::Owned(read_file_path),
                    base::Owned(last_modified_time)));
     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) {
     file_path_ = *read_file_path;
     response_info_.headers = BuildHttpHeaders(
         content_security_policy_,
         send_cors_header_,
         *last_modified_time);
     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_;
   std::string content_security_policy_;
   bool send_cors_header_;
   base::WeakPtrFactory<URLRequestExtensionJob> weak_factory_;
 };
 
 bool ExtensionCanLoadInIncognito(const ResourceRequestInfo* info,
                                  const std::string& extension_id,
@@ skipping 289 matching lines @@
                                     follow_symlinks_anywhere);
 }
 
 }  // namespace
 
 net::URLRequestJobFactory::ProtocolHandler* CreateExtensionProtocolHandler(
     Profile::ProfileType profile_type,
     extensions::InfoMap* extension_info_map) {
   return new ExtensionProtocolHandler(profile_type, extension_info_map);
 }