src/chrome/browser/net/url_info.cc

   1 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include "chrome/browser/net/url_info.h"
   6
   7 #include <ctype.h>
   8 #include <math.h>
   9
  10 #include <algorithm>
  11 #include <string>
  12
  13 #include "base/format_macros.h"
  14 #include "base/lazy_instance.h"
  15 #include "base/logging.h"
  16 #include "base/metrics/histogram.h"
  17 #include "base/strings/stringprintf.h"
  18
  19 using base::Time;
  20 using base::TimeDelta;
  21 using base::TimeTicks;
  22
  23 namespace chrome_browser_net {
  24
  25 namespace {
  26
  27 // The number of OS cache entries we can guarantee(?) before cache eviction
  28 // might likely take place.
  29 const int kMaxGuaranteedDnsCacheSize = 50;
  30
  31 // Common low end TTL for sites is 5 minutes.  However, DNS servers give us the
  32 // remaining time, not the original 5 minutes.  Hence it doesn't much matter
  33 // whether we found something in the local cache, or an ISP cache, it will on
  34 // average be 2.5 minutes before it expires.  We could try to model this with
  35 // 180 seconds, but simpler is just to do the lookups all the time (wasting OS
  36 // calls(?)), and let that OS cache decide what to do (with TTL in hand).  We
  37 // use a small time to help get some duplicate suppression, in case a page has
  38 // a TON of copies of the same domain name, so that we don't thrash the OS to
  39 // death.  Hopefully it is small enough that we're not hurting our cache hit
  40 // rate (i.e., we could always ask the OS).
  41 const int kDefaultCacheExpirationDuration = 5;
  42
  43 TimeDelta MaxNonNetworkDnsLookupDuration() {
  44   return TimeDelta::FromMilliseconds(15);
  45 }
  46
  47 bool detailed_logging_enabled = false;
  48
  49 struct GlobalState {
  50   GlobalState() {
  51     cache_expiration_duration =
  52         TimeDelta::FromSeconds(kDefaultCacheExpirationDuration);
  53   }
  54   TimeDelta cache_expiration_duration;
  55 };
  56
  57 base::LazyInstance<GlobalState>::Leaky global_state;
  58
  59 }  // anonymous namespace
  60
  61 // Use command line switch to enable detailed logging.
  62 void EnablePredictorDetailedLog(bool enable) {
  63   detailed_logging_enabled = enable;
  64 }
  65
  66 // static
  67 int UrlInfo::sequence_counter = 1;
  68
  69 UrlInfo::UrlInfo()
  70     : state_(PENDING),
  71       old_prequeue_state_(state_),
  72       resolve_duration_(NullDuration()),
  73       queue_duration_(NullDuration()),
  74       sequence_number_(0),
  75       motivation_(NO_PREFETCH_MOTIVATION),
  76       was_linked_(false) {
  77 }
  78
  79 UrlInfo::~UrlInfo() {}
  80
  81 bool UrlInfo::NeedsDnsUpdate() {
  82   switch (state_) {
  83     case PENDING:  // Just now created info.
  84       return true;
  85
  86     case QUEUED:  // In queue.
  87     case ASSIGNED:  // It's being resolved.
  88     case ASSIGNED_BUT_MARKED:  // It's being resolved.
  89       return false;  // We're already working on it
  90
  91     case NO_SUCH_NAME:  // Lookup failed.
  92     case FOUND:  // Lookup succeeded.
  93       return !IsStillCached();  // See if DNS cache expired.
  94
  95     default:
  96       NOTREACHED();
  97       return false;
  98   }
  99 }
 100
 101 // Used by test ONLY. The value is otherwise constant.
 102 // static
 103 void UrlInfo::set_cache_expiration(TimeDelta time) {
 104   global_state.Pointer()->cache_expiration_duration = time;
 105 }
 106
 107 // static
 108 TimeDelta UrlInfo::get_cache_expiration() {
 109   return global_state.Get().cache_expiration_duration;
 110 }
 111
 112 void UrlInfo::SetQueuedState(ResolutionMotivation motivation) {
 113   DCHECK(PENDING == state_ || FOUND == state_ || NO_SUCH_NAME == state_);
 114   old_prequeue_state_ = state_;
 115   state_ = QUEUED;
 116   queue_duration_ = resolve_duration_ = NullDuration();
 117   SetMotivation(motivation);
 118   GetDuration();  // Set time_
 119   DLogResultsStats("DNS Prefetch in queue");
 120 }
 121
 122 void UrlInfo::SetAssignedState() {
 123   DCHECK(QUEUED == state_);
 124   state_ = ASSIGNED;
 125   queue_duration_ = GetDuration();
 126   DLogResultsStats("DNS Prefetch assigned");
 127   UMA_HISTOGRAM_TIMES("DNS.PrefetchQueue", queue_duration_);
 128 }
 129
 130 void UrlInfo::RemoveFromQueue() {
 131   DCHECK(ASSIGNED == state_);
 132   state_ = old_prequeue_state_;
 133   DLogResultsStats("DNS Prefetch reset to prequeue");
 134   const TimeDelta kBoundary = TimeDelta::FromSeconds(2);
 135   if (queue_duration_ > kBoundary) {
 136     UMA_HISTOGRAM_MEDIUM_TIMES("DNS.QueueRecycledDeltaOver2",
 137                                queue_duration_ - kBoundary);
 138     return;
 139   }
 140   // Make a custom linear histogram for the region from 0 to boundary.
 141   static const size_t kBucketCount = 52;
 142   static base::HistogramBase* histogram(NULL);
 143   if (!histogram)
 144     histogram = base::LinearHistogram::FactoryTimeGet(
 145         "DNS.QueueRecycledUnder2", TimeDelta(), kBoundary, kBucketCount,
 146         base::HistogramBase::kUmaTargetedHistogramFlag);
 147   histogram->AddTime(queue_duration_);
 148 }
 149
 150 void UrlInfo::SetPendingDeleteState() {
 151   DCHECK(ASSIGNED == state_  || ASSIGNED_BUT_MARKED == state_);
 152   state_ = ASSIGNED_BUT_MARKED;
 153 }
 154
 155 void UrlInfo::SetFoundState() {
 156   DCHECK(ASSIGNED == state_);
 157   state_ = FOUND;
 158   resolve_duration_ = GetDuration();
 159   const TimeDelta max_duration = MaxNonNetworkDnsLookupDuration();
 160   if (max_duration <= resolve_duration_) {
 161     UMA_HISTOGRAM_CUSTOM_TIMES("DNS.PrefetchResolution", resolve_duration_,
 162         max_duration, TimeDelta::FromMinutes(15), 100);
 163   }
 164   sequence_number_ = sequence_counter++;
 165   DLogResultsStats("DNS PrefetchFound");
 166 }
 167
 168 void UrlInfo::SetNoSuchNameState() {
 169   DCHECK(ASSIGNED == state_);
 170   state_ = NO_SUCH_NAME;
 171   resolve_duration_ = GetDuration();
 172 #ifndef NDEBUG
 173   if (MaxNonNetworkDnsLookupDuration() <= resolve_duration_) {
 174     LOCAL_HISTOGRAM_TIMES("DNS.PrefetchNotFoundName", resolve_duration_);
 175   }
 176 #endif
 177   sequence_number_ = sequence_counter++;
 178   DLogResultsStats("DNS PrefetchNotFound");
 179 }
 180
 181 void UrlInfo::SetUrl(const GURL& url) {
 182   if (url_.is_empty())  // Not yet initialized.
 183     url_ = url;
 184   else
 185     DCHECK_EQ(url_, url);
 186 }
 187
 188 // IsStillCached() guesses if the DNS cache still has IP data,
 189 // or at least remembers results about "not finding host."
 190 bool UrlInfo::IsStillCached() const {
 191   DCHECK(FOUND == state_ || NO_SUCH_NAME == state_);
 192
 193   // Default MS OS does not cache failures. Hence we could return false almost
 194   // all the time for that case.  However, we'd never try again to prefetch
 195   // the value if we returned false that way.  Hence we'll just let the lookup
 196   // time out the same way as FOUND case.
 197
 198   if (sequence_counter - sequence_number_ > kMaxGuaranteedDnsCacheSize)
 199     return false;
 200
 201   TimeDelta time_since_resolution = TimeTicks::Now() - time_;
 202   return time_since_resolution < global_state.Get().cache_expiration_duration;
 203 }
 204
 205 void UrlInfo::DLogResultsStats(const char* message) const {
 206   if (!detailed_logging_enabled)
 207     return;
 208   DVLOG(1) << "\t" << message << "\tq=" << queue_duration().InMilliseconds()
 209            << "ms,\tr=" << resolve_duration().InMilliseconds()
 210            << "ms,\tp=" << sequence_number_ << "\t" << url_.spec();
 211 }
 212
 213 //------------------------------------------------------------------------------
 214 // This last section supports HTML output, such as seen in about:dns.
 215 //------------------------------------------------------------------------------
 216
 217 // Preclude any possibility of Java Script or markup in the text, by only
 218 // allowing alphanumerics, '.', '-', ':', and whitespace.
 219 static std::string RemoveJs(const std::string& text) {
 220   std::string output(text);
 221   size_t length = output.length();
 222   for (size_t i = 0; i < length; i++) {
 223     char next = output[i];
 224     if (isalnum(next) || isspace(next) || strchr(".-:/", next) != NULL)
 225       continue;
 226     output[i] = '?';
 227   }
 228   return output;
 229 }
 230
 231 class MinMaxAverage {
 232  public:
 233   MinMaxAverage()
 234     : sum_(0), square_sum_(0), count_(0),
 235       minimum_(kint64max), maximum_(kint64min) {
 236   }
 237
 238   // Return values for use in printf formatted as "%d"
 239   int sample(int64 value) {
 240     sum_ += value;
 241     square_sum_ += value * value;
 242     count_++;
 243     minimum_ = std::min(minimum_, value);
 244     maximum_ = std::max(maximum_, value);
 245     return static_cast<int>(value);
 246   }
 247   int minimum() const { return static_cast<int>(minimum_);    }
 248   int maximum() const { return static_cast<int>(maximum_);    }
 249   int average() const { return static_cast<int>(sum_/count_); }
 250   int     sum() const { return static_cast<int>(sum_);        }
 251
 252   int standard_deviation() const {
 253     double average = static_cast<float>(sum_) / count_;
 254     double variance = static_cast<float>(square_sum_)/count_
 255                       - average * average;
 256     return static_cast<int>(floor(sqrt(variance) + .5));
 257   }
 258
 259  private:
 260   int64 sum_;
 261   int64 square_sum_;
 262   int count_;
 263   int64 minimum_;
 264   int64 maximum_;
 265
 266   // DISALLOW_COPY_AND_ASSIGN(MinMaxAverage);
 267 };
 268
 269 static std::string HoursMinutesSeconds(int seconds) {
 270   std::string result;
 271   int print_seconds = seconds % 60;
 272   int minutes = seconds / 60;
 273   int print_minutes = minutes % 60;
 274   int print_hours = minutes/60;
 275   if (print_hours)
 276     base::StringAppendF(&result, "%.2d:",  print_hours);
 277   if (print_hours || print_minutes)
 278     base::StringAppendF(&result, "%2.2d:",  print_minutes);
 279   base::StringAppendF(&result, "%2.2d",  print_seconds);
 280   return result;
 281 }
 282
 283 // static
 284 void UrlInfo::GetHtmlTable(const UrlInfoTable& host_infos,
 285                            const char* description,
 286                            bool brief,
 287                            std::string* output) {
 288   if (0 == host_infos.size())
 289     return;
 290   output->append(description);
 291   base::StringAppendF(output, "%" PRIuS " %s", host_infos.size(),
 292                       (1 == host_infos.size()) ? "hostname" : "hostnames");
 293
 294   if (brief) {
 295     output->append("<br><br>");
 296     return;
 297   }
 298
 299   output->append("<br><table border=1>"
 300       "<tr><th>Host name</th>"
 301       "<th>How long ago<br>(HH:MM:SS)</th>"
 302       "<th>Motivation</th>"
 303       "</tr>");
 304
 305   const char* row_format = "<tr align=right><td>%s</td>"  // Host name.
 306                            "<td>%s</td>"                  // How long ago.
 307                            "<td>%s</td>"                  // Motivation.
 308                            "</tr>";
 309
 310   // Print bulk of table, and gather stats at same time.
 311   MinMaxAverage queue, when;
 312   TimeTicks current_time = TimeTicks::Now();
 313   for (UrlInfoTable::const_iterator it(host_infos.begin());
 314        it != host_infos.end(); it++) {
 315     queue.sample((it->queue_duration_.InMilliseconds()));
 316     base::StringAppendF(
 317         output,
 318         row_format,
 319         RemoveJs(it->url_.spec()).c_str(),
 320                  HoursMinutesSeconds(when.sample(
 321                      (current_time - it->time_).InSeconds())).c_str(),
 322         it->GetAsciiMotivation().c_str());
 323   }
 324   output->append("</table>");
 325
 326 #ifndef NDEBUG
 327   base::StringAppendF(
 328       output,
 329       "Prefetch Queue Durations: min=%d, avg=%d, max=%d<br><br>",
 330       queue.minimum(), queue.average(), queue.maximum());
 331 #endif
 332
 333   output->append("<br>");
 334 }
 335
 336 void UrlInfo::SetMotivation(ResolutionMotivation motivation) {
 337   motivation_ = motivation;
 338   if (motivation < LINKED_MAX_MOTIVATED)
 339     was_linked_ = true;
 340 }
 341
 342 std::string UrlInfo::GetAsciiMotivation() const {
 343   switch (motivation_) {
 344     case MOUSE_OVER_MOTIVATED:
 345       return "[mouse-over]";
 346
 347     case PAGE_SCAN_MOTIVATED:
 348       return "[page scan]";
 349
 350     case OMNIBOX_MOTIVATED:
 351       return "[omnibox]";
 352
 353     case STARTUP_LIST_MOTIVATED:
 354       return "[startup list]";
 355
 356     case NO_PREFETCH_MOTIVATION:
 357       return "n/a";
 358
 359     case STATIC_REFERAL_MOTIVATED:
 360       return RemoveJs(referring_url_.spec()) + "*";
 361
 362     case LEARNED_REFERAL_MOTIVATED:
 363       return RemoveJs(referring_url_.spec());
 364
 365     default:
 366       return std::string();
 367   }
 368 }
 369
 370 }  // namespace chrome_browser_net