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 if (MaxNonNetworkDnsLookupDuration() <= resolve_duration_) { 173 DHISTOGRAM_TIMES("DNS.PrefetchNotFoundName", resolve_duration_); 174 } 175 sequence_number_ = sequence_counter++; 176 DLogResultsStats("DNS PrefetchNotFound"); 177 } 178 179 void UrlInfo::SetUrl(const GURL& url) { 180 if (url_.is_empty()) // Not yet initialized. 181 url_ = url; 182 else 183 DCHECK_EQ(url_, url); 184 } 185 186 // IsStillCached() guesses if the DNS cache still has IP data, 187 // or at least remembers results about "not finding host." 188 bool UrlInfo::IsStillCached() const { 189 DCHECK(FOUND == state_ || NO_SUCH_NAME == state_); 190 191 // Default MS OS does not cache failures. Hence we could return false almost 192 // all the time for that case. However, we'd never try again to prefetch 193 // the value if we returned false that way. Hence we'll just let the lookup 194 // time out the same way as FOUND case. 195 196 if (sequence_counter - sequence_number_ > kMaxGuaranteedDnsCacheSize) 197 return false; 198 199 TimeDelta time_since_resolution = TimeTicks::Now() - time_; 200 return time_since_resolution < global_state.Get().cache_expiration_duration; 201 } 202 203 void UrlInfo::DLogResultsStats(const char* message) const { 204 if (!detailed_logging_enabled) 205 return; 206 DVLOG(1) << "\t" << message << "\tq=" << queue_duration().InMilliseconds() 207 << "ms,\tr=" << resolve_duration().InMilliseconds() 208 << "ms,\tp=" << sequence_number_ << "\t" << url_.spec(); 209 } 210 211 //------------------------------------------------------------------------------ 212 // This last section supports HTML output, such as seen in about:dns. 213 //------------------------------------------------------------------------------ 214 215 // Preclude any possibility of Java Script or markup in the text, by only 216 // allowing alphanumerics, '.', '-', ':', and whitespace. 217 static std::string RemoveJs(const std::string& text) { 218 std::string output(text); 219 size_t length = output.length(); 220 for (size_t i = 0; i < length; i++) { 221 char next = output[i]; 222 if (isalnum(next) || isspace(next) || strchr(".-:/", next) != NULL) 223 continue; 224 output[i] = '?'; 225 } 226 return output; 227 } 228 229 class MinMaxAverage { 230 public: 231 MinMaxAverage() 232 : sum_(0), square_sum_(0), count_(0), 233 minimum_(kint64max), maximum_(kint64min) { 234 } 235 236 // Return values for use in printf formatted as "%d" 237 int sample(int64 value) { 238 sum_ += value; 239 square_sum_ += value * value; 240 count_++; 241 minimum_ = std::min(minimum_, value); 242 maximum_ = std::max(maximum_, value); 243 return static_cast<int>(value); 244 } 245 int minimum() const { return static_cast<int>(minimum_); } 246 int maximum() const { return static_cast<int>(maximum_); } 247 int average() const { return static_cast<int>(sum_/count_); } 248 int sum() const { return static_cast<int>(sum_); } 249 250 int standard_deviation() const { 251 double average = static_cast<float>(sum_) / count_; 252 double variance = static_cast<float>(square_sum_)/count_ 253 - average * average; 254 return static_cast<int>(floor(sqrt(variance) + .5)); 255 } 256 257 private: 258 int64 sum_; 259 int64 square_sum_; 260 int count_; 261 int64 minimum_; 262 int64 maximum_; 263 264 // DISALLOW_COPY_AND_ASSIGN(MinMaxAverage); 265 }; 266 267 static std::string HoursMinutesSeconds(int seconds) { 268 std::string result; 269 int print_seconds = seconds % 60; 270 int minutes = seconds / 60; 271 int print_minutes = minutes % 60; 272 int print_hours = minutes/60; 273 if (print_hours) 274 base::StringAppendF(&result, "%.2d:", print_hours); 275 if (print_hours || print_minutes) 276 base::StringAppendF(&result, "%2.2d:", print_minutes); 277 base::StringAppendF(&result, "%2.2d", print_seconds); 278 return result; 279 } 280 281 // static 282 void UrlInfo::GetHtmlTable(const UrlInfoTable& host_infos, 283 const char* description, 284 bool brief, 285 std::string* output) { 286 if (0 == host_infos.size()) 287 return; 288 output->append(description); 289 base::StringAppendF(output, "%" PRIuS " %s", host_infos.size(), 290 (1 == host_infos.size()) ? "hostname" : "hostnames"); 291 292 if (brief) { 293 output->append("<br><br>"); 294 return; 295 } 296 297 output->append("<br><table border=1>" 298 "<tr><th>Host name</th>" 299 "<th>How long ago<br>(HH:MM:SS)</th>" 300 "<th>Motivation</th>" 301 "</tr>"); 302 303 const char* row_format = "<tr align=right><td>%s</td>" // Host name. 304 "<td>%s</td>" // How long ago. 305 "<td>%s</td>" // Motivation. 306 "</tr>"; 307 308 // Print bulk of table, and gather stats at same time. 309 MinMaxAverage queue, when; 310 TimeTicks current_time = TimeTicks::Now(); 311 for (UrlInfoTable::const_iterator it(host_infos.begin()); 312 it != host_infos.end(); it++) { 313 queue.sample((it->queue_duration_.InMilliseconds())); 314 base::StringAppendF( 315 output, 316 row_format, 317 RemoveJs(it->url_.spec()).c_str(), 318 HoursMinutesSeconds(when.sample( 319 (current_time - it->time_).InSeconds())).c_str(), 320 it->GetAsciiMotivation().c_str()); 321 } 322 output->append("</table>"); 323 324 #ifndef NDEBUG 325 base::StringAppendF( 326 output, 327 "Prefetch Queue Durations: min=%d, avg=%d, max=%d<br><br>", 328 queue.minimum(), queue.average(), queue.maximum()); 329 #endif 330 331 output->append("<br>"); 332 } 333 334 void UrlInfo::SetMotivation(ResolutionMotivation motivation) { 335 motivation_ = motivation; 336 if (motivation < LINKED_MAX_MOTIVATED) 337 was_linked_ = true; 338 } 339 340 std::string UrlInfo::GetAsciiMotivation() const { 341 switch (motivation_) { 342 case MOUSE_OVER_MOTIVATED: 343 return "[mouse-over]"; 344 345 case PAGE_SCAN_MOTIVATED: 346 return "[page scan]"; 347 348 case OMNIBOX_MOTIVATED: 349 return "[omnibox]"; 350 351 case STARTUP_LIST_MOTIVATED: 352 return "[startup list]"; 353 354 case NO_PREFETCH_MOTIVATION: 355 return "n/a"; 356 357 case STATIC_REFERAL_MOTIVATED: 358 return RemoveJs(referring_url_.spec()) + "*"; 359 360 case LEARNED_REFERAL_MOTIVATED: 361 return RemoveJs(referring_url_.spec()); 362 363 default: 364 return std::string(); 365 } 366 } 367 368 } // namespace chrome_browser_net 369