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