passive_log_collector.cc revision 21d179b334e59e9a3bfcaed4c4430bef1bc5759d
1// Copyright (c) 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/passive_log_collector.h" 6 7#include <algorithm> 8 9#include "base/compiler_specific.h" 10#include "base/lock.h" 11#include "base/string_util.h" 12#include "base/format_macros.h" 13#include "net/url_request/url_request_netlog_params.h" 14 15namespace { 16 17// TODO(eroman): Do something with the truncation count. 18 19const size_t kMaxNumEntriesPerLog = 30; 20 21void AddEntryToSourceInfo(const ChromeNetLog::Entry& entry, 22 PassiveLogCollector::SourceInfo* out_info) { 23 // Start dropping new entries when the log has gotten too big. 24 if (out_info->entries.size() + 1 <= kMaxNumEntriesPerLog) { 25 out_info->entries.push_back(entry); 26 } else { 27 out_info->num_entries_truncated += 1; 28 out_info->entries[kMaxNumEntriesPerLog - 1] = entry; 29 } 30} 31 32// Comparator to sort entries by their |order| property, ascending. 33bool SortByOrderComparator(const ChromeNetLog::Entry& a, 34 const ChromeNetLog::Entry& b) { 35 return a.order < b.order; 36} 37 38} // namespace 39 40PassiveLogCollector::SourceInfo::SourceInfo() 41 : source_id(net::NetLog::Source::kInvalidId), 42 num_entries_truncated(0), 43 reference_count(0), 44 is_alive(true) { 45} 46 47PassiveLogCollector::SourceInfo::~SourceInfo() {} 48 49//---------------------------------------------------------------------------- 50// PassiveLogCollector 51//---------------------------------------------------------------------------- 52 53PassiveLogCollector::PassiveLogCollector() 54 : ThreadSafeObserver(net::NetLog::LOG_BASIC), 55 ALLOW_THIS_IN_INITIALIZER_LIST(connect_job_tracker_(this)), 56 ALLOW_THIS_IN_INITIALIZER_LIST(url_request_tracker_(this)), 57 ALLOW_THIS_IN_INITIALIZER_LIST(socket_stream_tracker_(this)), 58 num_events_seen_(0) { 59 60 // Define the mapping between source types and the tracker objects. 61 memset(&trackers_[0], 0, sizeof(trackers_)); 62 trackers_[net::NetLog::SOURCE_NONE] = &global_source_tracker_; 63 trackers_[net::NetLog::SOURCE_URL_REQUEST] = &url_request_tracker_; 64 trackers_[net::NetLog::SOURCE_SOCKET_STREAM] = &socket_stream_tracker_; 65 trackers_[net::NetLog::SOURCE_CONNECT_JOB] = &connect_job_tracker_; 66 trackers_[net::NetLog::SOURCE_SOCKET] = &socket_tracker_; 67 trackers_[net::NetLog::SOURCE_INIT_PROXY_RESOLVER] = 68 &init_proxy_resolver_tracker_; 69 trackers_[net::NetLog::SOURCE_SPDY_SESSION] = &spdy_session_tracker_; 70 trackers_[net::NetLog::SOURCE_HOST_RESOLVER_IMPL_REQUEST] = 71 &dns_request_tracker_; 72 trackers_[net::NetLog::SOURCE_HOST_RESOLVER_IMPL_JOB] = &dns_job_tracker_; 73 // Make sure our mapping is up-to-date. 74 for (size_t i = 0; i < arraysize(trackers_); ++i) 75 DCHECK(trackers_[i]) << "Unhandled SourceType: " << i; 76} 77 78PassiveLogCollector::~PassiveLogCollector() { 79} 80 81void PassiveLogCollector::OnAddEntry( 82 net::NetLog::EventType type, 83 const base::TimeTicks& time, 84 const net::NetLog::Source& source, 85 net::NetLog::EventPhase phase, 86 net::NetLog::EventParameters* params) { 87 AssertNetLogLockAcquired(); 88 // Package the parameters into a single struct for convenience. 89 ChromeNetLog::Entry entry(num_events_seen_++, type, time, source, phase, 90 params); 91 92 SourceTrackerInterface* tracker = GetTrackerForSourceType_(entry.source.type); 93 if (tracker) 94 tracker->OnAddEntry(entry); 95} 96 97void PassiveLogCollector::Clear() { 98 AssertNetLogLockAcquired(); 99 for (size_t i = 0; i < arraysize(trackers_); ++i) 100 trackers_[i]->Clear(); 101} 102 103PassiveLogCollector::SourceTrackerInterface* 104PassiveLogCollector::GetTrackerForSourceType_( 105 net::NetLog::SourceType source_type) { 106 DCHECK_LE(source_type, static_cast<int>(arraysize(trackers_))); 107 DCHECK_GE(source_type, 0); 108 return trackers_[source_type]; 109} 110 111void PassiveLogCollector::GetAllCapturedEvents( 112 ChromeNetLog::EntryList* out) const { 113 AssertNetLogLockAcquired(); 114 out->clear(); 115 116 // Append all of the captured entries held by the various trackers to 117 // |out|. 118 for (size_t i = 0; i < arraysize(trackers_); ++i) 119 trackers_[i]->AppendAllEntries(out); 120 121 // Now sort the list of entries by their insertion time (ascending). 122 std::sort(out->begin(), out->end(), &SortByOrderComparator); 123} 124 125std::string PassiveLogCollector::SourceInfo::GetURL() const { 126 // Note: we look at the first *two* entries, since the outer REQUEST_ALIVE 127 // doesn't actually contain any data. 128 for (size_t i = 0; i < 2 && i < entries.size(); ++i) { 129 const ChromeNetLog::Entry& entry = entries[i]; 130 if (entry.phase == net::NetLog::PHASE_BEGIN && entry.params) { 131 switch (entry.type) { 132 case net::NetLog::TYPE_URL_REQUEST_START_JOB: 133 return static_cast<net::URLRequestStartEventParameters*>( 134 entry.params.get())->url().possibly_invalid_spec(); 135 case net::NetLog::TYPE_SOCKET_STREAM_CONNECT: 136 return static_cast<net::NetLogStringParameter*>( 137 entry.params.get())->value(); 138 default: 139 break; 140 } 141 } 142 } 143 return std::string(); 144} 145 146//---------------------------------------------------------------------------- 147// GlobalSourceTracker 148//---------------------------------------------------------------------------- 149 150PassiveLogCollector::GlobalSourceTracker::GlobalSourceTracker() {} 151PassiveLogCollector::GlobalSourceTracker::~GlobalSourceTracker() {} 152 153void PassiveLogCollector::GlobalSourceTracker::OnAddEntry( 154 const ChromeNetLog::Entry& entry) { 155 const size_t kMaxEntries = 30u; 156 entries_.push_back(entry); 157 if (entries_.size() > kMaxEntries) 158 entries_.pop_front(); 159} 160 161void PassiveLogCollector::GlobalSourceTracker::Clear() { 162 entries_.clear(); 163} 164 165void PassiveLogCollector::GlobalSourceTracker::AppendAllEntries( 166 ChromeNetLog::EntryList* out) const { 167 out->insert(out->end(), entries_.begin(), entries_.end()); 168} 169 170//---------------------------------------------------------------------------- 171// SourceTracker 172//---------------------------------------------------------------------------- 173 174PassiveLogCollector::SourceTracker::SourceTracker( 175 size_t max_num_sources, 176 size_t max_graveyard_size, 177 PassiveLogCollector* parent) 178 : max_num_sources_(max_num_sources), 179 max_graveyard_size_(max_graveyard_size), 180 parent_(parent) { 181} 182 183PassiveLogCollector::SourceTracker::~SourceTracker() {} 184 185void PassiveLogCollector::SourceTracker::OnAddEntry( 186 const ChromeNetLog::Entry& entry) { 187 // Lookup or insert a new entry into the bounded map. 188 SourceIDToInfoMap::iterator it = sources_.find(entry.source.id); 189 if (it == sources_.end()) { 190 if (sources_.size() >= max_num_sources_) { 191 LOG(WARNING) << "The passive log data has grown larger " 192 "than expected, resetting"; 193 Clear(); 194 } 195 it = sources_.insert( 196 SourceIDToInfoMap::value_type(entry.source.id, SourceInfo())).first; 197 it->second.source_id = entry.source.id; 198 } 199 200 SourceInfo& info = it->second; 201 Action result = DoAddEntry(entry, &info); 202 203 if (result != ACTION_NONE) { 204 // We are either queuing it for deletion, or deleting it immediately. 205 // If someone else holds a reference to this source, defer the deletion 206 // until all the references are released. 207 info.is_alive = false; 208 if (info.reference_count == 0) { 209 switch (result) { 210 case ACTION_MOVE_TO_GRAVEYARD: 211 AddToDeletionQueue(info.source_id); 212 break; 213 case ACTION_DELETE: 214 DeleteSourceInfo(info.source_id); 215 break; 216 default: 217 NOTREACHED(); 218 break; 219 } 220 } 221 } 222} 223 224void PassiveLogCollector::SourceTracker::DeleteSourceInfo( 225 uint32 source_id) { 226 SourceIDToInfoMap::iterator it = sources_.find(source_id); 227 if (it == sources_.end()) { 228 // TODO(eroman): Is this happening? And if so, why. Remove this 229 // once the cause is understood. 230 LOG(WARNING) << "Tried to delete info for nonexistent source"; 231 return; 232 } 233 // The source should not be in the deletion queue. 234 DCHECK(std::find(deletion_queue_.begin(), deletion_queue_.end(), 235 source_id) == deletion_queue_.end()); 236 ReleaseAllReferencesToDependencies(&(it->second)); 237 sources_.erase(it); 238} 239 240void PassiveLogCollector::SourceTracker::Clear() { 241 deletion_queue_.clear(); 242 243 // Release all references held to dependent sources. 244 for (SourceIDToInfoMap::iterator it = sources_.begin(); 245 it != sources_.end(); 246 ++it) { 247 ReleaseAllReferencesToDependencies(&(it->second)); 248 } 249 sources_.clear(); 250} 251 252void PassiveLogCollector::SourceTracker::AppendAllEntries( 253 ChromeNetLog::EntryList* out) const { 254 // Append all of the entries for each of the sources. 255 for (SourceIDToInfoMap::const_iterator it = sources_.begin(); 256 it != sources_.end(); 257 ++it) { 258 const SourceInfo& info = it->second; 259 out->insert(out->end(), info.entries.begin(), info.entries.end()); 260 } 261} 262 263void PassiveLogCollector::SourceTracker::AddToDeletionQueue( 264 uint32 source_id) { 265 DCHECK(sources_.find(source_id) != sources_.end()); 266 DCHECK(!sources_.find(source_id)->second.is_alive); 267 DCHECK_GE(sources_.find(source_id)->second.reference_count, 0); 268 DCHECK_LE(deletion_queue_.size(), max_graveyard_size_); 269 270 DCHECK(std::find(deletion_queue_.begin(), deletion_queue_.end(), 271 source_id) == deletion_queue_.end()); 272 deletion_queue_.push_back(source_id); 273 274 // After the deletion queue has reached its maximum size, start 275 // deleting sources in FIFO order. 276 if (deletion_queue_.size() > max_graveyard_size_) { 277 uint32 oldest = deletion_queue_.front(); 278 deletion_queue_.pop_front(); 279 DeleteSourceInfo(oldest); 280 } 281} 282 283void PassiveLogCollector::SourceTracker::EraseFromDeletionQueue( 284 uint32 source_id) { 285 DeletionQueue::iterator it = 286 std::remove(deletion_queue_.begin(), deletion_queue_.end(), 287 source_id); 288 DCHECK(it != deletion_queue_.end()); 289 deletion_queue_.erase(it); 290} 291 292void PassiveLogCollector::SourceTracker::AdjustReferenceCountForSource( 293 int offset, uint32 source_id) { 294 DCHECK(offset == -1 || offset == 1) << "invalid offset: " << offset; 295 296 // In general it is invalid to call AdjustReferenceCountForSource() on 297 // source that doesn't exist. However, it is possible that if 298 // SourceTracker::Clear() was previously called this can happen. 299 SourceIDToInfoMap::iterator it = sources_.find(source_id); 300 if (it == sources_.end()) { 301 LOG(WARNING) << "Released a reference to nonexistent source."; 302 return; 303 } 304 305 SourceInfo& info = it->second; 306 DCHECK_GE(info.reference_count, 0); 307 info.reference_count += offset; 308 309 bool released_unmatched_reference = info.reference_count < 0; 310 if (released_unmatched_reference) { 311 // In general this shouldn't happen, however it is possible to reach this 312 // state if SourceTracker::Clear() was called earlier. 313 LOG(WARNING) << "Released unmatched reference count."; 314 info.reference_count = 0; 315 } 316 317 if (!info.is_alive) { 318 if (info.reference_count == 1 && offset == 1) { 319 // If we just added a reference to a dead source that had no references, 320 // it must have been in the deletion queue, so remove it from the queue. 321 EraseFromDeletionQueue(source_id); 322 } else if (info.reference_count == 0) { 323 if (released_unmatched_reference) 324 EraseFromDeletionQueue(source_id); 325 // If we just released the final reference to a dead source, go ahead 326 // and delete it right away. 327 DeleteSourceInfo(source_id); 328 } 329 } 330} 331 332void PassiveLogCollector::SourceTracker::AddReferenceToSourceDependency( 333 const net::NetLog::Source& source, SourceInfo* info) { 334 // Find the tracker which should be holding |source|. 335 DCHECK(parent_); 336 DCHECK_NE(source.type, net::NetLog::SOURCE_NONE); 337 SourceTracker* tracker = static_cast<SourceTracker*>( 338 parent_->GetTrackerForSourceType_(source.type)); 339 DCHECK(tracker); 340 341 // Tell the owning tracker to increment the reference count of |source|. 342 tracker->AdjustReferenceCountForSource(1, source.id); 343 344 // Make a note to release this reference once |info| is destroyed. 345 info->dependencies.push_back(source); 346} 347 348void 349PassiveLogCollector::SourceTracker::ReleaseAllReferencesToDependencies( 350 SourceInfo* info) { 351 // Release all references |info| was holding to other sources. 352 for (SourceDependencyList::const_iterator it = info->dependencies.begin(); 353 it != info->dependencies.end(); ++it) { 354 const net::NetLog::Source& source = *it; 355 356 // Find the tracker which should be holding |source|. 357 DCHECK(parent_); 358 DCHECK_NE(source.type, net::NetLog::SOURCE_NONE); 359 SourceTracker* tracker = static_cast<SourceTracker*>( 360 parent_->GetTrackerForSourceType_(source.type)); 361 DCHECK(tracker); 362 363 // Tell the owning tracker to decrement the reference count of |source|. 364 tracker->AdjustReferenceCountForSource(-1, source.id); 365 } 366 367 info->dependencies.clear(); 368} 369 370//---------------------------------------------------------------------------- 371// ConnectJobTracker 372//---------------------------------------------------------------------------- 373 374const size_t PassiveLogCollector::ConnectJobTracker::kMaxNumSources = 100; 375const size_t PassiveLogCollector::ConnectJobTracker::kMaxGraveyardSize = 15; 376 377PassiveLogCollector::ConnectJobTracker::ConnectJobTracker( 378 PassiveLogCollector* parent) 379 : SourceTracker(kMaxNumSources, kMaxGraveyardSize, parent) { 380} 381 382PassiveLogCollector::SourceTracker::Action 383PassiveLogCollector::ConnectJobTracker::DoAddEntry( 384 const ChromeNetLog::Entry& entry, SourceInfo* out_info) { 385 AddEntryToSourceInfo(entry, out_info); 386 387 if (entry.type == net::NetLog::TYPE_CONNECT_JOB_SET_SOCKET) { 388 const net::NetLog::Source& source_dependency = 389 static_cast<net::NetLogSourceParameter*>(entry.params.get())->value(); 390 AddReferenceToSourceDependency(source_dependency, out_info); 391 } 392 393 // If this is the end of the connect job, move the source to the graveyard. 394 if (entry.type == net::NetLog::TYPE_SOCKET_POOL_CONNECT_JOB && 395 entry.phase == net::NetLog::PHASE_END) { 396 return ACTION_MOVE_TO_GRAVEYARD; 397 } 398 399 return ACTION_NONE; 400} 401 402//---------------------------------------------------------------------------- 403// SocketTracker 404//---------------------------------------------------------------------------- 405 406const size_t PassiveLogCollector::SocketTracker::kMaxNumSources = 200; 407const size_t PassiveLogCollector::SocketTracker::kMaxGraveyardSize = 15; 408 409PassiveLogCollector::SocketTracker::SocketTracker() 410 : SourceTracker(kMaxNumSources, kMaxGraveyardSize, NULL) { 411} 412 413PassiveLogCollector::SourceTracker::Action 414PassiveLogCollector::SocketTracker::DoAddEntry(const ChromeNetLog::Entry& entry, 415 SourceInfo* out_info) { 416 // TODO(eroman): aggregate the byte counts once truncation starts to happen, 417 // to summarize transaction read/writes for each SOCKET_IN_USE 418 // section. 419 if (entry.type == net::NetLog::TYPE_SOCKET_BYTES_SENT || 420 entry.type == net::NetLog::TYPE_SOCKET_BYTES_RECEIVED) { 421 return ACTION_NONE; 422 } 423 424 AddEntryToSourceInfo(entry, out_info); 425 426 if (entry.type == net::NetLog::TYPE_SOCKET_ALIVE && 427 entry.phase == net::NetLog::PHASE_END) { 428 return ACTION_MOVE_TO_GRAVEYARD; 429 } 430 431 return ACTION_NONE; 432} 433 434//---------------------------------------------------------------------------- 435// RequestTracker 436//---------------------------------------------------------------------------- 437 438const size_t PassiveLogCollector::RequestTracker::kMaxNumSources = 100; 439const size_t PassiveLogCollector::RequestTracker::kMaxGraveyardSize = 25; 440 441PassiveLogCollector::RequestTracker::RequestTracker(PassiveLogCollector* parent) 442 : SourceTracker(kMaxNumSources, kMaxGraveyardSize, parent) { 443} 444 445PassiveLogCollector::SourceTracker::Action 446PassiveLogCollector::RequestTracker::DoAddEntry( 447 const ChromeNetLog::Entry& entry, SourceInfo* out_info) { 448 if (entry.type == net::NetLog::TYPE_SOCKET_POOL_BOUND_TO_CONNECT_JOB || 449 entry.type == net::NetLog::TYPE_SOCKET_POOL_BOUND_TO_SOCKET) { 450 const net::NetLog::Source& source_dependency = 451 static_cast<net::NetLogSourceParameter*>(entry.params.get())->value(); 452 AddReferenceToSourceDependency(source_dependency, out_info); 453 } 454 455 AddEntryToSourceInfo(entry, out_info); 456 457 // If the request has ended, move it to the graveyard. 458 if (entry.type == net::NetLog::TYPE_REQUEST_ALIVE && 459 entry.phase == net::NetLog::PHASE_END) { 460 if (StartsWithASCII(out_info->GetURL(), "chrome://", false)) { 461 // Avoid sending "chrome://" requests to the graveyard, since it just 462 // adds to clutter. 463 return ACTION_DELETE; 464 } 465 return ACTION_MOVE_TO_GRAVEYARD; 466 } 467 468 return ACTION_NONE; 469} 470 471//---------------------------------------------------------------------------- 472// InitProxyResolverTracker 473//---------------------------------------------------------------------------- 474 475const size_t PassiveLogCollector::InitProxyResolverTracker::kMaxNumSources = 20; 476const size_t PassiveLogCollector::InitProxyResolverTracker::kMaxGraveyardSize = 477 3; 478 479PassiveLogCollector::InitProxyResolverTracker::InitProxyResolverTracker() 480 : SourceTracker(kMaxNumSources, kMaxGraveyardSize, NULL) { 481} 482 483PassiveLogCollector::SourceTracker::Action 484PassiveLogCollector::InitProxyResolverTracker::DoAddEntry( 485 const ChromeNetLog::Entry& entry, SourceInfo* out_info) { 486 AddEntryToSourceInfo(entry, out_info); 487 if (entry.type == net::NetLog::TYPE_INIT_PROXY_RESOLVER && 488 entry.phase == net::NetLog::PHASE_END) { 489 return ACTION_MOVE_TO_GRAVEYARD; 490 } else { 491 return ACTION_NONE; 492 } 493} 494 495//---------------------------------------------------------------------------- 496// SpdySessionTracker 497//---------------------------------------------------------------------------- 498 499const size_t PassiveLogCollector::SpdySessionTracker::kMaxNumSources = 50; 500const size_t PassiveLogCollector::SpdySessionTracker::kMaxGraveyardSize = 10; 501 502PassiveLogCollector::SpdySessionTracker::SpdySessionTracker() 503 : SourceTracker(kMaxNumSources, kMaxGraveyardSize, NULL) { 504} 505 506PassiveLogCollector::SourceTracker::Action 507PassiveLogCollector::SpdySessionTracker::DoAddEntry( 508 const ChromeNetLog::Entry& entry, SourceInfo* out_info) { 509 AddEntryToSourceInfo(entry, out_info); 510 if (entry.type == net::NetLog::TYPE_SPDY_SESSION && 511 entry.phase == net::NetLog::PHASE_END) { 512 return ACTION_MOVE_TO_GRAVEYARD; 513 } else { 514 return ACTION_NONE; 515 } 516} 517 518//---------------------------------------------------------------------------- 519// DNSRequestTracker 520//---------------------------------------------------------------------------- 521 522const size_t PassiveLogCollector::DNSRequestTracker::kMaxNumSources = 200; 523const size_t PassiveLogCollector::DNSRequestTracker::kMaxGraveyardSize = 20; 524 525PassiveLogCollector::DNSRequestTracker::DNSRequestTracker() 526 : SourceTracker(kMaxNumSources, kMaxGraveyardSize, NULL) { 527} 528 529PassiveLogCollector::SourceTracker::Action 530PassiveLogCollector::DNSRequestTracker::DoAddEntry( 531 const ChromeNetLog::Entry& entry, SourceInfo* out_info) { 532 AddEntryToSourceInfo(entry, out_info); 533 if (entry.type == net::NetLog::TYPE_HOST_RESOLVER_IMPL_REQUEST && 534 entry.phase == net::NetLog::PHASE_END) { 535 return ACTION_MOVE_TO_GRAVEYARD; 536 } else { 537 return ACTION_NONE; 538 } 539} 540 541//---------------------------------------------------------------------------- 542// DNSJobTracker 543//---------------------------------------------------------------------------- 544 545const size_t PassiveLogCollector::DNSJobTracker::kMaxNumSources = 100; 546const size_t PassiveLogCollector::DNSJobTracker::kMaxGraveyardSize = 15; 547 548PassiveLogCollector::DNSJobTracker::DNSJobTracker() 549 : SourceTracker(kMaxNumSources, kMaxGraveyardSize, NULL) { 550} 551 552PassiveLogCollector::SourceTracker::Action 553PassiveLogCollector::DNSJobTracker::DoAddEntry(const ChromeNetLog::Entry& entry, 554 SourceInfo* out_info) { 555 AddEntryToSourceInfo(entry, out_info); 556 if (entry.type == net::NetLog::TYPE_HOST_RESOLVER_IMPL_JOB && 557 entry.phase == net::NetLog::PHASE_END) { 558 return ACTION_MOVE_TO_GRAVEYARD; 559 } else { 560 return ACTION_NONE; 561 } 562} 563