diff options
Diffstat (limited to 'chrome/browser/net')
| -rw-r--r-- | chrome/browser/net/chrome_url_request_context.cc | 3 | ||||
| -rw-r--r-- | chrome/browser/net/connection_tester.cc | 3 | ||||
| -rw-r--r-- | chrome/browser/net/passive_log_collector.cc | 549 | ||||
| -rw-r--r-- | chrome/browser/net/passive_log_collector.h | 179 | ||||
| -rw-r--r-- | chrome/browser/net/passive_log_collector_unittest.cc | 1020 |
5 files changed, 500 insertions, 1254 deletions
diff --git a/chrome/browser/net/chrome_url_request_context.cc b/chrome/browser/net/chrome_url_request_context.cc index e75921e..ed36a1c 100644 --- a/chrome/browser/net/chrome_url_request_context.cc +++ b/chrome/browser/net/chrome_url_request_context.cc @@ -256,6 +256,7 @@ ChromeURLRequestContext* FactoryForOriginal::Create() { context->proxy_service(), context->ssl_config_service(), context->http_auth_handler_factory(), + io_thread()->globals()->net_log.get(), backend); if (command_line.HasSwitch(switches::kDisableByteRangeSupport)) @@ -379,6 +380,7 @@ ChromeURLRequestContext* FactoryForOffTheRecord::Create() { context->proxy_service(), context->ssl_config_service(), context->http_auth_handler_factory(), + io_thread()->globals()->net_log.get(), backend); context->set_cookie_store(new net::CookieMonster(NULL, cookie_monster_delegate_)); @@ -474,6 +476,7 @@ ChromeURLRequestContext* FactoryForMedia::Create() { main_context->proxy_service(), main_context->ssl_config_service(), main_context->http_auth_handler_factory(), + io_thread()->globals()->net_log.get(), backend); } diff --git a/chrome/browser/net/connection_tester.cc b/chrome/browser/net/connection_tester.cc index 430874a..6e72380 100644 --- a/chrome/browser/net/connection_tester.cc +++ b/chrome/browser/net/connection_tester.cc @@ -58,7 +58,8 @@ class ExperimentURLRequestContext : public URLRequestContext { net::HttpNetworkLayer::CreateFactory(NULL, host_resolver_, proxy_service_, ssl_config_service_, - http_auth_handler_factory_), + http_auth_handler_factory_, + NULL), net::HttpCache::DefaultBackend::InMemory(0)); // In-memory cookie store. cookie_store_ = new net::CookieMonster(NULL, NULL); diff --git a/chrome/browser/net/passive_log_collector.cc b/chrome/browser/net/passive_log_collector.cc index c506f25..4c3e4973 100644 --- a/chrome/browser/net/passive_log_collector.cc +++ b/chrome/browser/net/passive_log_collector.cc @@ -6,6 +6,7 @@ #include <algorithm> +#include "base/compiler_specific.h" #include "base/string_util.h" #include "base/format_macros.h" #include "chrome/browser/chrome_thread.h" @@ -13,16 +14,10 @@ namespace { -const size_t kMaxNumEntriesPerLog = 50; -const size_t kMaxConnectJobGraveyardSize = 3; -const size_t kMaxRequestGraveyardSize = 25; -const size_t kMaxLiveRequests = 200; +// TODO(eroman): Do something with the truncation count. -// Sort function on source ID. -bool OrderBySourceID(const PassiveLogCollector::RequestInfo& a, - const PassiveLogCollector::RequestInfo& b) { - return a.source_id < b.source_id; -} +const size_t kMaxNumEntriesPerLog = 30; +const size_t kMaxRequestsPerTracker = 200; void AddEntryToRequestInfo(const PassiveLogCollector::Entry& entry, PassiveLogCollector::RequestInfo* out_info) { @@ -35,45 +30,12 @@ void AddEntryToRequestInfo(const PassiveLogCollector::Entry& entry, } } -void AppendToRequestInfo(const PassiveLogCollector::RequestInfo& info, - PassiveLogCollector::RequestInfo* out_info) { - for (size_t i = 0; i < info.entries.size(); ++i) - AddEntryToRequestInfo(info.entries[i], out_info); -} - -// Appends all of the logged events in |input| to |out|. -void AppendAllEntriesFromRequests( - const PassiveLogCollector::RequestInfoList& input, - PassiveLogCollector::EntryList* out) { - for (size_t i = 0; i < input.size(); ++i) { - const PassiveLogCollector::EntryList& entries = input[i].entries; - out->insert(out->end(), entries.begin(), entries.end()); - } -} - // Comparator to sort entries by their |order| property, ascending. bool SortByOrderComparator(const PassiveLogCollector::Entry& a, const PassiveLogCollector::Entry& b) { return a.order < b.order; } -void SetSubordinateSource(PassiveLogCollector::RequestInfo* info, - const PassiveLogCollector::Entry& entry) { - info->subordinate_source.id = static_cast<net::NetLogIntegerParameter*>( - entry.params.get())->value(); - switch (entry.type) { - case net::NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID: - info->subordinate_source.type = net::NetLog::SOURCE_CONNECT_JOB; - break; - case net::NetLog::TYPE_SOCKET_POOL_SOCKET_ID: - info->subordinate_source.type = net::NetLog::SOURCE_SOCKET; - break; - default: - NOTREACHED(); - break; - } -} - } // namespace //---------------------------------------------------------------------------- @@ -81,9 +43,24 @@ void SetSubordinateSource(PassiveLogCollector::RequestInfo* info, //---------------------------------------------------------------------------- PassiveLogCollector::PassiveLogCollector() - : url_request_tracker_(&connect_job_tracker_, &socket_tracker_), - socket_stream_tracker_(&connect_job_tracker_, &socket_tracker_), + : ALLOW_THIS_IN_INITIALIZER_LIST(connect_job_tracker_(this)), + ALLOW_THIS_IN_INITIALIZER_LIST(url_request_tracker_(this)), + ALLOW_THIS_IN_INITIALIZER_LIST(socket_stream_tracker_(this)), num_events_seen_(0) { + + // Define the mapping between source types and the tracker objects. + memset(&trackers_[0], 0, sizeof(trackers_)); + trackers_[net::NetLog::SOURCE_URL_REQUEST] = &url_request_tracker_; + trackers_[net::NetLog::SOURCE_SOCKET_STREAM] = &socket_stream_tracker_; + trackers_[net::NetLog::SOURCE_CONNECT_JOB] = &connect_job_tracker_; + trackers_[net::NetLog::SOURCE_SOCKET] = &socket_tracker_; + trackers_[net::NetLog::SOURCE_INIT_PROXY_RESOLVER] = + &init_proxy_resolver_tracker_; + trackers_[net::NetLog::SOURCE_SPDY_SESSION] = &spdy_session_tracker_; + + // Make sure our mapping is up-to-date. + for (size_t i = 0; i < arraysize(trackers_); ++i) + DCHECK(trackers_[i]) << "Unhandled SourceType: " << i; } PassiveLogCollector::~PassiveLogCollector() { @@ -98,32 +75,22 @@ void PassiveLogCollector::OnAddEntry( // Package the parameters into a single struct for convenience. Entry entry(num_events_seen_++, type, time, source, phase, params); - switch (entry.source.type) { - case net::NetLog::SOURCE_URL_REQUEST: - url_request_tracker_.OnAddEntry(entry); - break; - case net::NetLog::SOURCE_SOCKET_STREAM: - socket_stream_tracker_.OnAddEntry(entry); - break; - case net::NetLog::SOURCE_CONNECT_JOB: - connect_job_tracker_.OnAddEntry(entry); - break; - case net::NetLog::SOURCE_SOCKET: - socket_tracker_.OnAddEntry(entry); - break; - case net::NetLog::SOURCE_INIT_PROXY_RESOLVER: - init_proxy_resolver_tracker_.OnAddEntry(entry); - break; - default: - // Drop all other logged events. - break; - } + RequestTrackerBase* tracker = GetTrackerForSourceType(entry.source.type); + if (tracker) + tracker->OnAddEntry(entry); +} + +PassiveLogCollector::RequestTrackerBase* +PassiveLogCollector::GetTrackerForSourceType( + net::NetLog::SourceType source_type) { + DCHECK_LE(source_type, static_cast<int>(arraysize(trackers_))); + DCHECK_GE(source_type, 0); + return trackers_[source_type]; } void PassiveLogCollector::Clear() { - connect_job_tracker_.Clear(); - url_request_tracker_.Clear(); - socket_stream_tracker_.Clear(); + for (size_t i = 0; i < arraysize(trackers_); ++i) + trackers_[i]->Clear(); } void PassiveLogCollector::GetAllCapturedEvents(EntryList* out) const { @@ -131,13 +98,8 @@ void PassiveLogCollector::GetAllCapturedEvents(EntryList* out) const { // Append all of the captured entries held by the various trackers to // |out|. - socket_stream_tracker_.AppendAllEntries(out); - url_request_tracker_.AppendAllEntries(out); - spdy_session_tracker_.AppendAllEntries(out); - - const EntryList& proxy_entries = - init_proxy_resolver_tracker_.entries(); - out->insert(out->end(), proxy_entries.begin(), proxy_entries.end()); + for (size_t i = 0; i < arraysize(trackers_); ++i) + trackers_[i]->AppendAllEntries(out); // Now sort the list of entries by their insertion time (ascending). std::sort(out->begin(), out->end(), &SortByOrderComparator); @@ -169,124 +131,166 @@ std::string PassiveLogCollector::RequestInfo::GetURL() const { //---------------------------------------------------------------------------- PassiveLogCollector::RequestTrackerBase::RequestTrackerBase( - size_t max_graveyard_size) - : max_graveyard_size_(max_graveyard_size), - next_graveyard_index_(0) { + size_t max_graveyard_size, PassiveLogCollector* parent) + : max_graveyard_size_(max_graveyard_size), parent_(parent) { } +PassiveLogCollector::RequestTrackerBase::~RequestTrackerBase() {} + void PassiveLogCollector::RequestTrackerBase::OnAddEntry(const Entry& entry) { - RequestInfo& info = live_requests_[entry.source.id]; + RequestInfo& info = requests_[entry.source.id]; info.source_id = entry.source.id; // In case this is a new entry. Action result = DoAddEntry(entry, &info); - switch (result) { - case ACTION_MOVE_TO_GRAVEYARD: - InsertIntoGraveyard(info); - // (fall-through) - case ACTION_DELETE: - RemoveFromLiveRequests(entry.source.id); - break; - default: - break; + if (result != ACTION_NONE) { + // We are either queuing it for deletion, or deleting it immediately. + // If someone else holds a reference to this source, defer the deletion + // until all the references are released. + info.is_alive = false; + if (info.reference_count == 0) { + switch (result) { + case ACTION_MOVE_TO_GRAVEYARD: + AddToDeletionQueue(info.source_id); + break; + case ACTION_DELETE: + DeleteRequestInfo(info.source_id); + break; + default: + NOTREACHED(); + break; + } + } } - if (live_requests_.size() > kMaxLiveRequests) { + if (requests_.size() > kMaxRequestsPerTracker) { // This is a safety net in case something went wrong, to avoid continually // growing memory. LOG(WARNING) << "The passive log data has grown larger " "than expected, resetting"; - live_requests_.clear(); + Clear(); } } -PassiveLogCollector::RequestInfoList -PassiveLogCollector::RequestTrackerBase::GetLiveRequests() const { - RequestInfoList list; +void PassiveLogCollector::RequestTrackerBase::DeleteRequestInfo( + uint32 source_id) { + SourceIDToInfoMap::iterator it = requests_.find(source_id); + DCHECK(it != requests_.end()); + // The request should not be in the deletion queue. + DCHECK(std::find(deletion_queue_.begin(), deletion_queue_.end(), + source_id) == deletion_queue_.end()); + ReleaseAllReferencesToDependencies(&(it->second)); + requests_.erase(it); +} + +void PassiveLogCollector::RequestTrackerBase::Clear() { + deletion_queue_.clear(); - // Copy all of the live requests into the vector. - for (SourceIDToInfoMap::const_iterator it = live_requests_.begin(); - it != live_requests_.end(); + // Release all references held to dependent sources. + for (SourceIDToInfoMap::iterator it = requests_.begin(); + it != requests_.end(); ++it) { - list.push_back(it->second); - // We pass the copy (made by the list insert), so changes made in - // OnLiveRequest are only seen by our caller. - OnLiveRequest(&list.back()); - std::sort(list.back().entries.begin(), list.back().entries.end(), - SortByOrderComparator); + ReleaseAllReferencesToDependencies(&(it->second)); } - - std::sort(list.begin(), list.end(), OrderBySourceID); - return list; + requests_.clear(); } -void PassiveLogCollector::RequestTrackerBase::ClearRecentlyDeceased() { - next_graveyard_index_ = 0; - graveyard_.clear(); +void PassiveLogCollector::RequestTrackerBase::AppendAllEntries( + EntryList* out) const { + // Append all of the entries for each of the sources. + for (SourceIDToInfoMap::const_iterator it = requests_.begin(); + it != requests_.end(); + ++it) { + const RequestInfo& info = it->second; + out->insert(out->end(), info.entries.begin(), info.entries.end()); + } } -// Returns a list of recently completed Requests. -PassiveLogCollector::RequestInfoList -PassiveLogCollector::RequestTrackerBase::GetRecentlyDeceased() const { - RequestInfoList list; - - // Copy the items from |graveyard_| (our circular queue of recently - // deceased request infos) into a vector, ordered from oldest to newest. - for (size_t i = 0; i < graveyard_.size(); ++i) { - size_t index = (next_graveyard_index_ + i) % graveyard_.size(); - list.push_back(graveyard_[index]); +void PassiveLogCollector::RequestTrackerBase::AddToDeletionQueue( + uint32 source_id) { + DCHECK(requests_.find(source_id) != requests_.end()); + DCHECK(!requests_.find(source_id)->second.is_alive); + DCHECK_GE(requests_.find(source_id)->second.reference_count, 0); + DCHECK_LE(deletion_queue_.size(), max_graveyard_size_); + + deletion_queue_.push_back(source_id); + + // After the deletion queue has reached its maximum size, start + // deleting requests in FIFO order. + if (deletion_queue_.size() > max_graveyard_size_) { + uint32 oldest = deletion_queue_.front(); + deletion_queue_.pop_front(); + DeleteRequestInfo(oldest); } - return list; } -PassiveLogCollector::RequestInfo* -PassiveLogCollector::RequestTrackerBase::GetRequestInfo(uint32 source_id) { - // Look for it in the live requests first. - SourceIDToInfoMap::iterator it = live_requests_.find(source_id); - if (it != live_requests_.end()) - return &(it->second); - - // Otherwise, scan through the graveyard to find an entry for |source_id|. - for (size_t i = 0; i < graveyard_.size(); ++i) { - if (graveyard_[i].source_id == source_id) { - return &graveyard_[i]; +void PassiveLogCollector::RequestTrackerBase::AdjustReferenceCountForSource( + int offset, uint32 source_id) { + DCHECK(offset == -1 || offset == 1) << "invalid offset: " << offset; + + // In general it is invalid to call AdjustReferenceCountForSource() on + // source that doesn't exist. However, it is possible that if + // RequestTrackerBase::Clear() was previously called this can happen. + // TODO(eroman): Add a unit-test that exercises this case. + SourceIDToInfoMap::iterator it = requests_.find(source_id); + if (it == requests_.end()) + return; + + RequestInfo& info = it->second; + DCHECK_GE(info.reference_count, 0); + DCHECK_GE(info.reference_count + offset, 0); + info.reference_count += offset; + + if (!info.is_alive) { + if (info.reference_count == 1 && offset == 1) { + // If we just added a reference to a dead source that had no references, + // it must have been in the deletion queue, so remove it from the queue. + DeletionQueue::iterator it = + std::remove(deletion_queue_.begin(), deletion_queue_.end(), + source_id); + DCHECK(it != deletion_queue_.end()); + deletion_queue_.erase(it); + } else if (info.reference_count == 0) { + // If we just released the final reference to a dead request, go ahead + // and delete it right away. + DeleteRequestInfo(source_id); } } - return NULL; } -void PassiveLogCollector::RequestTrackerBase::RemoveFromLiveRequests( - uint32 source_id) { - // Remove from |live_requests_|. - SourceIDToInfoMap::iterator it = live_requests_.find(source_id); - // TODO(eroman): Shouldn't have this 'if', is it actually really necessary? - if (it != live_requests_.end()) - live_requests_.erase(it); -} +void PassiveLogCollector::RequestTrackerBase::AddReferenceToSourceDependency( + const net::NetLog::Source& source, RequestInfo* info) { + // Find the tracker which should be holding |source|. + DCHECK(parent_); + RequestTrackerBase* tracker = + parent_->GetTrackerForSourceType(source.type); + DCHECK(tracker); -void PassiveLogCollector::RequestTrackerBase::Clear() { - ClearRecentlyDeceased(); - live_requests_.clear(); -} + // Tell the owning tracker to increment the reference count of |source|. + tracker->AdjustReferenceCountForSource(1, source.id); -void PassiveLogCollector::RequestTrackerBase::AppendAllEntries( - EntryList* out) const { - AppendAllEntriesFromRequests(GetLiveRequests(), out); - AppendAllEntriesFromRequests(GetRecentlyDeceased(), out); + // Make a note to release this reference once |info| is destroyed. + info->dependencies.push_back(source); } -void PassiveLogCollector::RequestTrackerBase::InsertIntoGraveyard( - const RequestInfo& info) { - // Enforce a bound on the graveyard size, by treating it as a - // circular buffer. - if (graveyard_.size() < max_graveyard_size_) { - // Still growing to maximum capacity. - DCHECK_EQ(next_graveyard_index_, graveyard_.size()); - graveyard_.push_back(info); - } else { - // At maximum capacity, overwite the oldest entry. - graveyard_[next_graveyard_index_] = info; +void +PassiveLogCollector::RequestTrackerBase::ReleaseAllReferencesToDependencies( + RequestInfo* info) { + // Release all references |info| was holding to dependent sources. + for (SourceDependencyList::const_iterator it = info->dependencies.begin(); + it != info->dependencies.end(); ++it) { + const net::NetLog::Source& source = *it; + + // Find the tracker which should be holding |source|. + DCHECK(parent_); + RequestTrackerBase* tracker = + parent_->GetTrackerForSourceType(source.type); + DCHECK(tracker); + + // Tell the owning tracker to decrement the reference count of |source|. + tracker->AdjustReferenceCountForSource(-1, source.id); } - next_graveyard_index_ = (next_graveyard_index_ + 1) % max_graveyard_size_; + + info->dependencies.clear(); } //---------------------------------------------------------------------------- @@ -295,8 +299,9 @@ void PassiveLogCollector::RequestTrackerBase::InsertIntoGraveyard( const size_t PassiveLogCollector::ConnectJobTracker::kMaxGraveyardSize = 15; -PassiveLogCollector::ConnectJobTracker::ConnectJobTracker() - : RequestTrackerBase(kMaxGraveyardSize) { +PassiveLogCollector::ConnectJobTracker::ConnectJobTracker( + PassiveLogCollector* parent) + : RequestTrackerBase(kMaxGraveyardSize, parent) { } PassiveLogCollector::RequestTrackerBase::Action @@ -304,8 +309,10 @@ PassiveLogCollector::ConnectJobTracker::DoAddEntry(const Entry& entry, RequestInfo* out_info) { AddEntryToRequestInfo(entry, out_info); - if (entry.type == net::NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID) { - SetSubordinateSource(out_info, entry); + if (entry.type == net::NetLog::TYPE_CONNECT_JOB_SET_SOCKET) { + const net::NetLog::Source& source_dependency = + static_cast<net::NetLogSourceParameter*>(entry.params.get())->value(); + AddReferenceToSourceDependency(source_dependency, out_info); } // If this is the end of the connect job, move the request to the graveyard. @@ -317,29 +324,6 @@ PassiveLogCollector::ConnectJobTracker::DoAddEntry(const Entry& entry, return ACTION_NONE; } -void PassiveLogCollector::ConnectJobTracker::AppendLogEntries( - RequestInfo* out_info, uint32 connect_id) { - RequestInfo* connect_info = GetRequestInfo(connect_id); - if (!connect_info) { - net::NetLogStringParameter* text = new net::NetLogStringParameter( - "todo", StringPrintf("Used ConnectJob id=%u", connect_id)); - Entry new_entry(0, net::NetLog::TYPE_TODO_STRING, base::TimeTicks(), - net::NetLog::Source(net::NetLog::SOURCE_CONNECT_JOB, - connect_id), - net::NetLog::PHASE_NONE, text); - AddEntryToRequestInfo(new_entry, out_info); - return; - } - - AppendToRequestInfo(*connect_info, out_info); - std::sort(out_info->entries.begin(), out_info->entries.end(), - &SortByOrderComparator); - out_info->num_entries_truncated += connect_info->num_entries_truncated; - - if (connect_info->subordinate_source.is_valid()) - AppendLogEntries(out_info, connect_info->subordinate_source.id); -} - //---------------------------------------------------------------------------- // SocketTracker //---------------------------------------------------------------------------- @@ -347,87 +331,28 @@ void PassiveLogCollector::ConnectJobTracker::AppendLogEntries( const size_t PassiveLogCollector::SocketTracker::kMaxGraveyardSize = 15; PassiveLogCollector::SocketTracker::SocketTracker() - : RequestTrackerBase(kMaxGraveyardSize) { + : RequestTrackerBase(kMaxGraveyardSize, NULL) { } PassiveLogCollector::RequestTrackerBase::Action PassiveLogCollector::SocketTracker::DoAddEntry(const Entry& entry, RequestInfo* out_info) { - int int_arg; - switch (entry.type) { - case net::NetLog::TYPE_SOCKET_BYTES_SENT: - int_arg = static_cast<net::NetLogIntegerParameter*>( - entry.params.get())->value(); - out_info->total_bytes_transmitted += int_arg; - out_info->bytes_transmitted += int_arg; - out_info->last_tx_rx_time = entry.time; - out_info->last_tx_rx_position = entry.order; - break; - case net::NetLog::TYPE_SOCKET_BYTES_RECEIVED: - int_arg = static_cast<net::NetLogIntegerParameter*>( - entry.params.get())->value(); - out_info->total_bytes_received += int_arg; - out_info->bytes_received += int_arg; - out_info->last_tx_rx_time = entry.time; - out_info->last_tx_rx_position = entry.order; - break; - case net::NetLog::TYPE_TCP_SOCKET_DONE: - return ACTION_MOVE_TO_GRAVEYARD; - default: - AddEntryToRequestInfo(entry, out_info); - break; + // TODO(eroman): aggregate the byte counts once truncation starts to happen, + // to summarize transaction read/writes for each SOCKET_IN_USE + // section. + if (entry.type == net::NetLog::TYPE_SOCKET_BYTES_SENT || + entry.type == net::NetLog::TYPE_SOCKET_BYTES_RECEIVED) { + return ACTION_NONE; } - return ACTION_NONE; -} -void PassiveLogCollector::SocketTracker::AppendLogEntries( - RequestInfo* out_info, uint32 socket_id, bool clear) { - RequestInfo* socket_info = GetRequestInfo(socket_id); - if (!socket_info) { - net::NetLogStringParameter* text = new net::NetLogStringParameter( - "todo", StringPrintf("Used Socket id=%u.", socket_id)); - Entry new_entry(0, net::NetLog::TYPE_TODO_STRING, base::TimeTicks(), - net::NetLog::Source(net::NetLog::SOURCE_SOCKET, socket_id), - net::NetLog::PHASE_NONE, text); - AddEntryToRequestInfo(new_entry, out_info); - return; - } + AddEntryToRequestInfo(entry, out_info); - AppendToRequestInfo(*socket_info, out_info); - out_info->num_entries_truncated += socket_info->num_entries_truncated; - - // Synthesize a log entry for bytes sent and received. - if (socket_info->bytes_transmitted > 0 || socket_info->bytes_received > 0) { - net::NetLogStringParameter* text = new net::NetLogStringParameter( - "stats", - StringPrintf("Tx/Rx: %"PRIu64"/%"PRIu64" [%"PRIu64"/%"PRIu64 - " total on socket] (Bytes)", - socket_info->bytes_transmitted, - socket_info->bytes_received, - socket_info->total_bytes_transmitted, - socket_info->total_bytes_received)); - Entry new_entry(socket_info->last_tx_rx_position, - net::NetLog::TYPE_TODO_STRING, - socket_info->last_tx_rx_time, - net::NetLog::Source(net::NetLog::SOURCE_SOCKET, socket_id), - net::NetLog::PHASE_NONE, - text); - AddEntryToRequestInfo(new_entry, out_info); + if (entry.type == net::NetLog::TYPE_SOCKET_ALIVE && + entry.phase == net::NetLog::PHASE_END) { + return ACTION_MOVE_TO_GRAVEYARD; } - std::sort(out_info->entries.begin(), out_info->entries.end(), - &SortByOrderComparator); - if (clear) - ClearInfo(socket_info); -} - -void PassiveLogCollector::SocketTracker::ClearInfo(RequestInfo* info) { - info->entries.clear(); - info->num_entries_truncated = 0; - info->bytes_transmitted = 0; - info->bytes_received = 0; - info->last_tx_rx_position = 0; - info->last_tx_rx_time = base::TimeTicks(); + return ACTION_NONE; } //---------------------------------------------------------------------------- @@ -436,59 +361,18 @@ void PassiveLogCollector::SocketTracker::ClearInfo(RequestInfo* info) { const size_t PassiveLogCollector::RequestTracker::kMaxGraveyardSize = 25; -PassiveLogCollector::RequestTracker::RequestTracker( - ConnectJobTracker* connect_job_tracker, SocketTracker* socket_tracker) - : RequestTrackerBase(kMaxGraveyardSize), - connect_job_tracker_(connect_job_tracker), - socket_tracker_(socket_tracker) { +PassiveLogCollector::RequestTracker::RequestTracker(PassiveLogCollector* parent) + : RequestTrackerBase(kMaxGraveyardSize, parent) { } PassiveLogCollector::RequestTrackerBase::Action PassiveLogCollector::RequestTracker::DoAddEntry(const Entry& entry, RequestInfo* out_info) { - // We expect up to three events with IDs. - // - Begin SOCKET_POOL_CONNECT_JOB_ID: Means a ConnectJob was created for - // this request. Including it for now, but the resulting socket may be - // used for a different request. - // - End SOCKET_POOL_CONNECT_JOB_ID: The named ConnectJob completed and - // this request will be getting the socket from that request. - // - SOCKET_POOL_SOCKET_ID: The given socket will be used for this request. - // - // The action to take when seeing these events depends on the current - // content of the |subordinate_source| field: - // |subordinate_source| is invalid (fresh state). - // - Begin SOCKET_POOL_CONNECT_JOB_ID: Set |subordinate_source|. - // - End SOCKET_POOL_CONNECT_JOB_ID: Integrate the named ConnectJob ID. - // - SOCKET_POOL_SOCKET_ID: Set |subordinate_source|. - // |subordinate_source| is a ConnectJob: - // - Begin SOCKET_POOL_CONNECT_JOB_ID: Set |subordinate_source|. - // - End SOCKET_POOL_CONNECT_JOB_ID: Integrate the named ConnectJob ID and - // clear the |subordinate_source|. - // - SOCKET_POOL_SOCKET_ID: Set |subordinate_source|. (The request was - // assigned a new idle socket, after starting a ConnectJob.) - // |subordinate_source| is a Socket: - // First, integrate the subordinate socket source, then: - // - Begin SOCKET_POOL_CONNECT_JOB_ID: Set |subordinate_source|. - // (Connection restarted with a new ConnectJob.) - // - End SOCKET_POOL_CONNECT_JOB_ID: Integrate the named ConnectJob ID and - // clear the |subordinate_source|. (Connection restarted with a late bound - // ConnectJob.) - // - SOCKET_POOL_SOCKET_ID: Set |subordinate_source|. (Connection - // restarted and got an idle socket.) - if (entry.type == net::NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID || - entry.type == net::NetLog::TYPE_SOCKET_POOL_SOCKET_ID) { - - if (out_info->subordinate_source.is_valid() && - out_info->subordinate_source.type == net::NetLog::SOURCE_SOCKET) - IntegrateSubordinateSource(out_info, true); - - SetSubordinateSource(out_info, entry); - - if (entry.phase == net::NetLog::PHASE_END && - entry.type == net::NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID) { - IntegrateSubordinateSource(out_info, true); - out_info->subordinate_source.id = net::NetLog::Source::kInvalidId; - } + if (entry.type == net::NetLog::TYPE_SOCKET_POOL_BOUND_TO_CONNECT_JOB || + entry.type == net::NetLog::TYPE_SOCKET_POOL_BOUND_TO_SOCKET) { + const net::NetLog::Source& source_dependency = + static_cast<net::NetLogSourceParameter*>(entry.params.get())->value(); + AddReferenceToSourceDependency(source_dependency, out_info); } AddEntryToRequestInfo(entry, out_info); @@ -496,7 +380,6 @@ PassiveLogCollector::RequestTracker::DoAddEntry(const Entry& entry, // If the request has ended, move it to the graveyard. if (entry.type == net::NetLog::TYPE_REQUEST_ALIVE && entry.phase == net::NetLog::PHASE_END) { - IntegrateSubordinateSource(out_info, true); if (StartsWithASCII(out_info->GetURL(), "chrome://", false)) { // Avoid sending "chrome://" requests to the graveyard, since it just // adds to clutter. @@ -508,53 +391,27 @@ PassiveLogCollector::RequestTracker::DoAddEntry(const Entry& entry, return ACTION_NONE; } -void PassiveLogCollector::RequestTracker::IntegrateSubordinateSource( - RequestInfo* info, bool clear_entries) const { - if (!info->subordinate_source.is_valid()) - return; - - uint32 subordinate_id = info->subordinate_source.id; - switch (info->subordinate_source.type) { - case net::NetLog::SOURCE_CONNECT_JOB: - connect_job_tracker_->AppendLogEntries(info, subordinate_id); - break; - case net::NetLog::SOURCE_SOCKET: - socket_tracker_->AppendLogEntries(info, subordinate_id, clear_entries); - break; - default: - NOTREACHED(); - break; - } -} - //---------------------------------------------------------------------------- // InitProxyResolverTracker //---------------------------------------------------------------------------- -PassiveLogCollector::InitProxyResolverTracker::InitProxyResolverTracker() {} +const size_t PassiveLogCollector::InitProxyResolverTracker::kMaxGraveyardSize = + 3; -void PassiveLogCollector::InitProxyResolverTracker::OnAddEntry( - const Entry& entry) { +PassiveLogCollector::InitProxyResolverTracker::InitProxyResolverTracker() + : RequestTrackerBase(kMaxGraveyardSize, NULL) { +} + +PassiveLogCollector::RequestTrackerBase::Action +PassiveLogCollector::InitProxyResolverTracker::DoAddEntry( + const Entry& entry, RequestInfo* out_info) { + AddEntryToRequestInfo(entry, out_info); if (entry.type == net::NetLog::TYPE_INIT_PROXY_RESOLVER && - entry.phase == net::NetLog::PHASE_BEGIN) { - // If this is the start of a new InitProxyResolver, overwrite the old data. - entries_.clear(); - entries_.push_back(entry); + entry.phase == net::NetLog::PHASE_END) { + return ACTION_MOVE_TO_GRAVEYARD; } else { - // Otherwise append it to the log for the latest InitProxyResolver. - if (!entries_.empty() && entries_[0].source.id != entry.source.id) { - // If this entry doesn't match what we think was the latest - // InitProxyResolver, drop it. (This shouldn't happen, but we will guard - // against it). - return; - } - entries_.push_back(entry); + return ACTION_NONE; } - - // Safety net: INIT_PROXY_RESOLVER shouldn't generate many messages, but in - // case something goes wrong, avoid exploding the memory usage. - if (entries_.size() > kMaxNumEntriesPerLog) - entries_.clear(); } //---------------------------------------------------------------------------- @@ -564,17 +421,17 @@ void PassiveLogCollector::InitProxyResolverTracker::OnAddEntry( const size_t PassiveLogCollector::SpdySessionTracker::kMaxGraveyardSize = 10; PassiveLogCollector::SpdySessionTracker::SpdySessionTracker() - : RequestTrackerBase(kMaxGraveyardSize) { + : RequestTrackerBase(kMaxGraveyardSize, NULL) { } PassiveLogCollector::RequestTrackerBase::Action PassiveLogCollector::SpdySessionTracker::DoAddEntry(const Entry& entry, RequestInfo* out_info) { + AddEntryToRequestInfo(entry, out_info); if (entry.type == net::NetLog::TYPE_SPDY_SESSION && entry.phase == net::NetLog::PHASE_END) { return ACTION_MOVE_TO_GRAVEYARD; } else { - AddEntryToRequestInfo(entry, out_info); return ACTION_NONE; } } diff --git a/chrome/browser/net/passive_log_collector.h b/chrome/browser/net/passive_log_collector.h index 2c59b67..a514428 100644 --- a/chrome/browser/net/passive_log_collector.h +++ b/chrome/browser/net/passive_log_collector.h @@ -5,6 +5,7 @@ #ifndef CHROME_BROWSER_NET_PASSIVE_LOG_COLLECTOR_H_ #define CHROME_BROWSER_NET_PASSIVE_LOG_COLLECTOR_H_ +#include <deque> #include <string> #include <vector> @@ -15,6 +16,21 @@ #include "chrome/browser/net/chrome_net_log.h" #include "net/base/net_log.h" +// PassiveLogCollector watches the NetLog event stream, and saves the network +// event for recent requests, in a circular buffer. +// +// This is done so that when a network problem is encountered (performance +// problem, or error), about:net-internals can be opened shortly after the +// problem and it will contain a trace for the problem request. +// +// (This is in contrast to the "active logging" which captures every single +// network event, but requires capturing to have been enabled *prior* to +// encountering the problem. Active capturing is enabled as long as +// about:net-internals is open). +// +// The data captured by PassiveLogCollector is grouped by NetLog::Source, into +// a RequestInfo structure. These in turn are grouped by NetLog::SourceType, and +// owned by a RequestTrackerBase instance for the specific source type. class PassiveLogCollector : public ChromeNetLog::Observer { public: // This structure encapsulates all of the parameters of a captured event, @@ -40,16 +56,13 @@ class PassiveLogCollector : public ChromeNetLog::Observer { }; typedef std::vector<Entry> EntryList; + typedef std::vector<net::NetLog::Source> SourceDependencyList; + // TODO(eroman): Rename to SourceInfo. struct RequestInfo { RequestInfo() : source_id(net::NetLog::Source::kInvalidId), - num_entries_truncated(0), - total_bytes_transmitted(0), - total_bytes_received(0), - bytes_transmitted(0), - bytes_received(0), - last_tx_rx_position(0) {} + num_entries_truncated(0), reference_count(0), is_alive(true) {} // Returns the URL that corresponds with this source. This is // only meaningful for certain source types (URL_REQUEST, SOCKET_STREAM). @@ -59,15 +72,21 @@ class PassiveLogCollector : public ChromeNetLog::Observer { uint32 source_id; EntryList entries; size_t num_entries_truncated; - net::NetLog::Source subordinate_source; - - // Only used in SocketTracker. - uint64 total_bytes_transmitted; - uint64 total_bytes_received; - uint64 bytes_transmitted; - uint64 bytes_received; - uint32 last_tx_rx_position; // The |order| of the last Tx or Rx entry. - base::TimeTicks last_tx_rx_time; // The |time| of the last Tx or Rx entry. + + // List of other sources which contain information relevant to this + // request (for example, a url request might depend on the log items + // for a connect job and for a socket that were bound to it.) + SourceDependencyList dependencies; + + // Holds the count of how many other sources have added this as a + // dependent source. When it is 0, it means noone has referenced it so it + // can be deleted normally. + int reference_count; + + // |is_alive| is set to false once the request has been added to the + // tracker's graveyard (it may still be kept around due to a non-zero + // reference_count, but it is still considered "dead"). + bool is_alive; }; typedef std::vector<RequestInfo> RequestInfoList; @@ -76,19 +95,32 @@ class PassiveLogCollector : public ChromeNetLog::Observer { // URLRequests/SocketStreams/ConnectJobs. class RequestTrackerBase { public: - explicit RequestTrackerBase(size_t max_graveyard_size); + RequestTrackerBase(size_t max_graveyard_size, PassiveLogCollector* parent); - void OnAddEntry(const Entry& entry); + virtual ~RequestTrackerBase(); - RequestInfoList GetLiveRequests() const; - void ClearRecentlyDeceased(); - RequestInfoList GetRecentlyDeceased() const; + void OnAddEntry(const Entry& entry); + // Clears all the passively logged data from this tracker. void Clear(); // Appends all the captured entries to |out|. The ordering is undefined. void AppendAllEntries(EntryList* out) const; +#ifdef UNIT_TEST + // Helper used to inspect the current state by unit-tests. + // Retuns a copy of the requests held by the tracker. + RequestInfoList GetAllDeadOrAliveRequests(bool is_alive) const { + RequestInfoList result; + for (SourceIDToInfoMap::const_iterator it = requests_.begin(); + it != requests_.end(); ++it) { + if (it->second.is_alive == is_alive) + result.push_back(it->second); + } + return result; + } +#endif + protected: enum Action { ACTION_NONE, @@ -96,29 +128,45 @@ class PassiveLogCollector : public ChromeNetLog::Observer { ACTION_MOVE_TO_GRAVEYARD, }; - // Finds a request, either in the live entries or the graveyard and returns - // it. - RequestInfo* GetRequestInfo(uint32 id); - - // When GetLiveRequests() is called, RequestTrackerBase calls this method - // for each entry after adding it to the list which will be returned - // to the caller. - virtual void OnLiveRequest(RequestInfo* info) const {} + // Makes |info| hold a reference to |source|. This way |source| will be + // kept alive at least as long as |info|. + void AddReferenceToSourceDependency(const net::NetLog::Source& source, + RequestInfo* info); private: typedef base::hash_map<uint32, RequestInfo> SourceIDToInfoMap; + typedef std::deque<uint32> DeletionQueue; // Updates |out_info| with the information from |entry|. Returns an action // to perform for this map entry on completion. virtual Action DoAddEntry(const Entry& entry, RequestInfo* out_info) = 0; - void RemoveFromLiveRequests(uint32 source_id); - void InsertIntoGraveyard(const RequestInfo& info); + // Removes |source_id| from |requests_|. This also releases any references + // to dependencies held by this source. + void DeleteRequestInfo(uint32 source_id); + + // Adds |source_id| to the FIFO queue (graveyard) for deletion. + void AddToDeletionQueue(uint32 source_id); + + // Adds/Releases a reference from the source with ID |source_id|. + // Use |offset=-1| to do a release, and |offset=1| for an addref. + void AdjustReferenceCountForSource(int offset, uint32 source_id); + + // Releases all the references to sources held by |info|. + void ReleaseAllReferencesToDependencies(RequestInfo* info); + + // This map contains all of the requests being tracked by this tracker. + // (It includes both the "live" requests, and the "dead" ones.) + SourceIDToInfoMap requests_; - SourceIDToInfoMap live_requests_; size_t max_graveyard_size_; - size_t next_graveyard_index_; - RequestInfoList graveyard_; + + // FIFO queue for entries in |requests_| that are no longer alive, and + // can be deleted. This buffer is also called "graveyard" elsewhere. We + // queue requests for deletion so they can persist a bit longer. + DeletionQueue deletion_queue_; + + PassiveLogCollector* parent_; DISALLOW_COPY_AND_ASSIGN(RequestTrackerBase); }; @@ -128,9 +176,7 @@ class PassiveLogCollector : public ChromeNetLog::Observer { public: static const size_t kMaxGraveyardSize; - ConnectJobTracker(); - - void AppendLogEntries(RequestInfo* out_info, uint32 connect_id); + explicit ConnectJobTracker(PassiveLogCollector* parent); protected: virtual Action DoAddEntry(const Entry& entry, RequestInfo* out_info); @@ -145,14 +191,10 @@ class PassiveLogCollector : public ChromeNetLog::Observer { SocketTracker(); - void AppendLogEntries(RequestInfo* out_info, uint32 socket_id, bool clear); - protected: virtual Action DoAddEntry(const Entry& entry, RequestInfo* out_info); private: - void ClearInfo(RequestInfo* info); - DISALLOW_COPY_AND_ASSIGN(SocketTracker); }; @@ -161,39 +203,27 @@ class PassiveLogCollector : public ChromeNetLog::Observer { public: static const size_t kMaxGraveyardSize; - RequestTracker(ConnectJobTracker* connect_job_tracker, - SocketTracker* socket_tracker); - - void IntegrateSubordinateSource(RequestInfo* info, - bool clear_entries) const; + explicit RequestTracker(PassiveLogCollector* parent); protected: virtual Action DoAddEntry(const Entry& entry, RequestInfo* out_info); - virtual void OnLiveRequest(RequestInfo* info) const { - IntegrateSubordinateSource(info, false); - } - private: - ConnectJobTracker* connect_job_tracker_; - SocketTracker* socket_tracker_; - DISALLOW_COPY_AND_ASSIGN(RequestTracker); }; - // Tracks the log entries for the last seen SOURCE_INIT_PROXY_RESOLVER. - class InitProxyResolverTracker { + // Specialization of RequestTrackerBase for handling + // SOURCE_INIT_PROXY_RESOLVER. + class InitProxyResolverTracker : public RequestTrackerBase { public: - InitProxyResolverTracker(); + static const size_t kMaxGraveyardSize; - void OnAddEntry(const Entry& entry); + InitProxyResolverTracker(); - const EntryList& entries() const { - return entries_; - } + protected: + virtual Action DoAddEntry(const Entry& entry, RequestInfo* out_info); private: - EntryList entries_; DISALLOW_COPY_AND_ASSIGN(InitProxyResolverTracker); }; @@ -221,32 +251,20 @@ class PassiveLogCollector : public ChromeNetLog::Observer { net::NetLog::EventPhase phase, net::NetLog::EventParameters* params); + // Returns the tracker to use for sources of type |source_type|, or NULL. + RequestTrackerBase* GetTrackerForSourceType( + net::NetLog::SourceType source_type); + // Clears all of the passively logged data. void Clear(); - RequestTracker* url_request_tracker() { - return &url_request_tracker_; - } - - RequestTracker* socket_stream_tracker() { - return &socket_stream_tracker_; - } - - InitProxyResolverTracker* init_proxy_resolver_tracker() { - return &init_proxy_resolver_tracker_; - } - - SpdySessionTracker* spdy_session_tracker() { - return &spdy_session_tracker_; - } - // Fills |out| with the full list of events that have been passively // captured. The list is ordered by capture time. void GetAllCapturedEvents(EntryList* out) const; private: - FRIEND_TEST_ALL_PREFIXES(PassiveLogCollectorTest, LostConnectJob); - FRIEND_TEST_ALL_PREFIXES(PassiveLogCollectorTest, LostSocket); + FRIEND_TEST_ALL_PREFIXES(PassiveLogCollectorTest, + HoldReferenceToDependentSource); ConnectJobTracker connect_job_tracker_; SocketTracker socket_tracker_; @@ -255,6 +273,11 @@ class PassiveLogCollector : public ChromeNetLog::Observer { InitProxyResolverTracker init_proxy_resolver_tracker_; SpdySessionTracker spdy_session_tracker_; + // This array maps each NetLog::SourceType to one of the tracker instances + // defined above. Use of this array avoid duplicating the list of trackers + // elsewhere. + RequestTrackerBase* trackers_[net::NetLog::SOURCE_COUNT]; + // The count of how many events have flowed through this log. Used to set the // "order" field on captured events. uint32 num_events_seen_; diff --git a/chrome/browser/net/passive_log_collector_unittest.cc b/chrome/browser/net/passive_log_collector_unittest.cc index 41209404..3e0894c 100644 --- a/chrome/browser/net/passive_log_collector_unittest.cc +++ b/chrome/browser/net/passive_log_collector_unittest.cc @@ -14,6 +14,7 @@ namespace { typedef PassiveLogCollector::RequestTracker RequestTracker; typedef PassiveLogCollector::RequestInfoList RequestInfoList; +typedef PassiveLogCollector::SocketTracker SocketTracker; using net::NetLog; const NetLog::SourceType kSourceType = NetLog::SOURCE_NONE; @@ -65,14 +66,33 @@ std::string GetStringParam(const PassiveLogCollector::Entry& entry) { entry.params.get())->value(); } +bool OrderBySourceID(const PassiveLogCollector::RequestInfo& a, + const PassiveLogCollector::RequestInfo& b) { + return a.source_id < b.source_id; +} + +RequestInfoList GetLiveRequests( + const PassiveLogCollector::RequestTrackerBase& tracker) { + RequestInfoList result = tracker.GetAllDeadOrAliveRequests(true); + std::sort(result.begin(), result.end(), &OrderBySourceID); + return result; +} + +RequestInfoList GetDeadRequests( + const PassiveLogCollector::RequestTrackerBase& tracker) { + RequestInfoList result = tracker.GetAllDeadOrAliveRequests(false); + std::sort(result.begin(), result.end(), &OrderBySourceID); + return result; +} + static const int kMaxNumLoadLogEntries = 1; } // namespace TEST(RequestTrackerTest, BasicBounded) { - RequestTracker tracker(NULL, NULL); - EXPECT_EQ(0u, tracker.GetLiveRequests().size()); - EXPECT_EQ(0u, tracker.GetRecentlyDeceased().size()); + RequestTracker tracker(NULL); + EXPECT_EQ(0u, GetLiveRequests(tracker).size()); + EXPECT_EQ(0u, GetDeadRequests(tracker).size()); tracker.OnAddEntry(MakeStartLogEntry(1)); tracker.OnAddEntry(MakeStartLogEntry(2)); @@ -80,7 +100,7 @@ TEST(RequestTrackerTest, BasicBounded) { tracker.OnAddEntry(MakeStartLogEntry(4)); tracker.OnAddEntry(MakeStartLogEntry(5)); - RequestInfoList live_reqs = tracker.GetLiveRequests(); + RequestInfoList live_reqs = GetLiveRequests(tracker); ASSERT_EQ(5u, live_reqs.size()); EXPECT_EQ("http://req1/", live_reqs[0].GetURL()); @@ -93,9 +113,9 @@ TEST(RequestTrackerTest, BasicBounded) { tracker.OnAddEntry(MakeEndLogEntry(5)); tracker.OnAddEntry(MakeEndLogEntry(3)); - ASSERT_EQ(3u, tracker.GetRecentlyDeceased().size()); + ASSERT_EQ(3u, GetDeadRequests(tracker).size()); - live_reqs = tracker.GetLiveRequests(); + live_reqs = GetLiveRequests(tracker); ASSERT_EQ(2u, live_reqs.size()); EXPECT_EQ("http://req2/", live_reqs[0].GetURL()); @@ -103,9 +123,9 @@ TEST(RequestTrackerTest, BasicBounded) { } TEST(RequestTrackerTest, GraveyardBounded) { - RequestTracker tracker(NULL, NULL); - EXPECT_EQ(0u, tracker.GetLiveRequests().size()); - EXPECT_EQ(0u, tracker.GetRecentlyDeceased().size()); + RequestTracker tracker(NULL); + EXPECT_EQ(0u, GetLiveRequests(tracker).size()); + EXPECT_EQ(0u, GetDeadRequests(tracker).size()); // Add twice as many requests as will fit in the graveyard. for (size_t i = 0; i < RequestTracker::kMaxGraveyardSize * 2; ++i) { @@ -113,9 +133,11 @@ TEST(RequestTrackerTest, GraveyardBounded) { tracker.OnAddEntry(MakeEndLogEntry(i)); } + EXPECT_EQ(0u, GetLiveRequests(tracker).size()); + // Check that only the last |kMaxGraveyardSize| requests are in-memory. - RequestInfoList recent_reqs = tracker.GetRecentlyDeceased(); + RequestInfoList recent_reqs = GetDeadRequests(tracker); ASSERT_EQ(RequestTracker::kMaxGraveyardSize, recent_reqs.size()); @@ -129,7 +151,7 @@ TEST(RequestTrackerTest, GraveyardBounded) { // Check that we exclude "chrome://" URLs from being saved into the recent // requests list (graveyard). TEST(RequestTrackerTest, GraveyardIsFiltered) { - RequestTracker tracker(NULL, NULL); + RequestTracker tracker(NULL); // This will be excluded. std::string url1 = "chrome://dontcare/"; @@ -146,824 +168,15 @@ TEST(RequestTrackerTest, GraveyardIsFiltered) { tracker.OnAddEntry(MakeStartLogEntryWithURL(3, url3)); tracker.OnAddEntry(MakeEndLogEntry(3)); - ASSERT_EQ(2u, tracker.GetRecentlyDeceased().size()); - EXPECT_EQ(url2, tracker.GetRecentlyDeceased()[0].GetURL()); - EXPECT_EQ(url3, tracker.GetRecentlyDeceased()[1].GetURL()); -} - -TEST(PassiveLogCollectorTest, BasicConnectJobAssociation) { - PassiveLogCollector log; - - RequestInfoList requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - AddStartURLRequestEntries(&log, 10); - AddStartURLRequestEntries(&log, 20); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(10u, requests[0].source_id); - EXPECT_EQ(2u, requests[0].entries.size()); - EXPECT_EQ(20u, requests[1].source_id); - EXPECT_EQ(2u, requests[1].entries.size()); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_BEGIN, NULL); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 21)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_END, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(4u, requests[0].entries.size()); - EXPECT_EQ(5u, requests[1].entries.size()); - - AddEndURLRequestEntries(&log, 10); - AddEndURLRequestEntries(&log, 20); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - requests = log.url_request_tracker()->GetRecentlyDeceased(); - EXPECT_EQ(2u, requests.size()); - EXPECT_EQ(5u, requests[0].entries.size()); - EXPECT_EQ(6u, requests[1].entries.size()); -} - -TEST(PassiveLogCollectorTest, BasicSocketAssociation) { - PassiveLogCollector log; - - RequestInfoList requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - AddStartURLRequestEntries(&log, 10); - AddStartURLRequestEntries(&log, 20); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_END, NULL); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 21)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_TCP_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_END, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(5u, requests[0].entries.size()); - EXPECT_EQ(6u, requests[1].entries.size()); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 11)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 21)); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(6u, requests[0].entries.size()); - EXPECT_EQ(7u, requests[1].entries.size()); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 25)); - - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_END, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(8u, requests[0].entries.size()); - EXPECT_EQ(10u, requests[1].entries.size()); - - AddEndURLRequestEntries(&log, 10); - AddEndURLRequestEntries(&log, 20); - - log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - requests = log.url_request_tracker()->GetRecentlyDeceased(); - EXPECT_EQ(2u, requests.size()); - EXPECT_EQ(9u, requests[0].entries.size()); - EXPECT_EQ(11u, requests[1].entries.size()); -} - -TEST(PassiveLogCollectorTest, IdleSocketAssociation) { - PassiveLogCollector log; - - RequestInfoList requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - AddStartURLRequestEntries(&log, 10); - AddStartURLRequestEntries(&log, 20); - log.OnAddEntry(NetLog::TYPE_INIT_PROXY_RESOLVER , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(2u, requests[0].entries.size()); - EXPECT_EQ(3u, requests[1].entries.size()); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 25)); - - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_END, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(4u, requests[0].entries.size()); - EXPECT_EQ(6u, requests[1].entries.size()); - - AddEndURLRequestEntries(&log, 10); - AddEndURLRequestEntries(&log, 20); - - log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - requests = log.url_request_tracker()->GetRecentlyDeceased(); - EXPECT_EQ(2u, requests.size()); - EXPECT_EQ(5u, requests[0].entries.size()); - EXPECT_EQ(7u, requests[1].entries.size()); -} - -TEST(PassiveLogCollectorTest, IdleAssociateAfterConnectJobStarted) { - PassiveLogCollector log; - - RequestInfoList requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - AddStartURLRequestEntries(&log, 10); - AddStartURLRequestEntries(&log, 20); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_END, NULL); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 21)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_TCP_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_END, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(5u, requests[0].entries.size()); - EXPECT_EQ(6u, requests[1].entries.size()); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 25)); - - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_END, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(5u, requests[0].entries.size()); - EXPECT_EQ(6u, requests[1].entries.size()); - - AddEndURLRequestEntries(&log, 10); - AddEndURLRequestEntries(&log, 20); - - log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - requests = log.url_request_tracker()->GetRecentlyDeceased(); - EXPECT_EQ(2u, requests.size()); - EXPECT_EQ(6u, requests[0].entries.size()); - EXPECT_EQ(7u, requests[1].entries.size()); -} - -TEST(PassiveLogCollectorTest, LateBindDifferentConnectJob) { - PassiveLogCollector log; - - RequestInfoList requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - AddStartURLRequestEntries(&log, 10); - AddStartURLRequestEntries(&log, 20); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_END, NULL); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 21)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_TCP_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_END, NULL); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 31), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_TCP_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 31), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_TCP_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 31), - NetLog::PHASE_END, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 31), - NetLog::PHASE_END, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(5u, requests[0].entries.size()); - EXPECT_EQ(6u, requests[1].entries.size()); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 21)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 31)); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(7u, requests[0].entries.size()); - EXPECT_EQ(8u, requests[1].entries.size()); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 25)); - - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_END, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(9u, requests[0].entries.size()); - EXPECT_EQ(11u, requests[1].entries.size()); - - AddEndURLRequestEntries(&log, 10); - AddEndURLRequestEntries(&log, 20); - - log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - requests = log.url_request_tracker()->GetRecentlyDeceased(); - EXPECT_EQ(2u, requests.size()); - EXPECT_EQ(10u, requests[0].entries.size()); - EXPECT_EQ(12u, requests[1].entries.size()); -} - -TEST(PassiveLogCollectorTest, LateBindPendingConnectJob) { - PassiveLogCollector log; - - RequestInfoList requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - AddStartURLRequestEntries(&log, 10); - AddStartURLRequestEntries(&log, 20); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_END, NULL); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_TCP_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21), - NetLog::PHASE_END, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(2u, requests[0].entries.size()); - EXPECT_EQ(2u, requests[1].entries.size()); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 11)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 21)); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(5u, requests[0].entries.size()); - EXPECT_EQ(6u, requests[1].entries.size()); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 25)); - - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_END, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(2u, requests.size()); - - EXPECT_EQ(7u, requests[0].entries.size()); - EXPECT_EQ(9u, requests[1].entries.size()); - - AddEndURLRequestEntries(&log, 10); - AddEndURLRequestEntries(&log, 20); - - log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 25), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - requests = log.url_request_tracker()->GetRecentlyDeceased(); - EXPECT_EQ(2u, requests.size()); - EXPECT_EQ(8u, requests[0].entries.size()); - EXPECT_EQ(10u, requests[1].entries.size()); -} - -TEST(PassiveLogCollectorTest, ReconnectToIdleSocket) { - PassiveLogCollector log; - - RequestInfoList requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - AddStartURLRequestEntries(&log, 10); - - // Initial socket. - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15)); - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(4u, requests[0].entries.size()); - - // Reconnect. - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 17)); - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 17), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(6u, requests[0].entries.size()); - - AddEndURLRequestEntries(&log, 10); - - log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - requests = log.url_request_tracker()->GetRecentlyDeceased(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(7u, requests[0].entries.size()); -} - -TEST(PassiveLogCollectorTest, ReconnectToLateBoundSocket) { - PassiveLogCollector log; - - RequestInfoList requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - AddStartURLRequestEntries(&log, 10); - - // Initial socket. - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15)); - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(4u, requests[0].entries.size()); - - // Now reconnect. - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_BEGIN, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(6u, requests[0].entries.size()); - - // But we get late bound to an idle socket. - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 17)); - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 17), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(7u, requests[0].entries.size()); - - AddEndURLRequestEntries(&log, 10); - - log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - requests = log.url_request_tracker()->GetRecentlyDeceased(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(8u, requests[0].entries.size()); -} - -TEST(PassiveLogCollectorTest, ReconnectToLateBoundConnectJob) { - PassiveLogCollector log; - - RequestInfoList requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - AddStartURLRequestEntries(&log, 10); - - // Initial socket. - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15)); - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(4u, requests[0].entries.size()); - - // Now reconnect. - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_BEGIN, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(6u, requests[0].entries.size()); - - // But we get late bound to a different ConnectJob. - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 12), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 12), - NetLog::PHASE_END, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 12)); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(8u, requests[0].entries.size()); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 17)); - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 17), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(10u, requests[0].entries.size()); - - AddEndURLRequestEntries(&log, 10); - - log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - requests = log.url_request_tracker()->GetRecentlyDeceased(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(11u, requests[0].entries.size()); -} - -TEST(PassiveLogCollectorTest, LostConnectJob) { - PassiveLogCollector log; - - RequestInfoList requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - AddStartURLRequestEntries(&log, 10); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11)); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_NONE, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11), - NetLog::PHASE_END, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(6u, requests[0].entries.size()); - - log.connect_job_tracker_.Clear(); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 11)); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(5u, requests[0].entries.size()); -} - -TEST(PassiveLogCollectorTest, LostSocket) { - PassiveLogCollector log; - - RequestInfoList requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - AddStartURLRequestEntries(&log, 10); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15)); - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_END, NULL); - log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_BEGIN, NULL); - log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_END, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(7u, requests[0].entries.size()); - - log.socket_tracker_.Clear(); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(4u, requests[0].entries.size()); -} - -TEST(PassiveLogCollectorTest, AccumulateRxTxData) { - PassiveLogCollector log; - - RequestInfoList requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - - AddStartURLRequestEntries(&log, 10); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15)); - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(4u, requests[0].entries.size()); - - log.OnAddEntry(NetLog::TYPE_SOCKET_BYTES_SENT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 1)); - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(5u, requests[0].entries.size()); - EXPECT_EQ(NetLog::TYPE_TODO_STRING, requests[0].entries[4].type); - EXPECT_EQ("Tx/Rx: 1/0 [1/0 total on socket] (Bytes)", - GetStringParam(requests[0].entries[4])); - - log.OnAddEntry(NetLog::TYPE_SOCKET_BYTES_RECEIVED , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 2)); - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(5u, requests[0].entries.size()); - EXPECT_EQ(NetLog::TYPE_TODO_STRING, requests[0].entries[4].type); - EXPECT_EQ("Tx/Rx: 1/2 [1/2 total on socket] (Bytes)", - GetStringParam(requests[0].entries[4])); - - AddEndURLRequestEntries(&log, 10); - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - requests = log.url_request_tracker()->GetRecentlyDeceased(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(6u, requests[0].entries.size()); - EXPECT_EQ(NetLog::TYPE_TODO_STRING, requests[0].entries[4].type); - EXPECT_EQ("Tx/Rx: 1/2 [1/2 total on socket] (Bytes)", - GetStringParam(requests[0].entries[4])); - - AddStartURLRequestEntries(&log, 20); - - log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15)); - log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_NONE, NULL); - - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(4u, requests[0].entries.size()); - - log.OnAddEntry(NetLog::TYPE_SOCKET_BYTES_SENT , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 4)); - log.OnAddEntry(NetLog::TYPE_SOCKET_BYTES_RECEIVED , base::TimeTicks(), - NetLog::Source(NetLog::SOURCE_SOCKET, 15), - NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 8)); - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(1u, requests.size()); - EXPECT_EQ(5u, requests[0].entries.size()); - EXPECT_EQ(NetLog::TYPE_TODO_STRING, requests[0].entries[4].type); - EXPECT_EQ("Tx/Rx: 4/8 [5/10 total on socket] (Bytes)", - GetStringParam(requests[0].entries[4])); - - AddEndURLRequestEntries(&log, 20); - requests = log.url_request_tracker()->GetLiveRequests(); - EXPECT_EQ(0u, requests.size()); - requests = log.url_request_tracker()->GetRecentlyDeceased(); - EXPECT_EQ(2u, requests.size()); - EXPECT_EQ(6u, requests[0].entries.size()); - EXPECT_EQ(6u, requests[1].entries.size()); + ASSERT_EQ(2u, GetDeadRequests(tracker).size()); + EXPECT_EQ(url2, GetDeadRequests(tracker)[0].GetURL()); + EXPECT_EQ(url3, GetDeadRequests(tracker)[1].GetURL()); } TEST(SpdySessionTracker, MovesToGraveyard) { PassiveLogCollector::SpdySessionTracker tracker; - EXPECT_EQ(0u, tracker.GetLiveRequests().size()); - EXPECT_EQ(0u, tracker.GetRecentlyDeceased().size()); + EXPECT_EQ(0u, GetLiveRequests(tracker).size()); + EXPECT_EQ(0u, GetDeadRequests(tracker).size()); PassiveLogCollector::Entry begin( 0u, @@ -974,8 +187,8 @@ TEST(SpdySessionTracker, MovesToGraveyard) { NULL); tracker.OnAddEntry(begin); - EXPECT_EQ(1u, tracker.GetLiveRequests().size()); - EXPECT_EQ(0u, tracker.GetRecentlyDeceased().size()); + EXPECT_EQ(1u, GetLiveRequests(tracker).size()); + EXPECT_EQ(0u, GetDeadRequests(tracker).size()); PassiveLogCollector::Entry end( 0u, @@ -986,6 +199,155 @@ TEST(SpdySessionTracker, MovesToGraveyard) { NULL); tracker.OnAddEntry(end); - EXPECT_EQ(0u, tracker.GetLiveRequests().size()); - EXPECT_EQ(1u, tracker.GetRecentlyDeceased().size()); + EXPECT_EQ(0u, GetLiveRequests(tracker).size()); + EXPECT_EQ(1u, GetDeadRequests(tracker).size()); +} + +// Test that when a SOURCE_SOCKET is connected to a SOURCE_URL_REQUEST +// (via the TYPE_SOCKET_POOL_BOUND_TO_SOCKET event), it holds a reference +// to the SOURCE_SOCKET preventing it from getting deleted as long as the +// SOURCE_URL_REQUEST is still around. +TEST(PassiveLogCollectorTest, HoldReferenceToDependentSource) { + PassiveLogCollector log; + + EXPECT_EQ(0u, GetLiveRequests(log.url_request_tracker_).size()); + EXPECT_EQ(0u, GetLiveRequests(log.socket_tracker_).size()); + + uint32 next_id = 0; + NetLog::Source socket_source(NetLog::SOURCE_SOCKET, next_id++); + NetLog::Source url_request_source(NetLog::SOURCE_URL_REQUEST, next_id++); + + // Start a SOURCE_SOCKET. + log.OnAddEntry(NetLog::TYPE_SOCKET_ALIVE, + base::TimeTicks(), + socket_source, + NetLog::PHASE_BEGIN, + NULL); + + EXPECT_EQ(0u, GetLiveRequests(log.url_request_tracker_).size()); + EXPECT_EQ(1u, GetLiveRequests(log.socket_tracker_).size()); + + // Start a SOURCE_URL_REQUEST. + log.OnAddEntry(NetLog::TYPE_REQUEST_ALIVE, + base::TimeTicks(), + url_request_source, + NetLog::PHASE_BEGIN, + NULL); + + // Check that there is no association between the SOURCE_URL_REQUEST and the + // SOURCE_SOCKET yet. + ASSERT_EQ(1u, GetLiveRequests(log.url_request_tracker_).size()); + { + PassiveLogCollector::RequestInfo info = + GetLiveRequests(log.url_request_tracker_)[0]; + EXPECT_EQ(0, info.reference_count); + EXPECT_EQ(0u, info.dependencies.size()); + } + ASSERT_EQ(1u, GetLiveRequests(log.socket_tracker_).size()); + { + PassiveLogCollector::RequestInfo info = + GetLiveRequests(log.socket_tracker_)[0]; + EXPECT_EQ(0, info.reference_count); + EXPECT_EQ(0u, info.dependencies.size()); + } + + // Associate the SOURCE_SOCKET with the SOURCE_URL_REQUEST. + log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_BOUND_TO_SOCKET, + base::TimeTicks(), + url_request_source, + NetLog::PHASE_NONE, + new net::NetLogSourceParameter("x", socket_source)); + + // Check that an associate was made -- the SOURCE_URL_REQUEST should have + // added a reference to the SOURCE_SOCKET. + ASSERT_EQ(1u, GetLiveRequests(log.url_request_tracker_).size()); + { + PassiveLogCollector::RequestInfo info = + GetLiveRequests(log.url_request_tracker_)[0]; + EXPECT_EQ(0, info.reference_count); + EXPECT_EQ(1u, info.dependencies.size()); + EXPECT_EQ(socket_source.id, info.dependencies[0].id); + } + ASSERT_EQ(1u, GetLiveRequests(log.socket_tracker_).size()); + { + PassiveLogCollector::RequestInfo info = + GetLiveRequests(log.socket_tracker_)[0]; + EXPECT_EQ(1, info.reference_count); + EXPECT_EQ(0u, info.dependencies.size()); + } + + // Now end both |source_socket| and |source_url_request|. This sends them + // to deletion queue, and they will be deleted once space runs out. + + log.OnAddEntry(NetLog::TYPE_REQUEST_ALIVE, + base::TimeTicks(), + url_request_source, + NetLog::PHASE_END, + NULL); + + log.OnAddEntry(NetLog::TYPE_SOCKET_ALIVE, + base::TimeTicks(), + socket_source, + NetLog::PHASE_END, + NULL); + + // Verify that both sources are in fact dead, and that |source_url_request| + // still holds a reference to |source_socket|. + ASSERT_EQ(0u, GetLiveRequests(log.url_request_tracker_).size()); + ASSERT_EQ(1u, GetDeadRequests(log.url_request_tracker_).size()); + { + PassiveLogCollector::RequestInfo info = + GetDeadRequests(log.url_request_tracker_)[0]; + EXPECT_EQ(0, info.reference_count); + EXPECT_EQ(1u, info.dependencies.size()); + EXPECT_EQ(socket_source.id, info.dependencies[0].id); + } + EXPECT_EQ(0u, GetLiveRequests(log.socket_tracker_).size()); + ASSERT_EQ(1u, GetDeadRequests(log.socket_tracker_).size()); + { + PassiveLogCollector::RequestInfo info = + GetDeadRequests(log.socket_tracker_)[0]; + EXPECT_EQ(1, info.reference_count); + EXPECT_EQ(0u, info.dependencies.size()); + } + + // Cycle through a bunch of SOURCE_SOCKET -- if it were not referenced, this + // loop will have deleted it. + for (size_t i = 0; i < SocketTracker::kMaxGraveyardSize; ++i) { + log.OnAddEntry(NetLog::TYPE_SOCKET_ALIVE, + base::TimeTicks(), + NetLog::Source(NetLog::SOURCE_SOCKET, next_id++), + NetLog::PHASE_END, + NULL); + } + + EXPECT_EQ(0u, GetLiveRequests(log.socket_tracker_).size()); + ASSERT_EQ(SocketTracker::kMaxGraveyardSize + 1, + GetDeadRequests(log.socket_tracker_).size()); + { + PassiveLogCollector::RequestInfo info = + GetDeadRequests(log.socket_tracker_)[0]; + EXPECT_EQ(socket_source.id, info.source_id); + EXPECT_EQ(1, info.reference_count); + EXPECT_EQ(0u, info.dependencies.size()); + } + + // Cycle through a bunch of SOURCE_URL_REQUEST -- this will cause + // |source_url_request| to be freed, which in turn should release the final + // reference to |source_socket| cause it to be freed as well. + for (size_t i = 0; i < RequestTracker::kMaxGraveyardSize; ++i) { + log.OnAddEntry(NetLog::TYPE_REQUEST_ALIVE, + base::TimeTicks(), + NetLog::Source(NetLog::SOURCE_URL_REQUEST, next_id++), + NetLog::PHASE_END, + NULL); + } + + EXPECT_EQ(0u, GetLiveRequests(log.url_request_tracker_).size()); + EXPECT_EQ(RequestTracker::kMaxGraveyardSize, + GetDeadRequests(log.url_request_tracker_).size()); + + EXPECT_EQ(0u, GetLiveRequests(log.socket_tracker_).size()); + EXPECT_EQ(SocketTracker::kMaxGraveyardSize, + GetDeadRequests(log.socket_tracker_).size()); } |