Add UMA Precache.Freshness.Prefetch

components/precache/core/precache_database.cc

 // Copyright 2013 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 "components/precache/core/precache_database.h"
 
 #include "base/bind.h"
 #include "base/files/file_path.h"
 #include "base/location.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/single_thread_task_runner.h"
 #include "base/threading/thread_task_runner_handle.h"
 #include "base/time/time.h"
 #include "components/history/core/browser/history_constants.h"
 #include "components/precache/core/proto/unfinished_work.pb.h"
+#include "net/http/http_response_headers.h"
+#include "net/http/http_response_info.h"
 #include "sql/connection.h"
 #include "sql/transaction.h"
 #include "url/gurl.h"
 
 namespace {
 
 // The number of days old that an entry in the precache URL table can be before
 // it is considered "old" and is removed from the table.
 const int kPrecacheHistoryExpiryPeriodDays = 60;
 
@@ skipping 60 matching lines @@
   }
 
   buffered_writes_.push_back(base::Bind(
       &PrecacheURLTable::DeleteAll, base::Unretained(&precache_url_table_)));
   Flush();
 }
 
 void PrecacheDatabase::RecordURLPrefetch(const GURL& url,
                                          const base::TimeDelta& latency,
                                          const base::Time& fetch_time,
-                                         int64_t size,
-                                         bool was_cached) {
+                                         const net::HttpResponseInfo& info,
+                                         int64_t size) {
   UMA_HISTOGRAM_TIMES("Precache.Latency.Prefetch", latency);
 
   if (!IsDatabaseAccessible()) {
     // Don't track anything if unable to access the database.
     return;
   }
 
   if (buffered_urls_.find(url.spec()) != buffered_urls_.end()) {
     // If the URL for this fetch is in the write buffer, then flush the write
     // buffer.
     Flush();
   }
 
-  if (was_cached && !precache_url_table_.HasURL(url)) {
-    // Since the precache came from the cache, and there's no entry in the URL
-    // table for the URL, this means that the resource was already in the cache
-    // because of user browsing. Thus, this precache had no effect, so ignore
-    // it.
+  DCHECK(info.headers) << "The headers are required.";
+  if (info.headers) {
+    UMA_HISTOGRAM_CUSTOM_COUNTS(

[twifkak, 2016/07/18 04:30:35]

Why not UMA_HISTOGRAM_CUSTOM_TIMES?

[jamartin, 2016/07/18 16:29:43]

I could if you really wanted. However, UMA_HISTOGRAM_CUSTOM_TIMES reports in
milliseconds and, given our range and desired resolution, I think it is
misleading to report in milliseconds. Besides, it's going to be a bit confusing
comparing the max-age of the headers (in seconds) against numbers in
milliseconds.

As I learned from rkaplow@, there is no unit conversion. UMA will report
whatever number we provide as-is.

[twifkak, 2016/07/18 23:50:44]

Nah, that's a good enough reason for me.

+        "Precache.Freshness.Prefetch",
+        info.headers->GetFreshnessLifetimes(info.response_time)
+            .freshness.InSeconds(),
+        base::TimeDelta::FromMinutes(1).InSeconds() /* min */,
+        base::TimeDelta::FromHours(36).InSeconds() /* max */,

[twifkak, 2016/07/18 04:30:35]

Obviously a lot of things are going to go in the overflow bucket
(http://httparchive.org/interesting.php#caching). I assume that's intended. :)

Come to think of it, would it be useful to have an UMA of freshness lifetimes
for Precache.Saved resources? That way we could see if we're benefitting 1-year
lifetime resources, or if our pipeline should have a maximum lifetime in
addition to a minimum.

[jamartin, 2016/07/18 16:29:43]

Well, my thought was to mimic the other counter (...TimeSinceLastPrecache) since
both are focused on the range between prefetches.

The kind of question I had in mind was, how frequently do the client need to do
the precaching in order to benefit from X% of the resources?

However, you rightly pointed out that the 95% range is about a year. What about
the following:
  min:  5 min
  max: 1 year

With that, there are 49 points (49.5 ranges) in the first 24h and 78 in the
first 30 days, which should be enough to answer my original question and it will
be more representative of the entire range. Don't you think?

BTW, thanks a lot for the link. I think you shared one to the same domain before
but I forgot, and it is really relevant. I've been thinking on how to compute
these stats internally, but since there seem that the HTTP headers are only in
doc.content.representation, then I'd need to write a small MR, since the Dremel
table does not contain that heavy field.

[twifkak, 2016/07/18 23:50:44]

Yeah, that sounds pretty reasonable.
That sounds fine, too. :P

+        100 /* bucket_count */);
+  }
+
+  if (info.was_cached && !info.network_accessed &&

[twifkak, 2016/07/18 04:30:35]

I thought the plan was to add a Precache.Saved.UpperBound metric for grey area
cases like this. By revalidating the cache entry, isn't it possible that all we
did was save the user a few bytes of 304 traffic later? OTOH, isn't it possible
that accessing a cache entry without needing revalidating would still update
it's last-accessed timestamp, thus saving it from LRU eviction?

[jamartin, 2016/07/18 16:29:43]

You are right. I don't understand this code as well as I thought I did.

I don't know why I thought that we were not considering the latency improvement
for those URLs that were not added to the table but that's not true. We measure
latency regardless of the URL table and we compare just by membership to the
experiment group. The URL table is, currently, only for measuring the byte
savings, and 304s don't amount for much, so I'm dropping this part of the CL.

Regarding the upper bound, I'll coordinate with Raj before doing it. I'll need
new fields in the DB which will conflict with his intended changes for the
bitvector, so it is better if we take turns at it.

[twifkak, 2016/07/18 23:50:44]

Oy, that sounds fun.

+      !precache_url_table_.HasURL(url)) {
+    // Since the precache came from the cache, there's no entry in the URL table
+    // for the URL and there was no validation, this means that the resource was
+    // already in the cache because of user browsing. Thus, this precache had no
+    // effect, so ignore it.
+    // We take credit for resources that were already in the cache due to user
+    // browsing but needed validation at the time of the prefetch.
     return;
   }
 
-  if (!was_cached) {
+  if (!info.was_cached) {
     // The precache only counts as overhead if it was downloaded over the
     // network.
     UMA_HISTOGRAM_COUNTS("Precache.DownloadedPrecacheMotivated",
                          static_cast<base::HistogramBase::Sample>(size));
   }
 
   // Use the URL table to keep track of URLs that are in the cache thanks to
   // precaching. If a row for the URL already exists, than update the timestamp
   // to |fetch_time|.
   buffered_writes_.push_back(
       base::Bind(&PrecacheURLTable::AddURL,
                  base::Unretained(&precache_url_table_), url, fetch_time));
   buffered_urls_.insert(url.spec());
   MaybePostFlush();
 }
 
 void PrecacheDatabase::RecordURLNonPrefetch(const GURL& url,
                                             const base::TimeDelta& latency,
                                             const base::Time& fetch_time,
+                                            const net::HttpResponseInfo& info,
                                             int64_t size,
-                                            bool was_cached,
                                             int host_rank,
                                             bool is_connection_cellular) {
   UMA_HISTOGRAM_TIMES("Precache.Latency.NonPrefetch", latency);
 
   if (host_rank != history::kMaxTopHosts) {
     // The resource was loaded on a page that could have been affected by
     // precaching.
     UMA_HISTOGRAM_TIMES("Precache.Latency.NonPrefetch.TopHosts", latency);
   } else {
     // The resource was loaded on a page that could NOT have been affected by
     // precaching.
     UMA_HISTOGRAM_TIMES("Precache.Latency.NonPrefetch.NonTopHosts", latency);
   }
 
   if (!IsDatabaseAccessible()) {
     // Don't track anything if unable to access the database.
     return;
   }
 
   if (buffered_urls_.find(url.spec()) != buffered_urls_.end()) {
     // If the URL for this fetch is in the write buffer, then flush the write
     // buffer.
     Flush();
   }
 
-  if (was_cached && !precache_url_table_.HasURL(url)) {
+  if (info.was_cached && !precache_url_table_.HasURL(url)) {
     // Ignore cache hits that precache can't take credit for.
     return;
   }
 
   base::HistogramBase::Sample size_sample =
       static_cast<base::HistogramBase::Sample>(size);
-  if (!was_cached) {
+  if (!info.was_cached) {
     // The fetch was served over the network during user browsing, so count it
     // as downloaded non-precache bytes.
     UMA_HISTOGRAM_COUNTS("Precache.DownloadedNonPrecache", size_sample);
     if (is_connection_cellular) {
       UMA_HISTOGRAM_COUNTS("Precache.DownloadedNonPrecache.Cellular",
                            size_sample);
     }
   } else {
     // The fetch was served from the cache, and since there's an entry for this
     // URL in the URL table, this means that the resource was served from the
@@ skipping 93 matching lines @@
 
 void PrecacheDatabase::DeleteUnfinishedWork() {
   precache_session_table_.DeleteUnfinishedWork();
 }
 
 base::WeakPtr<PrecacheDatabase> PrecacheDatabase::GetWeakPtr() {
   return weak_factory_.GetWeakPtr();
 }
 
 }  // namespace precache