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
MaxNonNetworkDnsLookupDuration()43 TimeDelta MaxNonNetworkDnsLookupDuration() {
44 return TimeDelta::FromMilliseconds(15);
45 }
46
47 bool detailed_logging_enabled = false;
48
49 struct GlobalState {
GlobalStatechrome_browser_net::__anon5f7a446a0111::GlobalState50 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.
EnablePredictorDetailedLog(bool enable)62 void EnablePredictorDetailedLog(bool enable) {
63 detailed_logging_enabled = enable;
64 }
65
66 // static
67 int UrlInfo::sequence_counter = 1;
68
UrlInfo()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
~UrlInfo()79 UrlInfo::~UrlInfo() {}
80
NeedsDnsUpdate()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
set_cache_expiration(TimeDelta time)103 void UrlInfo::set_cache_expiration(TimeDelta time) {
104 global_state.Pointer()->cache_expiration_duration = time;
105 }
106
107 // static
get_cache_expiration()108 TimeDelta UrlInfo::get_cache_expiration() {
109 return global_state.Get().cache_expiration_duration;
110 }
111
SetQueuedState(ResolutionMotivation motivation)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
SetAssignedState()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
RemoveFromQueue()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
SetPendingDeleteState()150 void UrlInfo::SetPendingDeleteState() {
151 DCHECK(ASSIGNED == state_ || ASSIGNED_BUT_MARKED == state_);
152 state_ = ASSIGNED_BUT_MARKED;
153 }
154
SetFoundState()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
SetNoSuchNameState()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
SetUrl(const GURL & url)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."
IsStillCached() const190 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
DLogResultsStats(const char * message) const205 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.
RemoveJs(const std::string & text)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:
MinMaxAverage()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"
sample(int64 value)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 }
minimum() const247 int minimum() const { return static_cast<int>(minimum_); }
maximum() const248 int maximum() const { return static_cast<int>(maximum_); }
average() const249 int average() const { return static_cast<int>(sum_/count_); }
sum() const250 int sum() const { return static_cast<int>(sum_); }
251
standard_deviation() const252 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
HoursMinutesSeconds(int seconds)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
GetHtmlTable(const UrlInfoTable & host_infos,const char * description,bool brief,std::string * output)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
SetMotivation(ResolutionMotivation motivation)336 void UrlInfo::SetMotivation(ResolutionMotivation motivation) {
337 motivation_ = motivation;
338 if (motivation < LINKED_MAX_MOTIVATED)
339 was_linked_ = true;
340 }
341
GetAsciiMotivation() const342 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
371