diff options
author | vandebo@chromium.org <vandebo@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2010-04-23 16:44:02 +0000 |
---|---|---|
committer | vandebo@chromium.org <vandebo@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2010-04-23 16:44:02 +0000 |
commit | a2006ecefa10d259d0a85ac4146b913eb0f9d02f (patch) | |
tree | 67fc5e5f6339f2fa5e53735a30324e47de22005a /chrome/browser/net | |
parent | f044ce8e4aeef63eb7686345f407bf5640045c18 (diff) | |
download | chromium_src-a2006ecefa10d259d0a85ac4146b913eb0f9d02f.zip chromium_src-a2006ecefa10d259d0a85ac4146b913eb0f9d02f.tar.gz chromium_src-a2006ecefa10d259d0a85ac4146b913eb0f9d02f.tar.bz2 |
Add net log entries that summarize transmit and receive byte counts.
Tx/Rx summaries are integrated into the net log at the last point that bytes were transmitted or received.
Hopefully this will help resolve http://crbug.com/37729 by showing if we've received bytes over the network when we hit the "Waiting for cache" bug.
This change also modernizes the use of NetLog:
- ClientSocket now has a net_log() accessor
- ClientSocket::Connect no longer takes a NetLog, instead the TCPClientSocket constructor takes one, others use their transport socket's NetLog
- TCPClientSocket creates a new source id with source type SOCKET
Also updates PassiveLogCollector infrastructure:
- The LiveRequestsObserver lets a RequestTracker update a RequestInfo just before it is displayed. This allows ConnectJobs to be associated with URLRequests while connecting and then reassociated if they are late-bound to a different request.
BUG=37729
TEST=tx/rx lines show up in chrome://net-internals/
Review URL: http://codereview.chromium.org/1696005
git-svn-id: svn://svn.chromium.org/chrome/trunk/src@45449 0039d316-1c4b-4281-b951-d872f2087c98
Diffstat (limited to 'chrome/browser/net')
-rw-r--r-- | chrome/browser/net/chrome_net_log.cc | 6 | ||||
-rw-r--r-- | chrome/browser/net/chrome_net_log.h | 4 | ||||
-rw-r--r-- | chrome/browser/net/passive_log_collector.cc | 268 | ||||
-rw-r--r-- | chrome/browser/net/passive_log_collector.h | 88 | ||||
-rw-r--r-- | chrome/browser/net/passive_log_collector_unittest.cc | 866 | ||||
-rw-r--r-- | chrome/browser/net/view_net_internals_job_factory.cc | 6 |
6 files changed, 1149 insertions, 89 deletions
diff --git a/chrome/browser/net/chrome_net_log.cc b/chrome/browser/net/chrome_net_log.cc index efb27be..b9c425d 100644 --- a/chrome/browser/net/chrome_net_log.cc +++ b/chrome/browser/net/chrome_net_log.cc @@ -12,7 +12,7 @@ #include "chrome/browser/net/passive_log_collector.h" ChromeNetLog::ChromeNetLog() - : next_id_(0), + : next_id_(1), passive_collector_(new PassiveLogCollector) { DCHECK(ChromeThread::CurrentlyOn(ChromeThread::IO)); AddObserver(passive_collector_.get()); @@ -35,7 +35,7 @@ void ChromeNetLog::AddEntry(EventType type, OnAddEntry(type, time, source, phase, extra_parameters)); } -int ChromeNetLog::NextID() { +uint32 ChromeNetLog::NextID() { DCHECK(ChromeThread::CurrentlyOn(ChromeThread::IO)); return next_id_++; } @@ -43,7 +43,7 @@ int ChromeNetLog::NextID() { bool ChromeNetLog::HasListener() const { DCHECK(ChromeThread::CurrentlyOn(ChromeThread::IO)); // TODO(eroman): Hack to get refactor working. - return passive_collector_->url_request_tracker()->IsUnbounded(); + return passive_collector_->url_request_tracker()->is_unbounded(); } void ChromeNetLog::AddObserver(Observer* observer) { diff --git a/chrome/browser/net/chrome_net_log.h b/chrome/browser/net/chrome_net_log.h index 7a50eca..b2f0d55 100644 --- a/chrome/browser/net/chrome_net_log.h +++ b/chrome/browser/net/chrome_net_log.h @@ -41,7 +41,7 @@ class ChromeNetLog : public net::NetLog { const Source& source, EventPhase phase, EventParameters* extra_parameters); - virtual int NextID(); + virtual uint32 NextID(); virtual bool HasListener() const; void AddObserver(Observer* observer); @@ -52,7 +52,7 @@ class ChromeNetLog : public net::NetLog { } private: - int next_id_; + uint32 next_id_; scoped_ptr<PassiveLogCollector> passive_collector_; ObserverList<Observer, true> observers_; diff --git a/chrome/browser/net/passive_log_collector.cc b/chrome/browser/net/passive_log_collector.cc index 64484da..9ffac48 100644 --- a/chrome/browser/net/passive_log_collector.cc +++ b/chrome/browser/net/passive_log_collector.cc @@ -7,6 +7,7 @@ #include <algorithm> #include "base/string_util.h" +#include "base/format_macros.h" #include "chrome/browser/chrome_thread.h" namespace { @@ -18,7 +19,7 @@ const size_t kMaxLiveRequests = 200; // Sort function on source ID. bool OrderBySourceID(const PassiveLogCollector::RequestInfo& a, const PassiveLogCollector::RequestInfo& b) { - return a.entries[0].source.id < b.entries[0].source.id; + return a.source_id < b.source_id; } void AddEntryToRequestInfo(const PassiveLogCollector::Entry& entry, @@ -56,6 +57,23 @@ bool SortByOrderComparator(const PassiveLogCollector::Entry& a, return a.order < b.order; } +void SetSubordinateSource(PassiveLogCollector::RequestInfo* info, + const PassiveLogCollector::Entry& entry) { + info->subordinate_source.id = static_cast<net::NetLogIntegerParameter*>( + entry.extra_parameters.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 //---------------------------------------------------------------------------- @@ -63,8 +81,8 @@ bool SortByOrderComparator(const PassiveLogCollector::Entry& a, //---------------------------------------------------------------------------- PassiveLogCollector::PassiveLogCollector() - : url_request_tracker_(&connect_job_tracker_), - socket_stream_tracker_(&connect_job_tracker_), + : url_request_tracker_(&connect_job_tracker_, &socket_tracker_), + socket_stream_tracker_(&connect_job_tracker_, &socket_tracker_), num_events_seen_(0) { } @@ -90,6 +108,9 @@ void PassiveLogCollector::OnAddEntry( 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; @@ -134,6 +155,7 @@ PassiveLogCollector::RequestTrackerBase::RequestTrackerBase( void PassiveLogCollector::RequestTrackerBase::OnAddEntry(const Entry& entry) { RequestInfo& info = live_requests_[entry.source.id]; + info.source_id = entry.source.id; // In case this is a new entry. Action result = DoAddEntry(entry, &info); switch (result) { @@ -165,6 +187,11 @@ PassiveLogCollector::RequestTrackerBase::GetLiveRequests() const { it != live_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); } std::sort(list.begin(), list.end(), OrderBySourceID); @@ -190,12 +217,16 @@ PassiveLogCollector::RequestTrackerBase::GetRecentlyDeceased() const { return list; } -const PassiveLogCollector::RequestInfo* -PassiveLogCollector::RequestTrackerBase::GetRequestInfoFromGraveyard( - int source_id) const { - // Scan through the graveyard to find an entry for |source_id|. +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].entries[0].source.id == source_id) { + if (graveyard_[i].source_id == source_id) { return &graveyard_[i]; } } @@ -203,7 +234,7 @@ PassiveLogCollector::RequestTrackerBase::GetRequestInfoFromGraveyard( } void PassiveLogCollector::RequestTrackerBase::RemoveFromLiveRequests( - int source_id) { + 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? @@ -260,7 +291,7 @@ void PassiveLogCollector::RequestTrackerBase::InsertIntoGraveyard( // ConnectJobTracker //---------------------------------------------------------------------------- -const size_t PassiveLogCollector::ConnectJobTracker::kMaxGraveyardSize = 3; +const size_t PassiveLogCollector::ConnectJobTracker::kMaxGraveyardSize = 15; PassiveLogCollector::ConnectJobTracker::ConnectJobTracker() : RequestTrackerBase(kMaxGraveyardSize) { @@ -269,9 +300,12 @@ PassiveLogCollector::ConnectJobTracker::ConnectJobTracker() PassiveLogCollector::RequestTrackerBase::Action PassiveLogCollector::ConnectJobTracker::DoAddEntry(const Entry& entry, RequestInfo* out_info) { - // Save the entry (possibly truncating). AddEntryToRequestInfo(entry, is_unbounded(), out_info); + if (entry.type == net::NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID) { + SetSubordinateSource(out_info, entry); + } + // If this is the end of the connect job, move the request to the graveyard. if (entry.type == net::NetLog::TYPE_SOCKET_POOL_CONNECT_JOB && entry.phase == net::NetLog::PHASE_END) { @@ -281,6 +315,118 @@ PassiveLogCollector::ConnectJobTracker::DoAddEntry(const Entry& entry, return ACTION_NONE; } +void PassiveLogCollector::ConnectJobTracker::AppendLogEntries( + RequestInfo* out_info, bool unbounded, uint32 connect_id) { + RequestInfo* connect_info = GetRequestInfo(connect_id); + if (!connect_info) { + net::NetLogStringParameter* text = new net::NetLogStringParameter( + 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, unbounded, out_info); + return; + } + + AppendToRequestInfo(*connect_info, unbounded, 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, unbounded, connect_info->subordinate_source.id); +} + +//---------------------------------------------------------------------------- +// SocketTracker +//---------------------------------------------------------------------------- + +const size_t PassiveLogCollector::SocketTracker::kMaxGraveyardSize = 15; + +PassiveLogCollector::SocketTracker::SocketTracker() + : RequestTrackerBase(kMaxGraveyardSize) { +} + +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.extra_parameters.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.extra_parameters.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, is_unbounded(), out_info); + break; + } + return ACTION_NONE; +} + +void PassiveLogCollector::SocketTracker::AppendLogEntries( + RequestInfo* out_info, bool unbounded, uint32 socket_id, bool clear) { + RequestInfo* socket_info = GetRequestInfo(socket_id); + if (!socket_info) { + net::NetLogStringParameter* text = new net::NetLogStringParameter( + 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, unbounded, out_info); + return; + } + + AppendToRequestInfo(*socket_info, unbounded, 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( + 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, unbounded, out_info); + } + 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(); +} + //---------------------------------------------------------------------------- // RequestTracker //---------------------------------------------------------------------------- @@ -289,24 +435,62 @@ const size_t PassiveLogCollector::RequestTracker::kMaxGraveyardSize = 25; const size_t PassiveLogCollector::RequestTracker::kMaxGraveyardURLSize = 1000; PassiveLogCollector::RequestTracker::RequestTracker( - ConnectJobTracker* connect_job_tracker) + ConnectJobTracker* connect_job_tracker, SocketTracker* socket_tracker) : RequestTrackerBase(kMaxGraveyardSize), - connect_job_tracker_(connect_job_tracker) { + connect_job_tracker_(connect_job_tracker), + socket_tracker_(socket_tracker) { } PassiveLogCollector::RequestTrackerBase::Action PassiveLogCollector::RequestTracker::DoAddEntry(const Entry& entry, RequestInfo* out_info) { - - if (entry.type == net::NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID) { - // If this was notification that a ConnectJob was bound to the request, - // copy all the logged data for that ConnectJob. - AddConnectJobInfo(entry, out_info); - } else { - // Otherwise just append this entry to the request info. - AddEntryToRequestInfo(entry, is_unbounded(), 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; + } } + AddEntryToRequestInfo(entry, is_unbounded(), out_info); + // If this was the start of a URLRequest/SocketStream, extract the URL. // Note: we look at the first *two* entries, since the outer REQUEST_ALIVE // doesn't actually contain any data. @@ -321,6 +505,7 @@ 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->url, "chrome://", false)) { // Avoid sending "chrome://" requests to the graveyard, since it just // adds to clutter. @@ -332,31 +517,24 @@ PassiveLogCollector::RequestTracker::DoAddEntry(const Entry& entry, return ACTION_NONE; } -void PassiveLogCollector::RequestTracker::AddConnectJobInfo( - const Entry& entry, - RequestInfo* live_entry) { - // We have just been notified of which ConnectJob the - // URLRequest/SocketStream was assigned. Lookup all the data we captured - // for the ConnectJob, and append it to the URLRequest/SocketStream's - // RequestInfo. - - int connect_job_id = static_cast<net::NetLogIntegerParameter*>( - entry.extra_parameters.get())->value(); - - const RequestInfo* connect_job_info = - connect_job_tracker_->GetRequestInfoFromGraveyard(connect_job_id); +void PassiveLogCollector::RequestTracker::IntegrateSubordinateSource( + RequestInfo* info, bool clear_entries) const { + if (!info->subordinate_source.is_valid()) + return; - if (connect_job_info) { - // Append the ConnectJob information we found. - AppendToRequestInfo(*connect_job_info, is_unbounded(), live_entry); - } else { - // If we couldn't find the information for the ConnectJob, append a - // generic message instead. - Entry e(entry); - e.type = net::NetLog::TYPE_TODO_STRING; - e.extra_parameters = new net::NetLogStringParameter( - StringPrintf("Used ConnectJob id=%d", connect_job_id)); - AddEntryToRequestInfo(e, is_unbounded(), live_entry); + uint32 subordinate_id = info->subordinate_source.id; + switch (info->subordinate_source.type) { + case net::NetLog::SOURCE_CONNECT_JOB: + connect_job_tracker_->AppendLogEntries( + info, connect_job_tracker_->is_unbounded(), subordinate_id); + break; + case net::NetLog::SOURCE_SOCKET: + socket_tracker_->AppendLogEntries(info, socket_tracker_->is_unbounded(), + subordinate_id, clear_entries); + break; + default: + NOTREACHED(); + break; } } diff --git a/chrome/browser/net/passive_log_collector.h b/chrome/browser/net/passive_log_collector.h index df9688a..55b7279 100644 --- a/chrome/browser/net/passive_log_collector.h +++ b/chrome/browser/net/passive_log_collector.h @@ -12,6 +12,7 @@ #include "base/time.h" #include "chrome/browser/net/chrome_net_log.h" #include "net/base/net_log.h" +#include "testing/gtest/include/gtest/gtest_prod.h" class PassiveLogCollector : public ChromeNetLog::Observer { public: @@ -19,7 +20,7 @@ class PassiveLogCollector : public ChromeNetLog::Observer { // including an "order" field that identifies when it was captured relative // to other events. struct Entry { - Entry(int order, + Entry(uint32 order, net::NetLog::EventType type, const base::TimeTicks& time, net::NetLog::Source source, @@ -29,7 +30,7 @@ class PassiveLogCollector : public ChromeNetLog::Observer { extra_parameters(extra_parameters) { } - int order; + uint32 order; net::NetLog::EventType type; base::TimeTicks time; net::NetLog::Source source; @@ -40,10 +41,29 @@ class PassiveLogCollector : public ChromeNetLog::Observer { typedef std::vector<Entry> EntryList; struct RequestInfo { - RequestInfo() : num_entries_truncated(0) {} - std::string url; + 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) {} + uint32 source_id; EntryList entries; size_t num_entries_truncated; + net::NetLog::Source subordinate_source; + + // Only used in RequestTracker. + std::string url; + + // 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. }; typedef std::vector<RequestInfo> RequestInfoList; @@ -61,15 +81,13 @@ class PassiveLogCollector : public ChromeNetLog::Observer { RequestInfoList GetRecentlyDeceased() const; void SetUnbounded(bool unbounded); - bool IsUnbounded() const { return is_unbounded_; } + bool is_unbounded() const { return is_unbounded_; } void Clear(); // Appends all the captured entries to |out|. The ordering is undefined. void AppendAllEntries(EntryList* out) const; - const RequestInfo* GetRequestInfoFromGraveyard(int id) const; - protected: enum Action { ACTION_NONE, @@ -81,12 +99,19 @@ class PassiveLogCollector : public ChromeNetLog::Observer { // to perform for this map entry on completion. virtual Action DoAddEntry(const Entry& entry, RequestInfo* out_info) = 0; - bool is_unbounded() const { return is_unbounded_; } + // 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 {} private: - typedef base::hash_map<int, RequestInfo> SourceIDToInfoMap; + typedef base::hash_map<uint32, RequestInfo> SourceIDToInfoMap; - void RemoveFromLiveRequests(int source_id); + void RemoveFromLiveRequests(uint32 source_id); void InsertIntoGraveyard(const RequestInfo& info); SourceIDToInfoMap live_requests_; @@ -105,29 +130,56 @@ class PassiveLogCollector : public ChromeNetLog::Observer { ConnectJobTracker(); + void AppendLogEntries(RequestInfo* out_info, bool unbounded, + uint32 connect_id); + protected: virtual Action DoAddEntry(const Entry& entry, RequestInfo* out_info); private: DISALLOW_COPY_AND_ASSIGN(ConnectJobTracker); }; + // Specialization of RequestTrackerBase for handling Sockets. + class SocketTracker : public RequestTrackerBase { + public: + static const size_t kMaxGraveyardSize; + + SocketTracker(); + + void AppendLogEntries(RequestInfo* out_info, bool unbounded, + 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); + }; + // Specialization of RequestTrackerBase for handling URLRequest/SocketStream. class RequestTracker : public RequestTrackerBase { public: static const size_t kMaxGraveyardSize; static const size_t kMaxGraveyardURLSize; - explicit RequestTracker(ConnectJobTracker* connect_job_tracker); + RequestTracker(ConnectJobTracker* connect_job_tracker, + SocketTracker* socket_tracker); + + void IntegrateSubordinateSource(RequestInfo* info, + bool clear_entries) const; protected: virtual Action DoAddEntry(const Entry& entry, RequestInfo* out_info); - private: - // Searches through |connect_job_tracker_| for information on the - // ConnectJob specified in |entry|, and appends it to |live_entry|. - void AddConnectJobInfo(const Entry& entry, RequestInfo* live_entry); + virtual void OnLiveRequest(RequestInfo* info) const { + IntegrateSubordinateSource(info, false); + } + private: ConnectJobTracker* connect_job_tracker_; + SocketTracker* socket_tracker_; DISALLOW_COPY_AND_ASSIGN(RequestTracker); }; @@ -178,14 +230,18 @@ class PassiveLogCollector : public ChromeNetLog::Observer { void GetAllCapturedEvents(EntryList* out) const; private: + FRIEND_TEST(PassiveLogCollectorTest, LostConnectJob); + FRIEND_TEST(PassiveLogCollectorTest, LostSocket); + ConnectJobTracker connect_job_tracker_; + SocketTracker socket_tracker_; RequestTracker url_request_tracker_; RequestTracker socket_stream_tracker_; InitProxyResolverTracker init_proxy_resolver_tracker_; // The count of how many events have flowed through this log. Used to set the // "order" field on captured events. - int num_events_seen_; + uint32 num_events_seen_; DISALLOW_COPY_AND_ASSIGN(PassiveLogCollector); }; diff --git a/chrome/browser/net/passive_log_collector_unittest.cc b/chrome/browser/net/passive_log_collector_unittest.cc index ef3d396..40dfc92e 100644 --- a/chrome/browser/net/passive_log_collector_unittest.cc +++ b/chrome/browser/net/passive_log_collector_unittest.cc @@ -13,17 +13,18 @@ namespace { typedef PassiveLogCollector::RequestTracker RequestTracker; typedef PassiveLogCollector::RequestInfoList RequestInfoList; +typedef net::NetLog NetLog; -const net::NetLog::SourceType kSourceType = net::NetLog::SOURCE_NONE; +const NetLog::SourceType kSourceType = NetLog::SOURCE_NONE; PassiveLogCollector::Entry MakeStartLogEntryWithURL(int source_id, const std::string& url) { return PassiveLogCollector::Entry( 0, - net::NetLog::TYPE_URL_REQUEST_START, + NetLog::TYPE_URL_REQUEST_START, base::TimeTicks(), - net::NetLog::Source(kSourceType, source_id), - net::NetLog::PHASE_BEGIN, + NetLog::Source(kSourceType, source_id), + NetLog::PHASE_BEGIN, new net::NetLogStringParameter(url)); } @@ -35,18 +36,36 @@ PassiveLogCollector::Entry MakeStartLogEntry(int source_id) { PassiveLogCollector::Entry MakeEndLogEntry(int source_id) { return PassiveLogCollector::Entry( 0, - net::NetLog::TYPE_REQUEST_ALIVE, + NetLog::TYPE_REQUEST_ALIVE, base::TimeTicks(), - net::NetLog::Source(kSourceType, source_id), - net::NetLog::PHASE_END, + NetLog::Source(kSourceType, source_id), + NetLog::PHASE_END, NULL); } +void AddStartURLRequestEntries(PassiveLogCollector* collector, uint32 id) { + collector->OnAddEntry(NetLog::TYPE_REQUEST_ALIVE, base::TimeTicks(), + NetLog::Source(NetLog::SOURCE_URL_REQUEST, id), + NetLog::PHASE_BEGIN, NULL); + collector->OnAddEntry(NetLog::TYPE_URL_REQUEST_START, base::TimeTicks(), + NetLog::Source(NetLog::SOURCE_URL_REQUEST, id), + NetLog::PHASE_BEGIN, new net::NetLogStringParameter( + StringPrintf("http://req%d", id))); +} + +void AddEndURLRequestEntries(PassiveLogCollector* collector, uint32 id) { + collector->OnAddEntry(NetLog::TYPE_REQUEST_ALIVE, base::TimeTicks(), + NetLog::Source(NetLog::SOURCE_URL_REQUEST, id), + NetLog::PHASE_END, NULL); +} + static const int kMaxNumLoadLogEntries = 1; +} // namespace + TEST(RequestTrackerTest, BasicBounded) { - RequestTracker tracker(NULL); - EXPECT_FALSE(tracker.IsUnbounded()); + RequestTracker tracker(NULL, NULL); + EXPECT_FALSE(tracker.is_unbounded()); EXPECT_EQ(0u, tracker.GetLiveRequests().size()); EXPECT_EQ(0u, tracker.GetRecentlyDeceased().size()); @@ -79,8 +98,8 @@ TEST(RequestTrackerTest, BasicBounded) { } TEST(RequestTrackerTest, GraveyardBounded) { - RequestTracker tracker(NULL); - EXPECT_FALSE(tracker.IsUnbounded()); + RequestTracker tracker(NULL, NULL); + EXPECT_FALSE(tracker.is_unbounded()); EXPECT_EQ(0u, tracker.GetLiveRequests().size()); EXPECT_EQ(0u, tracker.GetRecentlyDeceased().size()); @@ -104,14 +123,14 @@ TEST(RequestTrackerTest, GraveyardBounded) { } TEST(RequestTrackerTest, GraveyardUnbounded) { - RequestTracker tracker(NULL); - EXPECT_FALSE(tracker.IsUnbounded()); + RequestTracker tracker(NULL, NULL); + EXPECT_FALSE(tracker.is_unbounded()); EXPECT_EQ(0u, tracker.GetLiveRequests().size()); EXPECT_EQ(0u, tracker.GetRecentlyDeceased().size()); tracker.SetUnbounded(true); - EXPECT_TRUE(tracker.IsUnbounded()); + EXPECT_TRUE(tracker.is_unbounded()); // Add twice as many requests as would fit in the bounded graveyard. @@ -136,8 +155,8 @@ TEST(RequestTrackerTest, GraveyardUnbounded) { // Check that we exclude "chrome://" URLs from being saved into the recent // requests list (graveyard). TEST(RequestTrackerTest, GraveyardIsFiltered) { - RequestTracker tracker(NULL); - EXPECT_FALSE(tracker.IsUnbounded()); + RequestTracker tracker(NULL, NULL); + EXPECT_FALSE(tracker.is_unbounded()); // This will be excluded. std::string url1 = "chrome://dontcare/"; @@ -161,13 +180,13 @@ TEST(RequestTrackerTest, GraveyardIsFiltered) { // Convert an unbounded tracker back to being bounded. TEST(RequestTrackerTest, ConvertUnboundedToBounded) { - RequestTracker tracker(NULL); - EXPECT_FALSE(tracker.IsUnbounded()); + RequestTracker tracker(NULL, NULL); + EXPECT_FALSE(tracker.is_unbounded()); EXPECT_EQ(0u, tracker.GetLiveRequests().size()); EXPECT_EQ(0u, tracker.GetRecentlyDeceased().size()); tracker.SetUnbounded(true); - EXPECT_TRUE(tracker.IsUnbounded()); + EXPECT_TRUE(tracker.is_unbounded()); // Add twice as many requests as would fit in the bounded graveyard. @@ -193,4 +212,811 @@ TEST(RequestTrackerTest, ConvertUnboundedToBounded) { ASSERT_EQ(kMaxSize, tracker.GetRecentlyDeceased().size()); } -} // namespace +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(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(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(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(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(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(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(15)); + log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), + NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), + NetLog::PHASE_END, new net::NetLogIntegerParameter(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(15)); + log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), + NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), + NetLog::PHASE_END, new net::NetLogIntegerParameter(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(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(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(15)); + log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), + NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), + NetLog::PHASE_END, new net::NetLogIntegerParameter(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(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(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(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(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(15)); + log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), + NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), + NetLog::PHASE_END, new net::NetLogIntegerParameter(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(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(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(15)); + log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(), + NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20), + NetLog::PHASE_END, new net::NetLogIntegerParameter(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(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(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(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(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(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(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(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(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(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(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(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(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(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(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)", + requests[0].entries[4].extra_parameters->ToString()); + + log.OnAddEntry(NetLog::TYPE_SOCKET_BYTES_RECEIVED , base::TimeTicks(), + NetLog::Source(NetLog::SOURCE_SOCKET, 15), + NetLog::PHASE_END, new net::NetLogIntegerParameter(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)", + requests[0].entries[4].extra_parameters->ToString()); + + 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)", + requests[0].entries[4].extra_parameters->ToString()); + + 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(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(4)); + log.OnAddEntry(NetLog::TYPE_SOCKET_BYTES_RECEIVED , base::TimeTicks(), + NetLog::Source(NetLog::SOURCE_SOCKET, 15), + NetLog::PHASE_END, new net::NetLogIntegerParameter(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)", + requests[0].entries[4].extra_parameters->ToString()); + + 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()); +} diff --git a/chrome/browser/net/view_net_internals_job_factory.cc b/chrome/browser/net/view_net_internals_job_factory.cc index 176bf76..213ae5f 100644 --- a/chrome/browser/net/view_net_internals_job_factory.cc +++ b/chrome/browser/net/view_net_internals_job_factory.cc @@ -524,7 +524,7 @@ class URLRequestLiveSubSection : public SubSection { out->append("<ol>"); for (size_t i = 0; i < requests.size(); ++i) { - // Reverse the list order, so we dispay from most recent to oldest. + // Reverse the list order, so we display from most recent to oldest. size_t index = requests.size() - i - 1; OutputURLAndLoadLog(requests[index], out); } @@ -726,8 +726,8 @@ void ProcessQueryStringCommands(URLRequestContext* context, // logging, and clear some of the already logged data. void DrawControlsHeader(URLRequestContext* context, std::string* data) { bool is_full_logging_enabled = - GetURLRequestTracker(context)->IsUnbounded() && - GetSocketStreamTracker(context)->IsUnbounded(); + GetURLRequestTracker(context)->is_unbounded() && + GetSocketStreamTracker(context)->is_unbounded(); data->append("<div style='margin-bottom: 10px'>"); |