Adding DiskBasedCertCache to HttpCache (+UMA).

net/http/http_cache_transaction.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 "net/http/http_cache_transaction.h"
 
 #include "build/build_config.h"
 
 #if defined(OS_POSIX)
 #include <unistd.h>
@@ skipping 14 matching lines @@
 #include "base/time/time.h"
 #include "net/base/completion_callback.h"
 #include "net/base/io_buffer.h"
 #include "net/base/load_flags.h"
 #include "net/base/load_timing_info.h"
 #include "net/base/net_errors.h"
 #include "net/base/net_log.h"
 #include "net/base/upload_data_stream.h"
 #include "net/cert/cert_status_flags.h"
 #include "net/disk_cache/disk_cache.h"
+#include "net/http/disk_based_cert_cache.h"
 #include "net/http/http_network_session.h"
 #include "net/http/http_request_info.h"
 #include "net/http/http_response_headers.h"
 #include "net/http/http_transaction.h"
 #include "net/http/http_util.h"
 #include "net/http/partial_data.h"
 #include "net/ssl/ssl_cert_request_info.h"
 #include "net/ssl/ssl_config_service.h"
 
 using base::Time;
 using base::TimeDelta;
 using base::TimeTicks;
 
 namespace {
 
+// Stores data relevant to the statistics of writing and reading entire
+// certificate chains using DiskBasedCertCache. |num_pending_ops| is the number
+// of certificates in the chain that have pending operations in the
+// DiskBasedCertCache. |start_time| is the time that the read and write
+// commands began being issued to the DiskBasedCertCache.
+// TODO(brandonsalmon): Remove this when it is no longer necessary to
+// collect data.
+class SharedChainData : public base::RefCounted<SharedChainData> {
+ public:
+  SharedChainData(int num_ops, TimeTicks start)
+      : num_pending_ops(num_ops), start_time(start) {}
+
+  int num_pending_ops;
+  TimeTicks start_time;
+
+ private:
+  friend class base::RefCounted<SharedChainData>;
+  ~SharedChainData() {}
+  DISALLOW_COPY_AND_ASSIGN(SharedChainData);
+};
+
+// Used to obtain a cache entry key for an OSCertHandle.
+// TODO(brandonsalmon): Remove this when cache keys are stored
+// and no longer have to be recomputed to retrieve the OSCertHandle
+// from the disk.
+std::string GetCacheKeyForCert(net::X509Certificate::OSCertHandle cert_handle) {
+  net::SHA1HashValue fingerprint =
+      net::X509Certificate::CalculateFingerprint(cert_handle);
+
+  return "cert:" +
+         base::HexEncode(fingerprint.data, arraysize(fingerprint.data));
+}
+
+// |dist_from_root| indicates the position of the read certificate in the
+// certificate chain, 0 indicating it is the root. |is_leaf| indicates
+// whether or not the read certificate was the leaf of the chain.
+// |shared_chain_data| contains data shared by each certificate in
+// the chain.
+void OnCertReadIOComplete(
+    int dist_from_root,
+    bool is_leaf,
+    const scoped_refptr<SharedChainData>& shared_chain_data,
+    net::X509Certificate::OSCertHandle cert_handle) {
+  // If |num_pending_ops| is one, this was the last pending read operation
+  // for this chain of certificates. The total time used to read the chain
+  // can be calculated by subtracting the starting time from Now().
+  shared_chain_data->num_pending_ops--;
+  if (!shared_chain_data->num_pending_ops) {
+    const TimeDelta read_chain_wait =
+        TimeTicks::Now() - shared_chain_data->start_time;
+    UMA_HISTOGRAM_CUSTOM_TIMES("DiskBasedCertCache.ChainReadTime",

[wtc, 2014/07/10 18:42:21]

Should this histogram name also use the "CertIo" prefix?

[brandonsalmon, 2014/07/10 19:00:13]

It was my intention that "Chain" would become a different prefix here, to record
statistics specific to certificate chains. Although I only have the histograms
for timing right now.

+                               read_chain_wait,
+                               base::TimeDelta::FromMilliseconds(1),
+                               base::TimeDelta::FromMinutes(10),
+                               50);
+  }
+
+  bool success = (cert_handle != NULL);
+  if (is_leaf)
+    UMA_HISTOGRAM_BOOLEAN("DiskBasedCertCache.CertIoReadSuccessLeaf", success);

[wtc, 2014/07/10 18:42:21]

IMPORTANT: should we return here? Otherwise the results of leaf certificates
will be recorded in histograms below.

What you do is reasonable. I just wanted to make sure it was a deliberate
decision rather than an oversight.

[brandonsalmon, 2014/07/10 19:00:13]

I did this because it didn't make sense to me to record the root but not the
leaf. I agree that it could be better to return here and not record the leaf,
but I don't see the reason why.

One other possibility would be to add a different histogram to measure the
length of certificate chains (as this would tell us the position of the leaf).

+
+  if (success)
+    UMA_HISTOGRAM_CUSTOM_COUNTS(
+        "DiskBasedCertCache.CertIoReadSuccess", dist_from_root, 0, 10, 7);
+  else
+    UMA_HISTOGRAM_CUSTOM_COUNTS(
+        "DiskBasedCertCache.CertIoReadFailure", dist_from_root, 0, 10, 7);

[wtc, 2014/07/10 18:42:21]

Nit: use curly braces because the bodies of the if and else branch are two lines
(even though they are single statements).

+}
+
+// |dist_from_root| indicates the position of the written certificate in the
+// certificate chain, 0 indicating it is the root. |is_leaf| indicates
+// whether or not the written certificate was the leaf of the chain.
+// |shared_chain_data| contains data shared by each certificate in
+// the chain.
+void OnCertWriteIOComplete(
+    int dist_from_root,
+    bool is_leaf,
+    const scoped_refptr<SharedChainData>& shared_chain_data,
+    const std::string& key) {
+  // If |num_pending_ops| is one, this was the last pending write operation
+  // for this chain of certificates. The total time used to write the chain
+  // can be calculated by subtracting the starting time from Now().
+  shared_chain_data->num_pending_ops--;
+  if (!shared_chain_data->num_pending_ops) {
+    const TimeDelta write_chain_wait =
+        TimeTicks::Now() - shared_chain_data->start_time;
+    UMA_HISTOGRAM_CUSTOM_TIMES("DiskBasedCertCache.ChainWriteTime",
+                               write_chain_wait,
+                               base::TimeDelta::FromMilliseconds(1),
+                               base::TimeDelta::FromMinutes(10),
+                               50);
+  }
+
+  bool success = !key.empty();
+  if (is_leaf)
+    UMA_HISTOGRAM_BOOLEAN("DiskBasedCertCache.CertIoWriteSuccessLeaf", success);
+
+  if (success)
+    UMA_HISTOGRAM_CUSTOM_COUNTS(
+        "DiskBasedCertCache.CertIoWriteSuccess", dist_from_root, 0, 10, 7);
+  else
+    UMA_HISTOGRAM_CUSTOM_COUNTS(
+        "DiskBasedCertCache.CertIoWriteFailure", dist_from_root, 0, 10, 7);
+}
+
 // From http://tools.ietf.org/html/draft-ietf-httpbis-p6-cache-21#section-6
 //      a "non-error response" is one with a 2xx (Successful) or 3xx
 //      (Redirection) status code.
 bool NonErrorResponse(int status_code) {
   int status_code_range = status_code / 100;
   return status_code_range == 2 || status_code_range == 3;
 }
 
 // Error codes that will be considered indicative of a page being offline/
 // unreachable for LOAD_FROM_CACHE_IF_OFFLINE.
@@ skipping 1428 matching lines @@
 }
 
 int HttpCache::Transaction::DoCacheReadResponseComplete(int result) {
   net_log_.EndEventWithNetErrorCode(NetLog::TYPE_HTTP_CACHE_READ_INFO, result);
   if (result != io_buf_len_ ||
       !HttpCache::ParseResponseInfo(read_buf_->data(), io_buf_len_,
                                     &response_, &truncated_)) {
     return OnCacheReadError(result, true);
   }
 
+  // cert_cache() will be null if the CertCacheTrial field trial is disabled.
+  if (cache_->cert_cache() && response_.ssl_info.is_valid())
+    ReadCertChain();
+
   // Some resources may have slipped in as truncated when they're not.
   int current_size = entry_->disk_entry->GetDataSize(kResponseContentIndex);
   if (response_.headers->GetContentLength() == current_size)
     truncated_ = false;
 
   // We now have access to the cache entry.
   //
   //  o if we are a reader for the transaction, then we can start reading the
   //    cache entry.
   //
@@ skipping 192 matching lines @@
     if (done_reading_ || !entry_ || partial_.get() ||
         response_.headers->GetContentLength() <= 0)
       DoneWritingToEntry(true);
   }
 
   return result;
 }
 
 //-----------------------------------------------------------------------------
 
