DNS: Retain stale entries in HostCache and return when requested

net/dns/host_cache.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/dns/host_cache.h"
 
 #include "base/logging.h"
 #include "base/memory/ptr_util.h"
 #include "base/metrics/field_trial.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/trace_event/trace_event.h"
 #include "net/base/net_errors.h"
+#include "net/dns/dns_util.h"
 
 namespace net {
 
-//-----------------------------------------------------------------------------
+namespace {
+
+#define CACHE_HISTOGRAM_TIME(name, time) \
+  UMA_HISTOGRAM_LONG_TIMES("DNS.HostCache." name, time)
+
+#define CACHE_HISTOGRAM_COUNT(name, count) \
+  UMA_HISTOGRAM_COUNTS_1000("DNS.HostCache." name, count)
+
+#define CACHE_HISTOGRAM_ENUM(name, value, max) \
+  UMA_HISTOGRAM_ENUMERATION("DNS.HostCache." name, value, max)
+
+}  // namespace
+
+struct HostCache::EntryInternal : public HostCache::Entry {

[Randy Smith (Not in Mondays), 2016/05/04 18:15:25]

nit, suggestion: I'm somewhat uncomfortable with the existence of this structure
and whether it's worth having a secondary structure to Entry.  Did you consider
storing all this information in Entry, but making it private and only accessible
to the HostCache?

I'm also uncomfortable with inheritance rather than inclusion, as it feels like
the inheritance is being used for implementation simplicity rather than because
there's a real ISA relationship between the two classes.  But that's less of a
big deal because this class has much smaller visibility than Entry; it doesn't
matter too much playing those games within a single .cc file.

[Julia Tuttle, 2016/05/05 14:35:53]

I thought about it, but did not think about making it private. I didn't want to
expose them as public, because it seemed rude to expect the caller to see and
deal with them.

(I grew up using Java, so friend declarations don't occur to me easily.)

This is *much* nicer with the cache metadata as private members and HostCache as
a friend. Thanks for the suggestion.

+  EntryInternal(const Entry& entry,
+                base::TimeTicks now,
+                base::TimeDelta ttl,
+                int network_changes);
+
+  base::TimeTicks expires;

[Randy Smith (Not in Mondays), 2016/05/04 18:15:25]

Why isn't this in Entry in place of ttl?  It seems like it would be much more
valuable to the caller than ttl, and the same information isn't really needed in
both places, is it?

[Julia Tuttle, 2016/05/05 14:35:53]

I was trying not to alter the interface, for no practical reason.

It looks like the TTL is histogrammed in HostResolverImpl, but that's it.

The only user who'd like *expiration* is WebUI, so I don't know if it's worth
changing it for that.

+  // Copied from HostCache::network_changes when this entry is set; can later
+  // be compared to it to see if the entry was received on the current
+  // network.
+  int network_changes;
+  int total_hits;
+  int stale_hits;
+
+  bool IsStale(base::TimeTicks now, int network_changes) const;
+  void CountHit(bool hit_is_stale);
+  void GetStaleness(base::TimeTicks now,
+                    int network_changes,
+                    EntryStaleness* out) const;
+};
+
+// Used in histograms; do not modify existing values.
+enum HostCache::SetOutcome : int {
+  SET_INSERT = 0,
+  SET_UPDATE_VALID = 1,
+  SET_UPDATE_STALE = 2,
+  MAX_SET_OUTCOME
+};
+
+// Used in histograms; do not modify existing values.
+enum HostCache::LookupOutcome : int {
+  LOOKUP_MISS_ABSENT = 0,
+  LOOKUP_MISS_STALE = 1,
+  LOOKUP_HIT_VALID = 2,
+  LOOKUP_HIT_STALE = 3,
+  MAX_LOOKUP_OUTCOME
+};
+
+// Used in histograms; do not modify existing values.
+enum HostCache::EraseReason : int {
+  ERASE_EVICT = 0,
+  ERASE_CLEAR = 1,
+  ERASE_DESTRUCT = 2,
+  MAX_ERASE_REASON
+};
 
 HostCache::Entry::Entry(int error, const AddressList& addrlist,
                         base::TimeDelta ttl)
     : error(error),
       addrlist(addrlist),
       ttl(ttl) {
   DCHECK(ttl >= base::TimeDelta());
 }
 
 HostCache::Entry::Entry(int error, const AddressList& addrlist)
     : error(error),
       addrlist(addrlist),
       ttl(base::TimeDelta::FromSeconds(-1)) {
 }
 
-HostCache::Entry::~Entry() {
-}
-
-//-----------------------------------------------------------------------------
+HostCache::Entry::~Entry() {}
 
 HostCache::HostCache(size_t max_entries)
-    : entries_(max_entries) {
-}
+    : max_entries_(max_entries), network_changes_(0) {}
 
 HostCache::~HostCache() {
+  RecordEraseAll(ERASE_DESTRUCT, base::TimeTicks::Now());
 }
 
 const HostCache::Entry* HostCache::Lookup(const Key& key,
                                           base::TimeTicks now) {
   DCHECK(CalledOnValidThread());
   if (caching_is_disabled())
-    return NULL;
+    return nullptr;
 
-  return entries_.Get(key, now);
+  HostCache::EntryInternal* entry = LookupInternal(key);
+  if (!entry) {
+    RecordLookup(LOOKUP_MISS_ABSENT, now, nullptr);
+    return nullptr;
+  }
+  if (entry->IsStale(now, network_changes_)) {

[Randy Smith (Not in Mondays), 2016/05/04 18:15:25]

Is this a behavior change to Lookup() with this CL?  IIUC, network changes
didn't use to make entries stale, did they?

[Julia Tuttle, 2016/05/05 14:35:53]

No; network changes clear the cache right now.

This is just preparing to make network changes lighter-weight -- we can alter
the owner to only call OnNetworkChange, and then the entries will be stale
instead of gone.

+    RecordLookup(LOOKUP_MISS_STALE, now, entry);
+    return nullptr;
+  }
+
+  entry->CountHit(/* hit_is_stale= */ false);

[Randy Smith (Not in Mondays), 2016/05/04 18:15:25]

Consistency nit: Include the comment in all calls or none (my preference is all,
but up to you).

[Julia Tuttle, 2016/05/05 14:35:53]

Oh, whoops, thanks.

(I hadn't included it in the other version because the argument I was passing
was "is_stale", but it's better to be clearer.)

+  RecordLookup(LOOKUP_HIT_VALID, now, entry);
+  return entry;
+}
+
+const HostCache::Entry* HostCache::LookupStale(
+    const Key& key,
+    base::TimeTicks now,
+    HostCache::EntryStaleness* stale_out) {
+  DCHECK(CalledOnValidThread());
+  if (caching_is_disabled())
+    return nullptr;
+
+  HostCache::EntryInternal* entry = LookupInternal(key);
+  if (!entry) {
+    RecordLookup(LOOKUP_MISS_ABSENT, now, nullptr);
+    return nullptr;
+  }
+
+  bool is_stale = entry->IsStale(now, network_changes_);
+  entry->CountHit(is_stale);
+  RecordLookup(is_stale ? LOOKUP_HIT_STALE : LOOKUP_HIT_VALID, now, entry);
+
+  if (stale_out)
+    entry->GetStaleness(now, network_changes_, stale_out);
+  return entry;
+}
+
+HostCache::EntryInternal* HostCache::LookupInternal(const Key& key) {
+  auto it = entries_.find(key);
+  return (it != entries_.end()) ? &it->second : nullptr;
 }
 
 void HostCache::Set(const Key& key,
                     const Entry& entry,
                     base::TimeTicks now,
                     base::TimeDelta ttl) {
   TRACE_EVENT0("net", "HostCache::Set");
   DCHECK(CalledOnValidThread());
   if (caching_is_disabled())
     return;
 
-  entries_.Put(key, entry, now, now + ttl);
+  auto it = entries_.find(key);
+  if (it != entries_.end()) {
+    bool is_stale = it->second.IsStale(now, network_changes_);
+    RecordSet(is_stale ? SET_UPDATE_STALE : SET_UPDATE_VALID, now, &it->second,
+              entry);
+    // TODO(juliatuttle): Remember some old metadata (hit count or frequency or
+    // something like that) if it's useful for better eviction algorithms?
+    entries_.erase(it);
+  } else {
+    if (size() == max_entries_)
+      EvictOneEntry(now);
+    RecordSet(SET_INSERT, now, nullptr, entry);
+  }
+
+  DCHECK_GT(max_entries_, size());
+  DCHECK_EQ(0u, entries_.count(key));
+  entries_.insert(std::make_pair(
+      Key(key), EntryInternal(entry, now, ttl, network_changes_)));
+  DCHECK_GE(max_entries_, size());
+}
+
+void HostCache::OnNetworkChange() {
+  ++network_changes_;
 }
 
 void HostCache::clear() {
   DCHECK(CalledOnValidThread());
-  entries_.Clear();
+  RecordEraseAll(ERASE_CLEAR, base::TimeTicks::Now());
+  entries_.clear();
 }
 
 size_t HostCache::size() const {
   DCHECK(CalledOnValidThread());
   return entries_.size();
 }
 
 size_t HostCache::max_entries() const {
   DCHECK(CalledOnValidThread());
-  return entries_.max_entries();
+  return max_entries_;
 }
 
-// Note that this map may contain expired entries.
-const HostCache::EntryMap& HostCache::entries() const {
-  DCHECK(CalledOnValidThread());
-  return entries_;
+std::unique_ptr<base::Value> HostCache::GetEntriesAsValue() const {
+  std::unique_ptr<base::ListValue> entry_list(new base::ListValue());
+
+  for (const auto& pair : entries_) {
+    const Key& key = pair.first;
+    const EntryInternal& entry = pair.second;
+
+    base::DictionaryValue* entry_dict = new base::DictionaryValue();
+
+    entry_dict->SetString("hostname", key.hostname);
+    entry_dict->SetInteger("address_family",
+                           static_cast<int>(key.address_family));
+    entry_dict->SetString("expiration",
+                          NetLog::TickCountToString(entry.expires));
+
+    if (entry.error != OK) {
+      entry_dict->SetInteger("error", entry.error);
+    } else {
+      base::ListValue* address_list = new base::ListValue();
+      for (size_t i = 0; i < entry.addrlist.size(); ++i)
+        address_list->AppendString(entry.addrlist[i].ToStringWithoutPort());
+      entry_dict->Set("addresses", address_list);
+    }
+
+    entry_list->Append(entry_dict);
+  }
+
+  return std::move(entry_list);
 }
 
 // static
 std::unique_ptr<HostCache> HostCache::CreateDefaultCache() {
 // Cache capacity is determined by the field trial.
 #if defined(ENABLE_BUILT_IN_DNS)
   const size_t kDefaultMaxEntries = 1000;
 #else
   const size_t kDefaultMaxEntries = 100;
 #endif
   const size_t kSaneMaxEntries = 1 << 20;
   size_t max_entries = 0;
   base::StringToSizeT(base::FieldTrialList::FindFullName("HostCacheSize"),
                       &max_entries);
   if ((max_entries == 0) || (max_entries > kSaneMaxEntries))
     max_entries = kDefaultMaxEntries;
   return base::WrapUnique(new HostCache(max_entries));
 }
 
-void HostCache::EvictionHandler::Handle(
-    const Key& key,
-    const Entry& entry,
-    const base::TimeTicks& expiration,
-    const base::TimeTicks& now,
-    bool on_get) const {
-  if (on_get) {
-    DCHECK(now >= expiration);
-    UMA_HISTOGRAM_CUSTOM_TIMES("DNS.CacheExpiredOnGet", now - expiration,
-        base::TimeDelta::FromSeconds(1), base::TimeDelta::FromDays(1), 100);
-    return;
+HostCache::EntryInternal::EntryInternal(const HostCache::Entry& entry,
+                                        base::TimeTicks now,
+                                        base::TimeDelta ttl,
+                                        int network_changes)
+    : HostCache::Entry(entry),
+      expires(now + ttl),
+      network_changes(network_changes),
+      total_hits(0),
+      stale_hits(0) {}
+
+bool HostCache::EntryInternal::IsStale(base::TimeTicks now,
+                                       int network_changes) const {
+  EntryStaleness stale;
+  stale.expired_by = now - expires;
+  stale.network_changes = network_changes - this->network_changes;
+  stale.stale_hits = stale_hits;
+  return stale.is_stale();
+}
+
+void HostCache::EntryInternal::CountHit(bool hit_is_stale) {
+  ++total_hits;
+  if (hit_is_stale)
+    ++stale_hits;
+}
+
+void HostCache::EntryInternal::GetStaleness(base::TimeTicks now,
+                                            int network_changes,
+                                            EntryStaleness* out) const {
+  DCHECK(out);
+  out->expired_by = now - expires;
+  out->network_changes = network_changes - this->network_changes;
+  out->stale_hits = stale_hits;
+}
+
+void HostCache::EvictOneEntry(base::TimeTicks now) {
+  DCHECK_LT(0u, entries_.size());
+
+  auto oldest_it = entries_.begin();
+  for (auto it = entries_.begin(); it != entries_.end(); ++it) {
+    if (it->second.expires < oldest_it->second.expires)

[Randy Smith (Not in Mondays), 2016/05/04 18:15:25]

What is your thinking around expiring the strictly oldest as opposed to expiring
stale before fresh?  I could imagine fresh entries with long ttls being older
than stale entries.

[Julia Tuttle, 2016/05/05 14:35:53]

Maybe, but I'd rather tinker with eviction strategies in another CL.

This *should* mirror the behavior of the original cache for the most part.

+      oldest_it = it;
   }
-  if (expiration > now) {
-    UMA_HISTOGRAM_CUSTOM_TIMES("DNS.CacheEvicted", expiration - now,
-        base::TimeDelta::FromSeconds(1), base::TimeDelta::FromDays(1), 100);
-  } else {
-    UMA_HISTOGRAM_CUSTOM_TIMES("DNS.CacheExpired", now - expiration,
-        base::TimeDelta::FromSeconds(1), base::TimeDelta::FromDays(1), 100);
+
+  RecordErase(ERASE_EVICT, now, oldest_it->second);
+  entries_.erase(oldest_it);
+}
+
+void HostCache::RecordSet(SetOutcome outcome,
+                          base::TimeTicks now,
+                          const EntryInternal* old_entry,
+                          const Entry& new_entry) {
+  CACHE_HISTOGRAM_ENUM("Set", outcome, MAX_SET_OUTCOME);
+  switch (outcome) {
+    case SET_INSERT:
+      // Nothing to log here.

[Randy Smith (Not in Mondays), 2016/05/04 18:15:25]

I don't understand why this comment only applies to SET_INSERT and not
SET_UPDATE_VALID; the existence of the comment makes me feel like there's some
subtle difference between the two.  Is there?

[Julia Tuttle, 2016/05/05 14:35:53]

The intended difference was that INSERT doesn't have an old entry to compare to.

I decided to just share the comment between all of them, and also add one in the
DESTRUCT case in RecordErase.

+      break;
+    case SET_UPDATE_VALID:
+      break;
+    case SET_UPDATE_STALE: {
+      base::TimeDelta expired_by = now - old_entry->expires;
+      int network_changes = network_changes_ - old_entry->network_changes;
+      int stale_hits = old_entry->stale_hits;
+      CACHE_HISTOGRAM_TIME("UpdateStale.ExpiredBy", expired_by);
+      CACHE_HISTOGRAM_COUNT("UpdateStale.NetworkChanges", network_changes);
+      CACHE_HISTOGRAM_COUNT("UpdateStale.StaleHits", stale_hits);
+      if (old_entry->error == OK && new_entry.error == OK) {
+        RecordUpdateStale(*old_entry, new_entry, expired_by, network_changes,
+                          stale_hits);
+      }
+      break;
+    }
+    case MAX_SET_OUTCOME:
+      NOTREACHED();
+      break;
   }
 }
 
+void HostCache::RecordUpdateStale(const EntryInternal& old_entry,
+                                  const Entry& new_entry,
+                                  base::TimeDelta expired_by,
+                                  int network_changes,
+                                  int stale_hits) {
+  AddressListDeltaType delta =
+      FindAddressListDeltaType(old_entry.addrlist, new_entry.addrlist);
+  CACHE_HISTOGRAM_ENUM("UpdateStale.AddressListDelta", delta, MAX_DELTA_TYPE);
+  switch (delta) {
+    case DELTA_IDENTICAL:
+      CACHE_HISTOGRAM_TIME("UpdateStale.ExpiredBy_Identical", expired_by);
+      CACHE_HISTOGRAM_COUNT("UpdateStale.NetworkChanges_Identical",
+                            network_changes);
+      break;
+    case DELTA_REORDERED:
+      CACHE_HISTOGRAM_TIME("UpdateStale.ExpiredBy_Reordered", expired_by);
+      CACHE_HISTOGRAM_COUNT("UpdateStale.NetworkChanges_Reordered",
+                            network_changes);
+      break;
+    case DELTA_OVERLAP:
+      CACHE_HISTOGRAM_TIME("UpdateStale.ExpiredBy_Overlap", expired_by);
+      CACHE_HISTOGRAM_COUNT("UpdateStale.NetworkChanges_Overlap",
+                            network_changes);
+      break;
+    case DELTA_DISJOINT:
+      CACHE_HISTOGRAM_TIME("UpdateStale.ExpiredBy_Disjoint", expired_by);
+      CACHE_HISTOGRAM_COUNT("UpdateStale.NetworkChanges_Dijsoint",
+                            network_changes);
+      break;
+    case MAX_DELTA_TYPE:
+      NOTREACHED();
+      break;
+  }
+}
+
+void HostCache::RecordLookup(LookupOutcome outcome,
+                             base::TimeTicks now,
+                             const EntryInternal* entry) {
+  CACHE_HISTOGRAM_ENUM("Lookup", outcome, MAX_LOOKUP_OUTCOME);
+  switch (outcome) {
+    case LOOKUP_MISS_ABSENT:
+      // Nothing to log here.

[Randy Smith (Not in Mondays), 2016/05/04 18:15:25]

Same confusion as to why this comment applies here and not to the two below.

[Julia Tuttle, 2016/05/05 14:35:53]

Acknowledged.

+      break;
+    case LOOKUP_MISS_STALE:
+    case LOOKUP_HIT_VALID:
+      break;
+    case LOOKUP_HIT_STALE:
+      CACHE_HISTOGRAM_TIME("LookupStale.ExpiredBy", now - entry->expires);
+      CACHE_HISTOGRAM_COUNT("LookupStale.NetworkChanges",
+                            network_changes_ - entry->network_changes);
+      CACHE_HISTOGRAM_COUNT("LookupStale.Hits", entry->stale_hits);
+      break;
+    case MAX_LOOKUP_OUTCOME:
+      NOTREACHED();
+      break;
+  }
+}
+
+void HostCache::RecordErase(EraseReason reason,
+                            base::TimeTicks now,
+                            const EntryInternal& entry) {
+  HostCache::EntryStaleness stale;
+  entry.GetStaleness(now, network_changes_, &stale);
+  CACHE_HISTOGRAM_ENUM("Erase", reason, MAX_ERASE_REASON);
+  switch (reason) {
+    case ERASE_EVICT:
+      if (stale.is_stale()) {
+        CACHE_HISTOGRAM_TIME("EvictStale.ExpiredBy", stale.expired_by);
+        CACHE_HISTOGRAM_COUNT("EvictStale.NetworkChanges",
+                              stale.network_changes);
+        CACHE_HISTOGRAM_COUNT("EvictStale.StaleHits", entry.stale_hits);
+      } else {
+        CACHE_HISTOGRAM_TIME("EvictValid.ValidFor", -stale.expired_by);
+      }
+      break;
+    case ERASE_CLEAR:
+      // TODO(juliatuttle): Remove these once we stop clearing the cache on
+      // network change.
+      if (stale.is_stale()) {
+        CACHE_HISTOGRAM_TIME("ClearStale.ExpiredBy", stale.expired_by);
+        CACHE_HISTOGRAM_COUNT("ClearStale.NetworkChanges",
+                              stale.network_changes);
+        CACHE_HISTOGRAM_COUNT("ClearStale.StaleHits", entry.stale_hits);
+      } else {
+        CACHE_HISTOGRAM_TIME("ClearValid.ValidFor", -stale.expired_by);
+      }
+      break;
+    case ERASE_DESTRUCT:
+      break;
+    default:
+      NOTREACHED();
+      break;
+  }
+}
+
+void HostCache::RecordEraseAll(EraseReason reason, base::TimeTicks now) {
+  for (const auto& it : entries_)
+    RecordErase(reason, now, it.second);
+}
+
 }  // namespace net