[go: nahoru, domu]

blob: 63eae347f47ada7ce62f2d0d1664190bebf35eb0 [file] [log] [blame]
// Copyright (c) 2006-2008 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 "chrome/browser/net/dns_host_info.h"
#include <math.h>
#include <algorithm>
#include <string>
#include "base/format_macros.h"
#include "base/histogram.h"
#include "base/logging.h"
#include "base/string_util.h"
using base::Time;
using base::TimeDelta;
using base::TimeTicks;
namespace chrome_browser_net {
static bool detailed_logging_enabled = false;
// Use command line switch to enable detailed logging.
void EnableDnsDetailedLog(bool enable) {
detailed_logging_enabled = enable;
}
// static
int DnsHostInfo::sequence_counter = 1;
bool DnsHostInfo::NeedsDnsUpdate(const std::string& hostname) {
DCHECK(hostname == hostname_);
switch (state_) {
case PENDING: // Just now created info.
return true;
case QUEUED: // In queue.
case ASSIGNED: // It's being resolved.
case ASSIGNED_BUT_MARKED: // It's being resolved.
return false; // We're already working on it
case NO_SUCH_NAME: // Lookup failed.
case FOUND: // Lookup succeeded.
return !IsStillCached(); // See if DNS cache expired.
default:
DCHECK(false);
return false;
}
}
const TimeDelta DnsHostInfo::kNullDuration(TimeDelta::FromMilliseconds(-1));
// Common low end TTL for sites is 5 minutes. However, DNS servers give us
// the remaining time, not the original 5 minutes. Hence it doesn't much matter
// whether we found something in the local cache, or an ISP cache, it will
// on average be 2.5 minutes before it expires. We could try to model this with
// 180 seconds, but simpler is just to do the lookups all the time (wasting
// OS calls(?)), and let that OS cache decide what to do (with TTL in hand).
// We use a small time to help get some duplicate suppression, in case a page
// has a TON of copies of the same domain name, so that we don't thrash the OS
// to death. Hopefully it is small enough that we're not hurting our cache hit
// rate (i.e., we could always ask the OS).
TimeDelta DnsHostInfo::kCacheExpirationDuration(TimeDelta::FromSeconds(5));
const TimeDelta DnsHostInfo::kMaxNonNetworkDnsLookupDuration(
TimeDelta::FromMilliseconds(15));
// Used by test ONLY. The value is otherwise constant.
void DnsHostInfo::set_cache_expiration(TimeDelta time) {
kCacheExpirationDuration = time;
}
void DnsHostInfo::SetQueuedState(ResolutionMotivation motivation) {
DCHECK(PENDING == state_ || FOUND == state_ || NO_SUCH_NAME == state_);
old_prequeue_state_ = state_;
state_ = QUEUED;
queue_duration_ = resolve_duration_ = kNullDuration;
SetMotivation(motivation);
GetDuration(); // Set time_
DLogResultsStats("DNS Prefetch in queue");
}
void DnsHostInfo::SetAssignedState() {
DCHECK(QUEUED == state_);
state_ = ASSIGNED;
queue_duration_ = GetDuration();
DLogResultsStats("DNS Prefetch assigned");
UMA_HISTOGRAM_TIMES("DNS.PrefetchQueue", queue_duration_);
}
void DnsHostInfo::RemoveFromQueue() {
DCHECK(ASSIGNED == state_);
state_ = old_prequeue_state_;
DLogResultsStats("DNS Prefetch reset to prequeue");
static const TimeDelta kBoundary = TimeDelta::FromSeconds(2);
if (queue_duration_ > kBoundary) {
UMA_HISTOGRAM_MEDIUM_TIMES("DNS.QueueRecycledDeltaOver2",
queue_duration_ - kBoundary);
return;
}
// Make a custom linear histogram for the region from 0 to boundary.
const size_t kBucketCount = 52;
static LinearHistogram histogram("DNS.QueueRecycledUnder2", TimeDelta(),
kBoundary, kBucketCount);
histogram.SetFlags(kUmaTargetedHistogramFlag);
histogram.AddTime(queue_duration_);
}
void DnsHostInfo::SetPendingDeleteState() {
DCHECK(ASSIGNED == state_ || ASSIGNED_BUT_MARKED == state_);
state_ = ASSIGNED_BUT_MARKED;
}
void DnsHostInfo::SetFoundState() {
DCHECK(ASSIGNED == state_);
state_ = FOUND;
resolve_duration_ = GetDuration();
if (kMaxNonNetworkDnsLookupDuration <= resolve_duration_) {
UMA_HISTOGRAM_LONG_TIMES("DNS.PrefetchFoundNameL", resolve_duration_);
// Record potential beneficial time, and maybe we'll get a cache hit.
// We keep the maximum, as the warming we did earlier may still be
// helping with a cache upstream in DNS resolution.
benefits_remaining_ = std::max(resolve_duration_, benefits_remaining_);
}
sequence_number_ = sequence_counter++;
DLogResultsStats("DNS PrefetchFound");
}
void DnsHostInfo::SetNoSuchNameState() {
DCHECK(ASSIGNED == state_);
state_ = NO_SUCH_NAME;
resolve_duration_ = GetDuration();
if (kMaxNonNetworkDnsLookupDuration <= resolve_duration_) {
DHISTOGRAM_TIMES("DNS.PrefetchNotFoundName", resolve_duration_);
// Record potential beneficial time, and maybe we'll get a cache hit.
benefits_remaining_ = std::max(resolve_duration_, benefits_remaining_);
}
sequence_number_ = sequence_counter++;
DLogResultsStats("DNS PrefetchNotFound");
}
void DnsHostInfo::SetStartedState() {
DCHECK(PENDING == state_);
state_ = STARTED;
queue_duration_ = resolve_duration_ = TimeDelta(); // 0ms.
SetMotivation(NO_PREFETCH_MOTIVATION);
GetDuration(); // Set time.
}
void DnsHostInfo::SetFinishedState(bool was_resolved) {
DCHECK(STARTED == state_);
state_ = was_resolved ? FINISHED : FINISHED_UNRESOLVED;
resolve_duration_ = GetDuration();
// TODO(jar): Sequence number should be incremented in prefetched HostInfo.
DLogResultsStats("DNS HTTP Finished");
}
void DnsHostInfo::SetHostname(const std::string& hostname) {
if (hostname != hostname_) {
DCHECK_EQ(hostname_.size(), 0u); // Not yet initialized.
hostname_ = hostname;
}
}
// IsStillCached() guesses if the DNS cache still has IP data,
// or at least remembers results about "not finding host."
bool DnsHostInfo::IsStillCached() const {
DCHECK(FOUND == state_ || NO_SUCH_NAME == state_);
// Default MS OS does not cache failures. Hence we could return false almost
// all the time for that case. However, we'd never try again to prefetch
// the value if we returned false that way. Hence we'll just let the lookup
// time out the same way as FOUND case.
if (sequence_counter - sequence_number_ > kMaxGuaranteedCacheSize)
return false;
TimeDelta time_since_resolution = TimeTicks::Now() - time_;
return time_since_resolution < kCacheExpirationDuration;
}
// Compare the actual navigation DNS latency found in navigation_info, to the
// previously prefetched info.
DnsBenefit DnsHostInfo::AccruePrefetchBenefits(DnsHostInfo* navigation_info) {
DCHECK(FINISHED == navigation_info->state_ ||
FINISHED_UNRESOLVED == navigation_info->state_);
DCHECK_EQ(navigation_info->hostname_, hostname_.data());
if ((0 == benefits_remaining_.InMilliseconds()) ||
(FOUND != state_ && NO_SUCH_NAME != state_)) {
if (FINISHED == navigation_info->state_)
UMA_HISTOGRAM_LONG_TIMES("DNS.IndependentNavigation",
navigation_info->resolve_duration_);
else
UMA_HISTOGRAM_LONG_TIMES("DNS.IndependentFailedNavigation",
navigation_info->resolve_duration_);
return PREFETCH_NO_BENEFIT;
}
TimeDelta benefit = benefits_remaining_ - navigation_info->resolve_duration_;
navigation_info->benefits_remaining_ = benefits_remaining_;
benefits_remaining_ = TimeDelta(); // We used up all our benefits here.
navigation_info->motivation_ = motivation_;
if (LEARNED_REFERAL_MOTIVATED == motivation_ ||
STATIC_REFERAL_MOTIVATED == motivation_)
navigation_info->referring_hostname_ = referring_hostname_;
if (navigation_info->resolve_duration_ > kMaxNonNetworkDnsLookupDuration) {
// Our precache effort didn't help since HTTP stack hit the network.
UMA_HISTOGRAM_LONG_TIMES("DNS.PrefetchCacheEvictionL", resolve_duration_);
DLogResultsStats("DNS PrefetchCacheEviction");
return PREFETCH_CACHE_EVICTION;
}
if (NO_SUCH_NAME == state_) {
UMA_HISTOGRAM_LONG_TIMES("DNS.PrefetchNegativeHitL", benefit);
DLogResultsStats("DNS PrefetchNegativeHit");
return PREFETCH_NAME_NONEXISTANT;
}
DCHECK_EQ(FOUND, state_);
if (LEARNED_REFERAL_MOTIVATED == motivation_ ||
STATIC_REFERAL_MOTIVATED == motivation_) {
UMA_HISTOGRAM_TIMES("DNS.PrefetchReferredPositiveHit", benefit);
DLogResultsStats("DNS PrefetchReferredPositiveHit");
} else {
UMA_HISTOGRAM_LONG_TIMES("DNS.PrefetchPositiveHitL", benefit);
DLogResultsStats("DNS PrefetchPositiveHit");
}
return PREFETCH_NAME_FOUND;
}
void DnsHostInfo::DLogResultsStats(const char* message) const {
if (!detailed_logging_enabled)
return;
DLOG(INFO) << "\t" << message << "\tq="
<< queue_duration().InMilliseconds() << "ms,\tr="
<< resolve_duration().InMilliseconds() << "ms\tp="
<< benefits_remaining_.InMilliseconds() << "ms\tseq="
<< sequence_number_
<< "\t" << hostname_;
}
//------------------------------------------------------------------------------
// This last section supports HTML output, such as seen in about:dns.
//------------------------------------------------------------------------------
// Preclude any possibility of Java Script or markup in the text, by only
// allowing alphanumerics, '.', '-', ':', and whitespace.
static std::string RemoveJs(const std::string& text) {
std::string output(text);
size_t length = output.length();
for (size_t i = 0; i < length; i++) {
char next = output[i];
if (isalnum(next) || isspace(next) || strchr(".-:", next) != NULL)
continue;
output[i] = '?';
}
return output;
}
class MinMaxAverage {
public:
MinMaxAverage()
: sum_(0), square_sum_(0), count_(0),
minimum_(kint64max), maximum_(kint64min) {
}
// Return values for use in printf formatted as "%d"
int sample(int64 value) {
sum_ += value;
square_sum_ += value * value;
count_++;
minimum_ = std::min(minimum_, value);
maximum_ = std::max(maximum_, value);
return static_cast<int>(value);
}
int minimum() const { return static_cast<int>(minimum_); }
int maximum() const { return static_cast<int>(maximum_); }
int average() const { return static_cast<int>(sum_/count_); }
int sum() const { return static_cast<int>(sum_); }
int standard_deviation() const {
double average = static_cast<float>(sum_) / count_;
double variance = static_cast<float>(square_sum_)/count_
- average * average;
return static_cast<int>(floor(sqrt(variance) + .5));
}
private:
int64 sum_;
int64 square_sum_;
int count_;
int64 minimum_;
int64 maximum_;
// DISALLOW_COPY_AND_ASSIGN(MinMaxAverage);
};
static std::string HoursMinutesSeconds(int seconds) {
std::string result;
int print_seconds = seconds % 60;
int minutes = seconds / 60;
int print_minutes = minutes % 60;
int print_hours = minutes/60;
if (print_hours)
StringAppendF(&result, "%.2d:", print_hours);
if (print_hours || print_minutes)
StringAppendF(&result, "%2.2d:", print_minutes);
StringAppendF(&result, "%2.2d", print_seconds);
return result;
}
// static
void DnsHostInfo::GetHtmlTable(const DnsInfoTable host_infos,
const char* description,
const bool brief,
std::string* output) {
if (0 == host_infos.size())
return;
output->append(description);
StringAppendF(output, "%" PRIuS " %s", host_infos.size(),
(1 == host_infos.size()) ? "hostname" : "hostnames");
if (brief) {
output->append("<br><br>");
return;
}
const char* row_format = "<tr align=right><td>%s</td>"
"<td>%d</td><td>%d</td><td>%s</td><td>%s</td></tr>";
output->append("<br><table border=1>");
StringAppendF(output,
"<tr><th>%s</th><th>%s</th><th>%s</th><th>%s</th><th>%s</th></tr>",
"Host name", "Applicable Prefetch<br>Time (ms)",
"Recent Resolution<br>Time(ms)", "How long ago<br>(HH:MM:SS)",
"Motivation");
// Print bulk of table, and gather stats at same time.
MinMaxAverage queue, resolve, preresolve, when;
TimeTicks current_time = TimeTicks::Now();
for (DnsInfoTable::const_iterator it(host_infos.begin());
it != host_infos.end(); it++) {
queue.sample((it->queue_duration_.InMilliseconds()));
StringAppendF(output, row_format,
RemoveJs(it->hostname_).c_str(),
preresolve.sample((it->benefits_remaining_.InMilliseconds())),
resolve.sample((it->resolve_duration_.InMilliseconds())),
HoursMinutesSeconds(when.sample(
(current_time - it->time_).InSeconds())).c_str(),
it->GetAsciiMotivation().c_str());
}
// Write min, max, and average summary lines.
if (host_infos.size() > 2) {
output->append("<B>");
StringAppendF(output, row_format,
"<b>---minimum---</b>",
preresolve.minimum(), resolve.minimum(),
HoursMinutesSeconds(when.minimum()).c_str(), "");
StringAppendF(output, row_format,
"<b>---average---</b>",
preresolve.average(), resolve.average(),
HoursMinutesSeconds(when.average()).c_str(), "");
StringAppendF(output, row_format,
"<b>standard deviation</b>",
preresolve.standard_deviation(),
resolve.standard_deviation(), "n/a", "");
StringAppendF(output, row_format,
"<b>---maximum---</b>",
preresolve.maximum(), resolve.maximum(),
HoursMinutesSeconds(when.maximum()).c_str(), "");
StringAppendF(output, row_format,
"<b>-----SUM-----</b>",
preresolve.sum(), resolve.sum(), "n/a", "");
}
output->append("</table>");
#ifdef DEBUG
StringAppendF(output,
"Prefetch Queue Durations: min=%d, avg=%d, max=%d<br><br>",
queue.minimum(), queue.average(), queue.maximum());
#endif
output->append("<br>");
}
void DnsHostInfo::SetMotivation(ResolutionMotivation motivation) {
motivation_ = motivation;
if (motivation < LINKED_MAX_MOTIVATED)
was_linked_ = true;
}
std::string DnsHostInfo::GetAsciiMotivation() const {
switch (motivation_) {
case MOUSE_OVER_MOTIVATED:
return "[mouse-over]";
case PAGE_SCAN_MOTIVATED:
return "[page scan]";
case OMNIBOX_MOTIVATED:
return "[omnibox]";
case STARTUP_LIST_MOTIVATED:
return "[startup list]";
case NO_PREFETCH_MOTIVATION:
return "n/a";
case STATIC_REFERAL_MOTIVATED:
return RemoveJs(referring_hostname_) + "*";
case LEARNED_REFERAL_MOTIVATED:
return RemoveJs(referring_hostname_);
default:
return "";
}
}
} // namespace chrome_browser_net