+void HttpCache::Transaction::ReadCertChain() {
+  std::string key =
+      GetCacheKeyForCert(response_.ssl_info.cert->os_cert_handle());
+  const X509Certificate::OSCertHandles& intermediates =
+      response_.ssl_info.cert->GetIntermediateCertificates();
+  int dist_from_root = intermediates.size();
+
+  scoped_refptr<SharedChainData> shared_chain_data(
+      new SharedChainData(intermediates.size() + 1, TimeTicks::Now()));
+  cache_->cert_cache()->Get(key,
+                            base::Bind(&OnCertReadIOComplete,
+                                       dist_from_root,
+                                       true /* is leaf */,
+                                       shared_chain_data));
+
+  for (X509Certificate::OSCertHandles::const_iterator it =
+           intermediates.begin();
+       it != intermediates.end();
+       ++it) {
+    --dist_from_root;
+    key = GetCacheKeyForCert(*it);
+    cache_->cert_cache()->Get(key,
+                              base::Bind(&OnCertReadIOComplete,
+                                         dist_from_root,
+                                         false /* is not leaf */,
+                                         shared_chain_data));
+  }
+  DCHECK_EQ(0, dist_from_root);
+}
+
+void HttpCache::Transaction::WriteCertChain() {
+  const X509Certificate::OSCertHandles& intermediates =
+      response_.ssl_info.cert->GetIntermediateCertificates();
+  int dist_from_root = intermediates.size();
+
+  scoped_refptr<SharedChainData> shared_chain_data(
+      new SharedChainData(intermediates.size() + 1, TimeTicks::Now()));
+  cache_->cert_cache()->Set(response_.ssl_info.cert->os_cert_handle(),
+                            base::Bind(&OnCertWriteIOComplete,
+                                       dist_from_root,
+                                       true /* is leaf */,
+                                       shared_chain_data));
+  for (X509Certificate::OSCertHandles::const_iterator it =
+           intermediates.begin();
+       it != intermediates.end();
+       ++it) {
+    --dist_from_root;
+    cache_->cert_cache()->Set(*it,
+                              base::Bind(&OnCertWriteIOComplete,
+                                         dist_from_root,
+                                         false /* is not leaf */,
+                                         shared_chain_data));
+  }
+  DCHECK_EQ(0, dist_from_root);
+}
+
 void HttpCache::Transaction::SetRequest(const BoundNetLog& net_log,
                                         const HttpRequestInfo* request) {
   net_log_ = net_log;
   request_ = request;
   effective_load_flags_ = request_->load_flags;
 
   switch (cache_->mode()) {
     case NORMAL:
       break;
     case RECORD:
@@ skipping 600 matching lines @@
   // reverse-map the cert status to a net error and replay the net error.
   if ((cache_->mode() != RECORD &&
        response_.headers->HasHeaderValue("cache-control", "no-store")) ||
       net::IsCertStatusError(response_.ssl_info.cert_status)) {
     DoneWritingToEntry(false);
     if (net_log_.IsLogging())
       net_log_.EndEvent(NetLog::TYPE_HTTP_CACHE_WRITE_INFO);
     return OK;
   }
 
+  // cert_cache() will be null if the CertCacheTrial field trial is disabled.
+  if (cache_->cert_cache() && response_.ssl_info.is_valid())
+    WriteCertChain();
+
   // When writing headers, we normally only write the non-transient
   // headers; when in record mode, record everything.
   bool skip_transient_headers = (cache_->mode() != RECORD);
 
   if (truncated)
     DCHECK_EQ(200, response_.headers->response_code());
 
   scoped_refptr<PickledIOBuffer> data(new PickledIOBuffer());
   response_.Persist(data->pickle(), skip_transient_headers, truncated);
   data->Done();
@@ skipping 236 matching lines @@
     default:
       NOTREACHED();
   }
 }
 
 void HttpCache::Transaction::OnIOComplete(int result) {
   DoLoop(result);
 }
 
 }  // namespace net