| OLD | NEW |
|---|
| (Empty) |
| 1 // Copyright (c) 2006-2010 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/dns_host_info.h" | |
| 6 | |
| 7 #include <math.h> | |
| 8 | |
| 9 #include <algorithm> | |
| 10 #include <string> | |
| 11 | |
| 12 #include "base/field_trial.h" | |
| 13 #include "base/format_macros.h" | |
| 14 #include "base/histogram.h" | |
| 15 #include "base/logging.h" | |
| 16 #include "base/string_util.h" | |
| 17 | |
| 18 using base::Time; | |
| 19 using base::TimeDelta; | |
| 20 using base::TimeTicks; | |
| 21 | |
| 22 namespace chrome_browser_net { | |
| 23 | |
| 24 static bool detailed_logging_enabled = false; | |
| 25 | |
| 26 // Use command line switch to enable detailed logging. | |
| 27 void EnablePredictorDetailedLog(bool enable) { | |
| 28 detailed_logging_enabled = enable; | |
| 29 } | |
| 30 | |
| 31 // static | |
| 32 int UrlInfo::sequence_counter = 1; | |
| 33 | |
| 34 | |
| 35 bool UrlInfo::NeedsDnsUpdate() { | |
| 36 switch (state_) { | |
| 37 case PENDING: // Just now created info. | |
| 38 return true; | |
| 39 | |
| 40 case QUEUED: // In queue. | |
| 41 case ASSIGNED: // It's being resolved. | |
| 42 case ASSIGNED_BUT_MARKED: // It's being resolved. | |
| 43 return false; // We're already working on it | |
| 44 | |
| 45 case NO_SUCH_NAME: // Lookup failed. | |
| 46 case FOUND: // Lookup succeeded. | |
| 47 return !IsStillCached(); // See if DNS cache expired. | |
| 48 | |
| 49 default: | |
| 50 NOTREACHED(); | |
| 51 return false; | |
| 52 } | |
| 53 } | |
| 54 | |
| 55 const TimeDelta UrlInfo::kNullDuration(TimeDelta::FromMilliseconds(-1)); | |
| 56 | |
| 57 // Common low end TTL for sites is 5 minutes. However, DNS servers give us | |
| 58 // the remaining time, not the original 5 minutes. Hence it doesn't much matter | |
| 59 // whether we found something in the local cache, or an ISP cache, it will | |
| 60 // on average be 2.5 minutes before it expires. We could try to model this with | |
| 61 // 180 seconds, but simpler is just to do the lookups all the time (wasting | |
| 62 // OS calls(?)), and let that OS cache decide what to do (with TTL in hand). | |
| 63 // We use a small time to help get some duplicate suppression, in case a page | |
| 64 // has a TON of copies of the same domain name, so that we don't thrash the OS | |
| 65 // to death. Hopefully it is small enough that we're not hurting our cache hit | |
| 66 // rate (i.e., we could always ask the OS). | |
| 67 TimeDelta UrlInfo::kCacheExpirationDuration(TimeDelta::FromSeconds(5)); | |
| 68 | |
| 69 const TimeDelta UrlInfo::kMaxNonNetworkDnsLookupDuration( | |
| 70 TimeDelta::FromMilliseconds(15)); | |
| 71 | |
| 72 // Used by test ONLY. The value is otherwise constant. | |
| 73 void UrlInfo::set_cache_expiration(TimeDelta time) { | |
| 74 kCacheExpirationDuration = time; | |
| 75 } | |
| 76 | |
| 77 void UrlInfo::SetQueuedState(ResolutionMotivation motivation) { | |
| 78 DCHECK(PENDING == state_ || FOUND == state_ || NO_SUCH_NAME == state_); | |
| 79 old_prequeue_state_ = state_; | |
| 80 state_ = QUEUED; | |
| 81 queue_duration_ = resolve_duration_ = kNullDuration; | |
| 82 SetMotivation(motivation); | |
| 83 GetDuration(); // Set time_ | |
| 84 DLogResultsStats("DNS Prefetch in queue"); | |
| 85 } | |
| 86 | |
| 87 void UrlInfo::SetAssignedState() { | |
| 88 DCHECK(QUEUED == state_); | |
| 89 state_ = ASSIGNED; | |
| 90 queue_duration_ = GetDuration(); | |
| 91 DLogResultsStats("DNS Prefetch assigned"); | |
| 92 UMA_HISTOGRAM_TIMES("DNS.PrefetchQueue", queue_duration_); | |
| 93 } | |
| 94 | |
| 95 void UrlInfo::RemoveFromQueue() { | |
| 96 DCHECK(ASSIGNED == state_); | |
| 97 state_ = old_prequeue_state_; | |
| 98 DLogResultsStats("DNS Prefetch reset to prequeue"); | |
| 99 static const TimeDelta kBoundary = TimeDelta::FromSeconds(2); | |
| 100 if (queue_duration_ > kBoundary) { | |
| 101 UMA_HISTOGRAM_MEDIUM_TIMES("DNS.QueueRecycledDeltaOver2", | |
| 102 queue_duration_ - kBoundary); | |
| 103 return; | |
| 104 } | |
| 105 // Make a custom linear histogram for the region from 0 to boundary. | |
| 106 const size_t kBucketCount = 52; | |
| 107 static scoped_refptr<Histogram> histogram = LinearHistogram::FactoryGet( | |
| 108 "DNS.QueueRecycledUnder2", TimeDelta(), kBoundary, kBucketCount, | |
| 109 Histogram::kUmaTargetedHistogramFlag); | |
| 110 histogram->AddTime(queue_duration_); | |
| 111 } | |
| 112 | |
| 113 void UrlInfo::SetPendingDeleteState() { | |
| 114 DCHECK(ASSIGNED == state_ || ASSIGNED_BUT_MARKED == state_); | |
| 115 state_ = ASSIGNED_BUT_MARKED; | |
| 116 } | |
| 117 | |
| 118 void UrlInfo::SetFoundState() { | |
| 119 DCHECK(ASSIGNED == state_); | |
| 120 state_ = FOUND; | |
| 121 resolve_duration_ = GetDuration(); | |
| 122 if (kMaxNonNetworkDnsLookupDuration <= resolve_duration_) { | |
| 123 UMA_HISTOGRAM_CUSTOM_TIMES("DNS.PrefetchResolution", resolve_duration_, | |
| 124 kMaxNonNetworkDnsLookupDuration, TimeDelta::FromMinutes(15), 100); | |
| 125 | |
| 126 static bool use_ipv6_histogram(FieldTrialList::Find("IPv6_Probe") && | |
| 127 !FieldTrialList::Find("IPv6_Probe")->group_name().empty()); | |
| 128 if (use_ipv6_histogram) { | |
| 129 UMA_HISTOGRAM_CUSTOM_TIMES( | |
| 130 FieldTrial::MakeName("DNS.PrefetchResolution", "IPv6_Probe"), | |
| 131 resolve_duration_, kMaxNonNetworkDnsLookupDuration, | |
| 132 TimeDelta::FromMinutes(15), 100); | |
| 133 } | |
| 134 | |
| 135 // Record potential beneficial time, and maybe we'll get a cache hit. | |
| 136 // We keep the maximum, as the warming we did earlier may still be | |
| 137 // helping with a cache upstream in DNS resolution. | |
| 138 benefits_remaining_ = std::max(resolve_duration_, benefits_remaining_); | |
| 139 } | |
| 140 sequence_number_ = sequence_counter++; | |
| 141 DLogResultsStats("DNS PrefetchFound"); | |
| 142 } | |
| 143 | |
| 144 void UrlInfo::SetNoSuchNameState() { | |
| 145 DCHECK(ASSIGNED == state_); | |
| 146 state_ = NO_SUCH_NAME; | |
| 147 resolve_duration_ = GetDuration(); | |
| 148 if (kMaxNonNetworkDnsLookupDuration <= resolve_duration_) { | |
| 149 DHISTOGRAM_TIMES("DNS.PrefetchNotFoundName", resolve_duration_); | |
| 150 // Record potential beneficial time, and maybe we'll get a cache hit. | |
| 151 benefits_remaining_ = std::max(resolve_duration_, benefits_remaining_); | |
| 152 } | |
| 153 sequence_number_ = sequence_counter++; | |
| 154 DLogResultsStats("DNS PrefetchNotFound"); | |
| 155 } | |
| 156 | |
| 157 void UrlInfo::SetStartedState() { | |
| 158 DCHECK(PENDING == state_); | |
| 159 state_ = STARTED; | |
| 160 queue_duration_ = resolve_duration_ = TimeDelta(); // 0ms. | |
| 161 SetMotivation(NO_PREFETCH_MOTIVATION); | |
| 162 GetDuration(); // Set time. | |
| 163 } | |
| 164 | |
| 165 void UrlInfo::SetFinishedState(bool was_resolved) { | |
| 166 DCHECK(STARTED == state_); | |
| 167 state_ = was_resolved ? FINISHED : FINISHED_UNRESOLVED; | |
| 168 resolve_duration_ = GetDuration(); | |
| 169 // TODO(jar): Sequence number should be incremented in prefetched HostInfo. | |
| 170 DLogResultsStats("DNS HTTP Finished"); | |
| 171 } | |
| 172 | |
| 173 void UrlInfo::SetUrl(const GURL& url) { | |
| 174 if (url_.is_empty()) // Not yet initialized. | |
| 175 url_ = url; | |
| 176 else | |
| 177 DCHECK_EQ(url_, url); | |
| 178 } | |
| 179 | |
| 180 // IsStillCached() guesses if the DNS cache still has IP data, | |
| 181 // or at least remembers results about "not finding host." | |
| 182 bool UrlInfo::IsStillCached() const { | |
| 183 DCHECK(FOUND == state_ || NO_SUCH_NAME == state_); | |
| 184 | |
| 185 // Default MS OS does not cache failures. Hence we could return false almost | |
| 186 // all the time for that case. However, we'd never try again to prefetch | |
| 187 // the value if we returned false that way. Hence we'll just let the lookup | |
| 188 // time out the same way as FOUND case. | |
| 189 | |
| 190 if (sequence_counter - sequence_number_ > kMaxGuaranteedDnsCacheSize) | |
| 191 return false; | |
| 192 | |
| 193 TimeDelta time_since_resolution = TimeTicks::Now() - time_; | |
| 194 | |
| 195 return time_since_resolution < kCacheExpirationDuration; | |
| 196 } | |
| 197 | |
| 198 // Compare the actual navigation DNS latency found in navigation_info, to the | |
| 199 // previously prefetched info. | |
| 200 DnsBenefit UrlInfo::AccruePrefetchBenefits(UrlInfo* navigation_info) { | |
| 201 DCHECK(FINISHED == navigation_info->state_ || | |
| 202 FINISHED_UNRESOLVED == navigation_info->state_); | |
| 203 DCHECK(navigation_info->url() == url_); | |
| 204 | |
| 205 if ((0 == benefits_remaining_.InMilliseconds()) || | |
| 206 (FOUND != state_ && NO_SUCH_NAME != state_)) { | |
| 207 if (FINISHED == navigation_info->state_) | |
| 208 UMA_HISTOGRAM_LONG_TIMES("DNS.IndependentNavigation", | |
| 209 navigation_info->resolve_duration_); | |
| 210 else | |
| 211 UMA_HISTOGRAM_LONG_TIMES("DNS.IndependentFailedNavigation", | |
| 212 navigation_info->resolve_duration_); | |
| 213 return PREFETCH_NO_BENEFIT; | |
| 214 } | |
| 215 | |
| 216 TimeDelta benefit = benefits_remaining_ - navigation_info->resolve_duration_; | |
| 217 navigation_info->benefits_remaining_ = benefits_remaining_; | |
| 218 benefits_remaining_ = TimeDelta(); // We used up all our benefits here. | |
| 219 | |
| 220 navigation_info->motivation_ = motivation_; | |
| 221 if (LEARNED_REFERAL_MOTIVATED == motivation_ || | |
| 222 STATIC_REFERAL_MOTIVATED == motivation_) | |
| 223 navigation_info->referring_url_ = referring_url_; | |
| 224 | |
| 225 if (navigation_info->resolve_duration_ > kMaxNonNetworkDnsLookupDuration) { | |
| 226 // Our precache effort didn't help since HTTP stack hit the network. | |
| 227 UMA_HISTOGRAM_LONG_TIMES("DNS.PrefetchCacheEvictionL", resolve_duration_); | |
| 228 DLogResultsStats("DNS PrefetchCacheEviction"); | |
| 229 return PREFETCH_CACHE_EVICTION; | |
| 230 } | |
| 231 | |
| 232 if (NO_SUCH_NAME == state_) { | |
| 233 UMA_HISTOGRAM_LONG_TIMES("DNS.PrefetchNegativeHitL", benefit); | |
| 234 DLogResultsStats("DNS PrefetchNegativeHit"); | |
| 235 return PREFETCH_NAME_NONEXISTANT; | |
| 236 } | |
| 237 | |
| 238 DCHECK_EQ(FOUND, state_); | |
| 239 if (LEARNED_REFERAL_MOTIVATED == motivation_ || | |
| 240 STATIC_REFERAL_MOTIVATED == motivation_) { | |
| 241 UMA_HISTOGRAM_TIMES("DNS.PrefetchReferredPositiveHit", benefit); | |
| 242 DLogResultsStats("DNS PrefetchReferredPositiveHit"); | |
| 243 } else { | |
| 244 UMA_HISTOGRAM_LONG_TIMES("DNS.PrefetchPositiveHitL", benefit); | |
| 245 DLogResultsStats("DNS PrefetchPositiveHit"); | |
| 246 } | |
| 247 return PREFETCH_NAME_FOUND; | |
| 248 } | |
| 249 | |
| 250 void UrlInfo::DLogResultsStats(const char* message) const { | |
| 251 if (!detailed_logging_enabled) | |
| 252 return; | |
| 253 DLOG(INFO) << "\t" << message << "\tq=" | |
| 254 << queue_duration().InMilliseconds() << "ms,\tr=" | |
| 255 << resolve_duration().InMilliseconds() << "ms\tp=" | |
| 256 << benefits_remaining_.InMilliseconds() << "ms\tseq=" | |
| 257 << sequence_number_ | |
| 258 << "\t" << url_.spec(); | |
| 259 } | |
| 260 | |
| 261 //------------------------------------------------------------------------------ | |
| 262 // This last section supports HTML output, such as seen in about:dns. | |
| 263 //------------------------------------------------------------------------------ | |
| 264 | |
| 265 // Preclude any possibility of Java Script or markup in the text, by only | |
| 266 // allowing alphanumerics, '.', '-', ':', and whitespace. | |
| 267 static std::string RemoveJs(const std::string& text) { | |
| 268 std::string output(text); | |
| 269 size_t length = output.length(); | |
| 270 for (size_t i = 0; i < length; i++) { | |
| 271 char next = output[i]; | |
| 272 if (isalnum(next) || isspace(next) || strchr(".-:/", next) != NULL) | |
| 273 continue; | |
| 274 output[i] = '?'; | |
| 275 } | |
| 276 return output; | |
| 277 } | |
| 278 | |
| 279 class MinMaxAverage { | |
| 280 public: | |
| 281 MinMaxAverage() | |
| 282 : sum_(0), square_sum_(0), count_(0), | |
| 283 minimum_(kint64max), maximum_(kint64min) { | |
| 284 } | |
| 285 | |
| 286 // Return values for use in printf formatted as "%d" | |
| 287 int sample(int64 value) { | |
| 288 sum_ += value; | |
| 289 square_sum_ += value * value; | |
| 290 count_++; | |
| 291 minimum_ = std::min(minimum_, value); | |
| 292 maximum_ = std::max(maximum_, value); | |
| 293 return static_cast<int>(value); | |
| 294 } | |
| 295 int minimum() const { return static_cast<int>(minimum_); } | |
| 296 int maximum() const { return static_cast<int>(maximum_); } | |
| 297 int average() const { return static_cast<int>(sum_/count_); } | |
| 298 int sum() const { return static_cast<int>(sum_); } | |
| 299 | |
| 300 int standard_deviation() const { | |
| 301 double average = static_cast<float>(sum_) / count_; | |
| 302 double variance = static_cast<float>(square_sum_)/count_ | |
| 303 - average * average; | |
| 304 return static_cast<int>(floor(sqrt(variance) + .5)); | |
| 305 } | |
| 306 | |
| 307 private: | |
| 308 int64 sum_; | |
| 309 int64 square_sum_; | |
| 310 int count_; | |
| 311 int64 minimum_; | |
| 312 int64 maximum_; | |
| 313 | |
| 314 // DISALLOW_COPY_AND_ASSIGN(MinMaxAverage); | |
| 315 }; | |
| 316 | |
| 317 static std::string HoursMinutesSeconds(int seconds) { | |
| 318 std::string result; | |
| 319 int print_seconds = seconds % 60; | |
| 320 int minutes = seconds / 60; | |
| 321 int print_minutes = minutes % 60; | |
| 322 int print_hours = minutes/60; | |
| 323 if (print_hours) | |
| 324 StringAppendF(&result, "%.2d:", print_hours); | |
| 325 if (print_hours || print_minutes) | |
| 326 StringAppendF(&result, "%2.2d:", print_minutes); | |
| 327 StringAppendF(&result, "%2.2d", print_seconds); | |
| 328 return result; | |
| 329 } | |
| 330 | |
| 331 // static | |
| 332 void UrlInfo::GetHtmlTable(const DnsInfoTable host_infos, | |
| 333 const char* description, | |
| 334 const bool brief, | |
| 335 std::string* output) { | |
| 336 if (0 == host_infos.size()) | |
| 337 return; | |
| 338 output->append(description); | |
| 339 StringAppendF(output, "%" PRIuS " %s", host_infos.size(), | |
| 340 (1 == host_infos.size()) ? "hostname" : "hostnames"); | |
| 341 | |
| 342 if (brief) { | |
| 343 output->append("<br><br>"); | |
| 344 return; | |
| 345 } | |
| 346 | |
| 347 const char* row_format = "<tr align=right><td>%s</td>" | |
| 348 "<td>%d</td><td>%d</td><td>%s</td><td>%s</td></tr>"; | |
| 349 | |
| 350 output->append("<br><table border=1>"); | |
| 351 StringAppendF(output, | |
| 352 "<tr><th>%s</th><th>%s</th><th>%s</th><th>%s</th><th>%s</th></tr>", | |
| 353 "Host name", "Applicable Prefetch<br>Time (ms)", | |
| 354 "Recent Resolution<br>Time(ms)", "How long ago<br>(HH:MM:SS)", | |
| 355 "Motivation"); | |
| 356 | |
| 357 // Print bulk of table, and gather stats at same time. | |
| 358 MinMaxAverage queue, resolve, preresolve, when; | |
| 359 TimeTicks current_time = TimeTicks::Now(); | |
| 360 for (DnsInfoTable::const_iterator it(host_infos.begin()); | |
| 361 it != host_infos.end(); it++) { | |
| 362 queue.sample((it->queue_duration_.InMilliseconds())); | |
| 363 StringAppendF(output, row_format, | |
| 364 RemoveJs(it->url_.spec()).c_str(), | |
| 365 preresolve.sample((it->benefits_remaining_.InMilliseconds())), | |
| 366 resolve.sample((it->resolve_duration_.InMilliseconds())), | |
| 367 HoursMinutesSeconds(when.sample( | |
| 368 (current_time - it->time_).InSeconds())).c_str(), | |
| 369 it->GetAsciiMotivation().c_str()); | |
| 370 } | |
| 371 // Write min, max, and average summary lines. | |
| 372 if (host_infos.size() > 2) { | |
| 373 output->append("<B>"); | |
| 374 StringAppendF(output, row_format, | |
| 375 "<b>---minimum---</b>", | |
| 376 preresolve.minimum(), resolve.minimum(), | |
| 377 HoursMinutesSeconds(when.minimum()).c_str(), ""); | |
| 378 StringAppendF(output, row_format, | |
| 379 "<b>---average---</b>", | |
| 380 preresolve.average(), resolve.average(), | |
| 381 HoursMinutesSeconds(when.average()).c_str(), ""); | |
| 382 StringAppendF(output, row_format, | |
| 383 "<b>standard deviation</b>", | |
| 384 preresolve.standard_deviation(), | |
| 385 resolve.standard_deviation(), "n/a", ""); | |
| 386 StringAppendF(output, row_format, | |
| 387 "<b>---maximum---</b>", | |
| 388 preresolve.maximum(), resolve.maximum(), | |
| 389 HoursMinutesSeconds(when.maximum()).c_str(), ""); | |
| 390 StringAppendF(output, row_format, | |
| 391 "<b>-----SUM-----</b>", | |
| 392 preresolve.sum(), resolve.sum(), "n/a", ""); | |
| 393 } | |
| 394 output->append("</table>"); | |
| 395 | |
| 396 #ifdef DEBUG | |
| 397 StringAppendF(output, | |
| 398 "Prefetch Queue Durations: min=%d, avg=%d, max=%d<br><br>", | |
| 399 queue.minimum(), queue.average(), queue.maximum()); | |
| 400 #endif | |
| 401 | |
| 402 output->append("<br>"); | |
| 403 } | |
| 404 | |
| 405 void UrlInfo::SetMotivation(ResolutionMotivation motivation) { | |
| 406 motivation_ = motivation; | |
| 407 if (motivation < LINKED_MAX_MOTIVATED) | |
| 408 was_linked_ = true; | |
| 409 } | |
| 410 | |
| 411 std::string UrlInfo::GetAsciiMotivation() const { | |
| 412 switch (motivation_) { | |
| 413 case MOUSE_OVER_MOTIVATED: | |
| 414 return "[mouse-over]"; | |
| 415 | |
| 416 case PAGE_SCAN_MOTIVATED: | |
| 417 return "[page scan]"; | |
| 418 | |
| 419 case OMNIBOX_MOTIVATED: | |
| 420 return "[omnibox]"; | |
| 421 | |
| 422 case STARTUP_LIST_MOTIVATED: | |
| 423 return "[startup list]"; | |
| 424 | |
| 425 case NO_PREFETCH_MOTIVATION: | |
| 426 return "n/a"; | |
| 427 | |
| 428 case STATIC_REFERAL_MOTIVATED: | |
| 429 return RemoveJs(referring_url_.spec()) + "*"; | |
| 430 | |
| 431 case LEARNED_REFERAL_MOTIVATED: | |
| 432 return RemoveJs(referring_url_.spec()); | |
| 433 | |
| 434 default: | |
| 435 return ""; | |
| 436 } | |
| 437 } | |
| 438 | |
| 439 } // namespace chrome_browser_net | |
| OLD | NEW |
|---|
Chromium Code Reviews
Issue 2866026:
Rename Dns prefetching files to Predictor files... (Closed)
Base URL: svn://chrome-svn/chrome/trunk/src/