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 | |
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
47 files changed, 1539 insertions, 404 deletions
diff --git a/chrome/browser/dom_ui/net_internals_ui.cc b/chrome/browser/dom_ui/net_internals_ui.cc index 0567c8c..8a08cfb 100644 --- a/chrome/browser/dom_ui/net_internals_ui.cc +++ b/chrome/browser/dom_ui/net_internals_ui.cc @@ -441,6 +441,7 @@ void NetInternalsMessageHandler::IOThreadImpl::OnRendererReady( dict->SetInteger(L"INIT_PROXY_RESOLVER", net::NetLog::SOURCE_INIT_PROXY_RESOLVER); dict->SetInteger(L"CONNECT_JOB", net::NetLog::SOURCE_CONNECT_JOB); + dict->SetInteger(L"SOCKET", net::NetLog::SOURCE_SOCKET); CallJavascriptFunction(L"g_browser.receivedLogSourceTypeConstants", dict); } 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'>"); diff --git a/chrome/browser/sync/notifier/communicator/ssl_socket_adapter.cc b/chrome/browser/sync/notifier/communicator/ssl_socket_adapter.cc index 277e6fe..cd3e5f0 100644 --- a/chrome/browser/sync/notifier/communicator/ssl_socket_adapter.cc +++ b/chrome/browser/sync/notifier/communicator/ssl_socket_adapter.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -102,7 +102,7 @@ int SSLSocketAdapter::BeginSSL() { net::ClientSocketFactory::GetDefaultFactory()->CreateSSLClientSocket( transport_socket_, hostname_.c_str(), ssl_config)); - int result = ssl_socket_->Connect(&connected_callback_, NULL); + int result = ssl_socket_->Connect(&connected_callback_); if (result == net::ERR_IO_PENDING || result == net::OK) { return 0; @@ -238,8 +238,7 @@ TransportSocket::TransportSocket(talk_base::AsyncSocket* socket, socket_->SignalConnectEvent.connect(this, &TransportSocket::OnConnectEvent); } -int TransportSocket::Connect(net::CompletionCallback* callback, - const net::BoundNetLog& /* net_log */) { +int TransportSocket::Connect(net::CompletionCallback* callback) { connect_callback_ = callback; return socket_->Connect(addr_); } diff --git a/chrome/browser/sync/notifier/communicator/ssl_socket_adapter.h b/chrome/browser/sync/notifier/communicator/ssl_socket_adapter.h index 2e7d618..59cdb08 100644 --- a/chrome/browser/sync/notifier/communicator/ssl_socket_adapter.h +++ b/chrome/browser/sync/notifier/communicator/ssl_socket_adapter.h @@ -1,4 +1,4 @@ -// Copyright (c) 2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -9,15 +9,12 @@ #include "net/base/completion_callback.h" #include "net/base/io_buffer.h" #include "net/base/net_errors.h" +#include "net/base/net_log.h" #include "net/socket/client_socket.h" #include "net/socket/ssl_client_socket.h" #include "talk/base/asyncsocket.h" #include "talk/base/ssladapter.h" -namespace net { -class BoundNetLog; -} // namespace net - namespace notifier { class SSLSocketAdapter; @@ -37,12 +34,12 @@ class TransportSocket : public net::ClientSocket, public sigslot::has_slots<> { // net::ClientSocket implementation - virtual int Connect(net::CompletionCallback* callback, - const net::BoundNetLog& /* net_log */); + virtual int Connect(net::CompletionCallback* callback); virtual void Disconnect(); virtual bool IsConnected() const; virtual bool IsConnectedAndIdle() const; virtual int GetPeerAddress(net::AddressList* address) const; + virtual const net::BoundNetLog& NetLog() const { return net_log_; } // net::Socket implementation @@ -69,6 +66,8 @@ class TransportSocket : public net::ClientSocket, public sigslot::has_slots<> { scoped_refptr<net::IOBuffer> write_buffer_; int write_buffer_len_; + net::BoundNetLog net_log_; + talk_base::AsyncSocket *socket_; talk_base::SocketAddress addr_; diff --git a/net/base/net_log.cc b/net/base/net_log.cc index 1ebdfdb..c9ef380 100644 --- a/net/base/net_log.cc +++ b/net/base/net_log.cc @@ -86,6 +86,13 @@ void BoundNetLog::BeginEventWithString(NetLog::EventType event_type, BeginEventWithParameters(event_type, params); } +void BoundNetLog::BeginEventWithInteger(NetLog::EventType event_type, + int integer) const { + scoped_refptr<NetLog::EventParameters> params = + new NetLogIntegerParameter(integer); + BeginEventWithParameters(event_type, params); +} + void BoundNetLog::EndEvent(NetLog::EventType event_type) const { EndEventWithParameters(event_type, NULL); } @@ -153,7 +160,7 @@ void CapturingNetLog::AddEntry(EventType type, entries_.push_back(entry); } -int CapturingNetLog::NextID() { +uint32 CapturingNetLog::NextID() { return next_id_++; } diff --git a/net/base/net_log.h b/net/base/net_log.h index 3a85131..cb2b3a6 100644 --- a/net/base/net_log.h +++ b/net/base/net_log.h @@ -67,17 +67,21 @@ class NetLog { SOURCE_SOCKET_STREAM, SOURCE_INIT_PROXY_RESOLVER, SOURCE_CONNECT_JOB, + SOURCE_SOCKET, }; // Identifies the entity that generated this log. The |id| field should // uniquely identify the source, and is used by log observers to infer // message groupings. Can use NetLog::NextID() to create unique IDs. struct Source { - Source() : type(SOURCE_NONE), id(-1) {} - Source(SourceType type, int id) : type(type), id(id) {} + static const uint32 kInvalidId = 0; + + Source() : type(SOURCE_NONE), id(kInvalidId) {} + Source(SourceType type, uint32 id) : type(type), id(id) {} + bool is_valid() { return id != kInvalidId; } SourceType type; - int id; + uint32 id; }; // Base class for associating additional parameters with an event. Log @@ -115,7 +119,7 @@ class NetLog { EventParameters* extra_parameters) = 0; // Returns a unique ID which can be used as a source ID. - virtual int NextID() = 0; + virtual uint32 NextID() = 0; // Returns true if more complicated messages should be sent to the log. // TODO(eroman): This is a carry-over from refactoring; figure out @@ -141,7 +145,7 @@ class BoundNetLog { // TODO(eroman): This is a complete hack to allow passing in NULL in // place of a BoundNetLog. I added this while refactoring to simplify the // task of updating all the callers. - BoundNetLog(int) : net_log_(NULL) {} + BoundNetLog(uint32) : net_log_(NULL) {} BoundNetLog(const NetLog::Source& source, NetLog* net_log) : source_(source), net_log_(net_log) { @@ -167,6 +171,7 @@ class BoundNetLog { NetLog::EventParameters* params) const; void BeginEventWithString(NetLog::EventType event_type, const std::string& string) const; + void BeginEventWithInteger(NetLog::EventType event_type, int integer) const; void AddEventWithInteger(NetLog::EventType event_type, int integer) const; void EndEvent(NetLog::EventType event_type) const; void EndEventWithParameters(NetLog::EventType event_type, @@ -278,7 +283,7 @@ class CapturingNetLog : public NetLog { const Source& source, EventPhase phase, EventParameters* extra_parameters); - virtual int NextID(); + virtual uint32 NextID(); virtual bool HasListener() const { return true; } // Returns the list of all entries in the log. @@ -287,7 +292,7 @@ class CapturingNetLog : public NetLog { void Clear(); private: - int next_id_; + uint32 next_id_; size_t max_num_entries_; EntryList entries_; diff --git a/net/base/net_log_event_type_list.h b/net/base/net_log_event_type_list.h index 8d6e841..7e794e4 100644 --- a/net/base/net_log_event_type_list.h +++ b/net/base/net_log_event_type_list.h @@ -1,4 +1,4 @@ -// Copyright (c) 2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -90,12 +90,15 @@ EVENT_TYPE(PROXY_RESOLVER_V8_DNS_RESOLVE_EX) EVENT_TYPE(WAITING_FOR_SINGLE_PROXY_RESOLVER_THREAD) // ------------------------------------------------------------------------ -// ClientSocket::Connect +// ClientSocket // ------------------------------------------------------------------------ // The start/end of a TCP connect(). EVENT_TYPE(TCP_CONNECT) +// Marks the destruction of a TCP socket. +EVENT_TYPE(TCP_SOCKET_DONE) + // The start/end of a SOCKS connect(). EVENT_TYPE(SOCKS_CONNECT) @@ -105,6 +108,12 @@ EVENT_TYPE(SOCKS5_CONNECT) // The start/end of a SSL connect(). EVENT_TYPE(SSL_CONNECT) +// The specified number of bytes were sent on the socket. +EVENT_TYPE(SOCKET_BYTES_SENT) + +// The specified number of bytes were received on the socket. +EVENT_TYPE(SOCKET_BYTES_RECEIVED) + // ------------------------------------------------------------------------ // ClientSocketPoolBase::ConnectJob // ------------------------------------------------------------------------ @@ -134,10 +143,17 @@ EVENT_TYPE(SOCKET_BACKUP_CREATED) // A backup socket is created due to slow connect EVENT_TYPE(SOCKET_BACKUP_TIMER_EXTENDED) -// Identifies the NetLog::Source() for the ConnectJob that this socket ended -// up binding to. +// Identifies the NetLog::Source() for a ConnectJob. The begin event +// is sent to the request that triggered the ConnectJob, the end event +// is sent to the request that received the connected socket. Because of +// late binding, they may not be the same. Therefore the ID for the +// ConnectJob NetLog is sent in both events. EVENT_TYPE(SOCKET_POOL_CONNECT_JOB_ID) +// Identifies the NetLog::Source() for the Socket assigned to the pending +// request. +EVENT_TYPE(SOCKET_POOL_SOCKET_ID) + // ------------------------------------------------------------------------ // URLRequest // ------------------------------------------------------------------------ diff --git a/net/ftp/ftp_network_transaction.cc b/net/ftp/ftp_network_transaction.cc index 33f7dba..c939455 100644 --- a/net/ftp/ftp_network_transaction.cc +++ b/net/ftp/ftp_network_transaction.cc @@ -616,8 +616,9 @@ int FtpNetworkTransaction::DoCtrlResolveHostComplete(int result) { int FtpNetworkTransaction::DoCtrlConnect() { next_state_ = STATE_CTRL_CONNECT_COMPLETE; - ctrl_socket_.reset(socket_factory_->CreateTCPClientSocket(addresses_)); - return ctrl_socket_->Connect(&io_callback_, net_log_); + ctrl_socket_.reset(socket_factory_->CreateTCPClientSocket( + addresses_, net_log_.net_log())); + return ctrl_socket_->Connect(&io_callback_); } int FtpNetworkTransaction::DoCtrlConnectComplete(int result) { @@ -1227,8 +1228,9 @@ int FtpNetworkTransaction::DoDataConnect() { if (rv != OK) return Stop(rv); data_address.SetPort(data_connection_port_); - data_socket_.reset(socket_factory_->CreateTCPClientSocket(data_address)); - return data_socket_->Connect(&io_callback_, net_log_); + data_socket_.reset(socket_factory_->CreateTCPClientSocket( + data_address, net_log_.net_log())); + return data_socket_->Connect(&io_callback_); } int FtpNetworkTransaction::DoDataConnectComplete(int result) { diff --git a/net/http/http_network_transaction.cc b/net/http/http_network_transaction.cc index 39111f4..f3cd4d5 100644 --- a/net/http/http_network_transaction.cc +++ b/net/http/http_network_transaction.cc @@ -853,7 +853,7 @@ int HttpNetworkTransaction::DoSSLConnect() { s = session_->socket_factory()->CreateSSLClientSocket( s, request_->url.HostNoBrackets(), ssl_config_); connection_->set_socket(s); - return connection_->socket()->Connect(&io_callback_, net_log_); + return connection_->socket()->Connect(&io_callback_); } int HttpNetworkTransaction::DoSSLConnectComplete(int result) { diff --git a/net/socket/client_socket.h b/net/socket/client_socket.h index 3005708..2bc1adb 100644 --- a/net/socket/client_socket.h +++ b/net/socket/client_socket.h @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -28,8 +28,7 @@ class ClientSocket : public Socket { // // Connect may also be called again after a call to the Disconnect method. // - virtual int Connect(CompletionCallback* callback, - const BoundNetLog& net_log) = 0; + virtual int Connect(CompletionCallback* callback) = 0; // Called to disconnect a socket. Does nothing if the socket is already // disconnected. After calling Disconnect it is possible to call Connect @@ -51,6 +50,9 @@ class ClientSocket : public Socket { // Copies the peer address to |address| and returns a network error code. virtual int GetPeerAddress(AddressList* address) const = 0; + + // Gets the NetLog for this socket. + virtual const BoundNetLog& NetLog() const = 0; }; } // namespace net diff --git a/net/socket/client_socket_factory.cc b/net/socket/client_socket_factory.cc index 4f05575..24d9e39 100644 --- a/net/socket/client_socket_factory.cc +++ b/net/socket/client_socket_factory.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -40,8 +40,8 @@ SSLClientSocketFactory g_ssl_factory = DefaultSSLClientSocketFactory; class DefaultClientSocketFactory : public ClientSocketFactory { public: virtual ClientSocket* CreateTCPClientSocket( - const AddressList& addresses) { - return new TCPClientSocket(addresses); + const AddressList& addresses, NetLog* net_log) { + return new TCPClientSocket(addresses, net_log); } virtual SSLClientSocket* CreateSSLClientSocket( diff --git a/net/socket/client_socket_factory.h b/net/socket/client_socket_factory.h index 1c97cd6..b519b32 100644 --- a/net/socket/client_socket_factory.h +++ b/net/socket/client_socket_factory.h @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -11,6 +11,7 @@ namespace net { class AddressList; class ClientSocket; +class NetLog; class SSLClientSocket; struct SSLConfig; @@ -27,7 +28,7 @@ class ClientSocketFactory { virtual ~ClientSocketFactory() {} virtual ClientSocket* CreateTCPClientSocket( - const AddressList& addresses) = 0; + const AddressList& addresses, NetLog* net_log) = 0; virtual SSLClientSocket* CreateSSLClientSocket( ClientSocket* transport_socket, diff --git a/net/socket/client_socket_pool_base.cc b/net/socket/client_socket_pool_base.cc index 4b6cff0..af87eba 100644 --- a/net/socket/client_socket_pool_base.cc +++ b/net/socket/client_socket_pool_base.cc @@ -38,15 +38,16 @@ ConnectJob::ConnectJob(const std::string& group_name, : group_name_(group_name), timeout_duration_(timeout_duration), delegate_(delegate), - net_log_(net_log) { + net_log_(net_log), + idle_(true) { DCHECK(!group_name.empty()); DCHECK(delegate); } ConnectJob::~ConnectJob() { - if (delegate_) { + if (delegate_ && !idle_) { // If the delegate was not NULLed, then NotifyDelegateOfCompletion has - // not been called yet (hence we are cancelling). + // not been called yet. If we've started then we are cancelling. net_log_.AddEvent(NetLog::TYPE_CANCELLED); net_log_.EndEvent(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB); } @@ -58,6 +59,7 @@ int ConnectJob::Connect() { net_log_.BeginEventWithString(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB, group_name_); + idle_ = false; int rv = ConnectInternal(); @@ -231,20 +233,17 @@ int ClientSocketPoolBaseHelper::RequestSocketInternal( // We couldn't find a socket to reuse, so allocate and connect a new one. BoundNetLog job_net_log = BoundNetLog::Make( request->net_log().net_log(), NetLog::SOURCE_CONNECT_JOB); + request->net_log().BeginEventWithInteger( + NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID, job_net_log.source().id); scoped_ptr<ConnectJob> connect_job( connect_job_factory_->NewConnectJob(group_name, *request, this, job_net_log)); int rv = connect_job->Connect(); - - if (rv != ERR_IO_PENDING) { - request->net_log().AddEventWithInteger( - NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID, - job_net_log.source().id); - } - if (rv == OK) { + request->net_log().EndEventWithInteger( + NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID, job_net_log.source().id); HandOutSocket(connect_job->ReleaseSocket(), false /* not reused */, handle, base::TimeDelta(), &group, request->net_log()); } else if (rv == ERR_IO_PENDING) { @@ -263,8 +262,11 @@ int ClientSocketPoolBaseHelper::RequestSocketInternal( ConnectJob* job = connect_job.release(); group.jobs.insert(job); - } else if (group.IsEmpty()) { - group_map_.erase(group_name); + } else { + request->net_log().EndEventWithInteger( + NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID, job_net_log.source().id); + if (group.IsEmpty()) + group_map_.erase(group_name); } return rv; @@ -566,7 +568,7 @@ void ClientSocketPoolBaseHelper::OnConnectJobComplete( if (!group.pending_requests.empty()) { scoped_ptr<const Request> r(RemoveRequestFromQueue( group.pending_requests.begin(), &group.pending_requests)); - r->net_log().AddEventWithInteger(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID, + r->net_log().EndEventWithInteger(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID, job_log.source().id); r->net_log().EndEvent(NetLog::TYPE_SOCKET_POOL); HandOutSocket( @@ -582,7 +584,7 @@ void ClientSocketPoolBaseHelper::OnConnectJobComplete( if (!group.pending_requests.empty()) { scoped_ptr<const Request> r(RemoveRequestFromQueue( group.pending_requests.begin(), &group.pending_requests)); - r->net_log().AddEventWithInteger(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID, + r->net_log().EndEventWithInteger(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID, job_log.source().id); r->net_log().EndEvent(NetLog::TYPE_SOCKET_POOL); r->callback()->Run(result); @@ -678,6 +680,8 @@ void ClientSocketPoolBaseHelper::HandOutSocket( StringPrintf("Socket sat idle for %" PRId64 " milliseconds", idle_time.InMilliseconds())); } + net_log.AddEventWithInteger(NetLog::TYPE_SOCKET_POOL_SOCKET_ID, + socket->NetLog().source().id); handed_out_socket_count_++; group->active_socket_count++; diff --git a/net/socket/client_socket_pool_base.h b/net/socket/client_socket_pool_base.h index d1abd58..ce25463 100644 --- a/net/socket/client_socket_pool_base.h +++ b/net/socket/client_socket_pool_base.h @@ -109,6 +109,8 @@ class ConnectJob { Delegate* delegate_; scoped_ptr<ClientSocket> socket_; BoundNetLog net_log_; + // A ConnectJob is idle until Connect() has been called. + bool idle_; DISALLOW_COPY_AND_ASSIGN(ConnectJob); }; diff --git a/net/socket/client_socket_pool_base_unittest.cc b/net/socket/client_socket_pool_base_unittest.cc index a706df8..f9e555ca 100644 --- a/net/socket/client_socket_pool_base_unittest.cc +++ b/net/socket/client_socket_pool_base_unittest.cc @@ -50,7 +50,7 @@ class MockClientSocket : public ClientSocket { // ClientSocket methods: - virtual int Connect(CompletionCallback* callback, const BoundNetLog& net_log) { + virtual int Connect(CompletionCallback* callback) { connected_ = true; return OK; } @@ -63,8 +63,13 @@ class MockClientSocket : public ClientSocket { return ERR_UNEXPECTED; } + virtual const BoundNetLog& NetLog() const { + return net_log_; + } + private: bool connected_; + BoundNetLog net_log_; DISALLOW_COPY_AND_ASSIGN(MockClientSocket); }; @@ -75,7 +80,8 @@ class MockClientSocketFactory : public ClientSocketFactory { public: MockClientSocketFactory() : allocation_count_(0) {} - virtual ClientSocket* CreateTCPClientSocket(const AddressList& addresses) { + virtual ClientSocket* CreateTCPClientSocket(const AddressList& addresses, + NetLog* /* net_log */) { allocation_count_++; return NULL; } @@ -133,7 +139,7 @@ class TestConnectJob : public ConnectJob { virtual int ConnectInternal() { AddressList ignored; - client_socket_factory_->CreateTCPClientSocket(ignored); + client_socket_factory_->CreateTCPClientSocket(ignored, NULL); set_socket(new MockClientSocket()); switch (job_type_) { case kMockJob: @@ -196,7 +202,7 @@ class TestConnectJob : public ConnectJob { int result = ERR_CONNECTION_FAILED; if (succeed) { result = OK; - socket()->Connect(NULL, NULL); + socket()->Connect(NULL); } else { set_socket(NULL); } @@ -520,18 +526,22 @@ TEST_F(ClientSocketPoolBaseTest, BasicSynchronous) { EXPECT_TRUE(handle.socket()); handle.Reset(); - EXPECT_EQ(5u, log.entries().size()); + EXPECT_EQ(7u, log.entries().size()); EXPECT_TRUE(LogContainsBeginEvent( log.entries(), 0, NetLog::TYPE_SOCKET_POOL)); EXPECT_TRUE(LogContainsBeginEvent( - log.entries(), 1, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB)); - EXPECT_TRUE(LogContainsEndEvent( + log.entries(), 1, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID)); + EXPECT_TRUE(LogContainsBeginEvent( log.entries(), 2, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB)); + EXPECT_TRUE(LogContainsEndEvent( + log.entries(), 3, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB)); + EXPECT_TRUE(LogContainsEndEvent( + log.entries(), 4, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID)); EXPECT_TRUE(LogContainsEvent( - log.entries(), 3, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID, + log.entries(), 5, NetLog::TYPE_SOCKET_POOL_SOCKET_ID, NetLog::PHASE_NONE)); EXPECT_TRUE(LogContainsEndEvent( - log.entries(), 4, NetLog::TYPE_SOCKET_POOL)); + log.entries(), 6, NetLog::TYPE_SOCKET_POOL)); } TEST_F(ClientSocketPoolBaseTest, InitConnectionFailure) { @@ -545,13 +555,13 @@ TEST_F(ClientSocketPoolBaseTest, InitConnectionFailure) { InitHandle(req.handle(), "a", kDefaultPriority, &req, pool_, log.bound())); - EXPECT_EQ(5u, log.entries().size()); + EXPECT_EQ(6u, log.entries().size()); EXPECT_TRUE(LogContainsBeginEvent(log.entries(), 0, NetLog::TYPE_SOCKET_POOL)); EXPECT_TRUE(LogContainsBeginEvent( - log.entries(), 1, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB)); - EXPECT_TRUE(LogContainsEndEvent( log.entries(), 2, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB)); - EXPECT_TRUE(LogContainsEndEvent(log.entries(), 4, NetLog::TYPE_SOCKET_POOL)); + EXPECT_TRUE(LogContainsEndEvent( + log.entries(), 3, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB)); + EXPECT_TRUE(LogContainsEndEvent(log.entries(), 5, NetLog::TYPE_SOCKET_POOL)); } TEST_F(ClientSocketPoolBaseTest, TotalLimit) { @@ -1158,15 +1168,15 @@ TEST_F(ClientSocketPoolBaseTest, BasicAsynchronous) { EXPECT_TRUE(req.handle()->socket()); req.handle()->Reset(); - EXPECT_EQ(5u, log.entries().size()); + EXPECT_EQ(7u, log.entries().size()); EXPECT_TRUE(LogContainsBeginEvent( log.entries(), 0, NetLog::TYPE_SOCKET_POOL)); EXPECT_TRUE(LogContainsBeginEvent( - log.entries(), 1, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB)); - EXPECT_TRUE(LogContainsEndEvent( log.entries(), 2, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB)); EXPECT_TRUE(LogContainsEndEvent( - log.entries(), 4, NetLog::TYPE_SOCKET_POOL)); + log.entries(), 3, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB)); + EXPECT_TRUE(LogContainsEndEvent( + log.entries(), 5, NetLog::TYPE_SOCKET_POOL)); } TEST_F(ClientSocketPoolBaseTest, @@ -1182,15 +1192,15 @@ TEST_F(ClientSocketPoolBaseTest, EXPECT_EQ(LOAD_STATE_CONNECTING, pool_->GetLoadState("a", req.handle())); EXPECT_EQ(ERR_CONNECTION_FAILED, req.WaitForResult()); - EXPECT_EQ(5u, log.entries().size()); + EXPECT_EQ(6u, log.entries().size()); EXPECT_TRUE(LogContainsBeginEvent( log.entries(), 0, NetLog::TYPE_SOCKET_POOL)); EXPECT_TRUE(LogContainsBeginEvent( - log.entries(), 1, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB)); - EXPECT_TRUE(LogContainsEndEvent( log.entries(), 2, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB)); EXPECT_TRUE(LogContainsEndEvent( - log.entries(), 4, NetLog::TYPE_SOCKET_POOL)); + log.entries(), 3, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB)); + EXPECT_TRUE(LogContainsEndEvent( + log.entries(), 5, NetLog::TYPE_SOCKET_POOL)); } TEST_F(ClientSocketPoolBaseTest, TwoRequestsCancelOne) { diff --git a/net/socket/socket_test_util.cc b/net/socket/socket_test_util.cc index 18790be..9e74d88 100644 --- a/net/socket/socket_test_util.cc +++ b/net/socket/socket_test_util.cc @@ -18,9 +18,10 @@ namespace net { -MockClientSocket::MockClientSocket() +MockClientSocket::MockClientSocket(net::NetLog* net_log) : ALLOW_THIS_IN_INITIALIZER_LIST(method_factory_(this)), - connected_(false) { + connected_(false), + net_log_(NetLog::Source(), net_log) { } void MockClientSocket::GetSSLInfo(net::SSLInfo* ssl_info) { @@ -69,8 +70,10 @@ void MockClientSocket::RunCallback(net::CompletionCallback* callback, } MockTCPClientSocket::MockTCPClientSocket(const net::AddressList& addresses, + net::NetLog* net_log, net::SocketDataProvider* data) - : addresses_(addresses), + : MockClientSocket(net_log), + addresses_(addresses), data_(data), read_offset_(0), read_data_(false, net::ERR_UNEXPECTED), @@ -83,8 +86,7 @@ MockTCPClientSocket::MockTCPClientSocket(const net::AddressList& addresses, data_->Reset(); } -int MockTCPClientSocket::Connect(net::CompletionCallback* callback, - const BoundNetLog& net_log) { +int MockTCPClientSocket::Connect(net::CompletionCallback* callback) { if (connected_) return net::OK; connected_ = true; @@ -244,7 +246,8 @@ MockSSLClientSocket::MockSSLClientSocket( const std::string& hostname, const net::SSLConfig& ssl_config, net::SSLSocketDataProvider* data) - : transport_(transport_socket), + : MockClientSocket(transport_socket->NetLog().net_log()), + transport_(transport_socket), data_(data) { DCHECK(data_); } @@ -257,11 +260,10 @@ void MockSSLClientSocket::GetSSLInfo(net::SSLInfo* ssl_info) { ssl_info->Reset(); } -int MockSSLClientSocket::Connect(net::CompletionCallback* callback, - const BoundNetLog& net_log) { +int MockSSLClientSocket::Connect(net::CompletionCallback* callback) { ConnectCallback* connect_callback = new ConnectCallback( this, callback, data_->connect.result); - int rv = transport_->Connect(connect_callback, net_log); + int rv = transport_->Connect(connect_callback); if (rv == net::OK) { delete connect_callback; if (data_->connect.async) { @@ -412,10 +414,10 @@ MockSSLClientSocket* MockClientSocketFactory::GetMockSSLClientSocket( } ClientSocket* MockClientSocketFactory::CreateTCPClientSocket( - const AddressList& addresses) { + const AddressList& addresses, net::NetLog* net_log) { SocketDataProvider* data_provider = mock_data_.GetNext(); MockTCPClientSocket* socket = - new MockTCPClientSocket(addresses, data_provider); + new MockTCPClientSocket(addresses, net_log, data_provider); data_provider->set_socket(socket); tcp_client_sockets_.push_back(socket); return socket; diff --git a/net/socket/socket_test_util.h b/net/socket/socket_test_util.h index 91522ed..4358a72 100644 --- a/net/socket/socket_test_util.h +++ b/net/socket/socket_test_util.h @@ -1,4 +1,4 @@ -// Copyright (c) 2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -17,6 +17,7 @@ #include "net/base/address_list.h" #include "net/base/io_buffer.h" #include "net/base/net_errors.h" +#include "net/base/net_log.h" #include "net/base/ssl_config_service.h" #include "net/base/test_completion_callback.h" #include "net/socket/client_socket_factory.h" @@ -35,7 +36,6 @@ enum { ERR_TEST_PEER_CLOSE_AFTER_NEXT_MOCK_READ = -10000, }; -class BoundNetLog; class ClientSocket; class MockClientSocket; class SSLClientSocket; @@ -289,7 +289,8 @@ class MockClientSocketFactory : public ClientSocketFactory { MockSSLClientSocket* GetMockSSLClientSocket(size_t index) const; // ClientSocketFactory - virtual ClientSocket* CreateTCPClientSocket(const AddressList& addresses); + virtual ClientSocket* CreateTCPClientSocket(const AddressList& addresses, + NetLog* net_log); virtual SSLClientSocket* CreateSSLClientSocket( ClientSocket* transport_socket, const std::string& hostname, @@ -306,15 +307,15 @@ class MockClientSocketFactory : public ClientSocketFactory { class MockClientSocket : public net::SSLClientSocket { public: - MockClientSocket(); + explicit MockClientSocket(net::NetLog* net_log); // ClientSocket methods: - virtual int Connect(net::CompletionCallback* callback, - const BoundNetLog& net_log) = 0; + virtual int Connect(net::CompletionCallback* callback) = 0; virtual void Disconnect(); virtual bool IsConnected() const; virtual bool IsConnectedAndIdle() const; virtual int GetPeerAddress(AddressList* address) const; + virtual const BoundNetLog& NetLog() const { return net_log_;} // SSLClientSocket methods: virtual void GetSSLInfo(net::SSLInfo* ssl_info); @@ -345,16 +346,17 @@ class MockClientSocket : public net::SSLClientSocket { // True if Connect completed successfully and Disconnect hasn't been called. bool connected_; + + net::BoundNetLog net_log_; }; class MockTCPClientSocket : public MockClientSocket { public: - MockTCPClientSocket(const net::AddressList& addresses, + MockTCPClientSocket(const net::AddressList& addresses, net::NetLog* net_log, net::SocketDataProvider* socket); // ClientSocket methods: - virtual int Connect(net::CompletionCallback* callback, - const BoundNetLog& net_log); + virtual int Connect(net::CompletionCallback* callback); virtual void Disconnect(); virtual bool IsConnected() const; virtual bool IsConnectedAndIdle() const { return IsConnected(); } @@ -401,8 +403,7 @@ class MockSSLClientSocket : public MockClientSocket { virtual void GetSSLInfo(net::SSLInfo* ssl_info); - virtual int Connect(net::CompletionCallback* callback, - const BoundNetLog& net_log); + virtual int Connect(net::CompletionCallback* callback); virtual void Disconnect(); // Socket methods: diff --git a/net/socket/socks5_client_socket.cc b/net/socket/socks5_client_socket.cc index eef3403..c960b80 100644 --- a/net/socket/socks5_client_socket.cc +++ b/net/socket/socks5_client_socket.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -59,7 +59,8 @@ SOCKS5ClientSocket::SOCKS5ClientSocket( bytes_sent_(0), bytes_received_(0), read_header_size(kReadHeaderSize), - host_request_info_(req_info) { + host_request_info_(req_info), + net_log_(transport_socket->socket()->NetLog()) { } SOCKS5ClientSocket::SOCKS5ClientSocket( @@ -74,7 +75,8 @@ SOCKS5ClientSocket::SOCKS5ClientSocket( bytes_sent_(0), bytes_received_(0), read_header_size(kReadHeaderSize), - host_request_info_(req_info) { + host_request_info_(req_info), + net_log_(transport_socket->NetLog()) { transport_->set_socket(transport_socket); } @@ -82,8 +84,7 @@ SOCKS5ClientSocket::~SOCKS5ClientSocket() { Disconnect(); } -int SOCKS5ClientSocket::Connect(CompletionCallback* callback, - const BoundNetLog& net_log) { +int SOCKS5ClientSocket::Connect(CompletionCallback* callback) { DCHECK(transport_.get()); DCHECK(transport_->socket()); DCHECK(transport_->socket()->IsConnected()); @@ -94,8 +95,7 @@ int SOCKS5ClientSocket::Connect(CompletionCallback* callback, if (completed_handshake_) return OK; - net_log_ = net_log; - net_log.BeginEvent(NetLog::TYPE_SOCKS5_CONNECT); + net_log_.BeginEvent(NetLog::TYPE_SOCKS5_CONNECT); next_state_ = STATE_GREET_WRITE; buffer_.clear(); @@ -104,8 +104,7 @@ int SOCKS5ClientSocket::Connect(CompletionCallback* callback, if (rv == ERR_IO_PENDING) { user_callback_ = callback; } else { - net_log.EndEvent(NetLog::TYPE_SOCKS5_CONNECT); - net_log_ = BoundNetLog(); + net_log_.EndEvent(NetLog::TYPE_SOCKS5_CONNECT); } return rv; } @@ -118,7 +117,6 @@ void SOCKS5ClientSocket::Disconnect() { // These are the states initialized by Connect(). next_state_ = STATE_NONE; user_callback_ = NULL; - net_log_ = BoundNetLog(); } bool SOCKS5ClientSocket::IsConnected() const { @@ -175,7 +173,6 @@ void SOCKS5ClientSocket::OnIOComplete(int result) { int rv = DoLoop(result); if (rv != ERR_IO_PENDING) { net_log_.EndEvent(NetLog::TYPE_SOCKS5_CONNECT); - net_log_ = BoundNetLog(); DoCallback(rv); } } diff --git a/net/socket/socks5_client_socket.h b/net/socket/socks5_client_socket.h index 3e30c19..e6150f3 100644 --- a/net/socket/socks5_client_socket.h +++ b/net/socket/socks5_client_socket.h @@ -1,4 +1,4 @@ -// Copyright (c) 2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -50,10 +50,11 @@ class SOCKS5ClientSocket : public ClientSocket { // ClientSocket methods: // Does the SOCKS handshake and completes the protocol. - virtual int Connect(CompletionCallback* callback, const BoundNetLog& net_log); + virtual int Connect(CompletionCallback* callback); virtual void Disconnect(); virtual bool IsConnected() const; virtual bool IsConnectedAndIdle() const; + virtual const BoundNetLog& NetLog() const { return net_log_; } // Socket methods: virtual int Read(IOBuffer* buf, int buf_len, CompletionCallback* callback); diff --git a/net/socket/socks5_client_socket_unittest.cc b/net/socket/socks5_client_socket_unittest.cc index d9d1012..eb4109a 100644 --- a/net/socket/socks5_client_socket_unittest.cc +++ b/net/socket/socks5_client_socket_unittest.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -36,12 +36,14 @@ class SOCKS5ClientSocketTest : public PlatformTest { MockWrite writes[], size_t writes_count, const std::string& hostname, - int port); + int port, + NetLog* net_log); virtual void SetUp(); protected: const uint16 kNwPort; + CapturingNetLog net_log_; scoped_ptr<SOCKS5ClientSocket> user_sock_; AddressList address_list_; ClientSocket* tcp_sock_; @@ -54,7 +56,9 @@ class SOCKS5ClientSocketTest : public PlatformTest { }; SOCKS5ClientSocketTest::SOCKS5ClientSocketTest() - : kNwPort(htons(80)), host_resolver_(new MockHostResolver) { + : kNwPort(htons(80)), + net_log_(CapturingNetLog::kUnbounded), + host_resolver_(new MockHostResolver) { } // Set up platform before every test case @@ -73,13 +77,14 @@ SOCKS5ClientSocket* SOCKS5ClientSocketTest::BuildMockSocket( MockWrite writes[], size_t writes_count, const std::string& hostname, - int port) { + int port, + NetLog* net_log) { TestCompletionCallback callback; data_.reset(new StaticSocketDataProvider(reads, reads_count, writes, writes_count)); - tcp_sock_ = new MockTCPClientSocket(address_list_, data_.get()); + tcp_sock_ = new MockTCPClientSocket(address_list_, net_log, data_.get()); - int rv = tcp_sock_->Connect(&callback, NULL); + int rv = tcp_sock_->Connect(&callback); EXPECT_EQ(ERR_IO_PENDING, rv); rv = callback.WaitForResult(); EXPECT_EQ(OK, rv); @@ -116,23 +121,24 @@ TEST_F(SOCKS5ClientSocketTest, CompleteHandshake) { user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - "localhost", 80)); + "localhost", 80, &net_log_)); // At this state the TCP connection is completed but not the SOCKS handshake. EXPECT_TRUE(tcp_sock_->IsConnected()); EXPECT_FALSE(user_sock_->IsConnected()); - CapturingBoundNetLog log(CapturingNetLog::kUnbounded); - int rv = user_sock_->Connect(&callback_, log.bound()); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(ERR_IO_PENDING, rv); EXPECT_FALSE(user_sock_->IsConnected()); - EXPECT_TRUE(LogContainsBeginEvent(log.entries(), 0, NetLog::TYPE_SOCKS5_CONNECT)); + EXPECT_TRUE(LogContainsBeginEvent(net_log_.entries(), 0, + NetLog::TYPE_SOCKS5_CONNECT)); rv = callback_.WaitForResult(); EXPECT_EQ(OK, rv); EXPECT_TRUE(user_sock_->IsConnected()); - EXPECT_TRUE(LogContainsEndEvent(log.entries(), -1, NetLog::TYPE_SOCKS5_CONNECT)); + EXPECT_TRUE(LogContainsEndEvent(net_log_.entries(), -1, + NetLog::TYPE_SOCKS5_CONNECT)); scoped_refptr<IOBuffer> buffer = new IOBuffer(payload_write.size()); memcpy(buffer->data(), payload_write.data(), payload_write.size()); @@ -180,9 +186,9 @@ TEST_F(SOCKS5ClientSocketTest, ConnectAndDisconnectTwice) { user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - hostname, 80)); + hostname, 80, NULL)); - int rv = user_sock_->Connect(&callback_, NULL); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(OK, rv); EXPECT_TRUE(user_sock_->IsConnected()); @@ -202,12 +208,12 @@ TEST_F(SOCKS5ClientSocketTest, LargeHostNameFails) { MockRead data_reads[] = {MockRead()}; user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - large_host_name, 80)); + large_host_name, 80, NULL)); // Try to connect -- should fail (without having read/written anything to // the transport socket first) because the hostname is too long. TestCompletionCallback callback; - int rv = user_sock_->Connect(&callback, NULL); + int rv = user_sock_->Connect(&callback); EXPECT_EQ(ERR_SOCKS_CONNECTION_FAILED, rv); } @@ -238,15 +244,16 @@ TEST_F(SOCKS5ClientSocketTest, PartialReadWrites) { MockRead(true, kSOCKS5OkResponse, kSOCKS5OkResponseLength) }; user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - hostname, 80)); - CapturingBoundNetLog log(CapturingNetLog::kUnbounded); - int rv = user_sock_->Connect(&callback_, log.bound()); + hostname, 80, &net_log_)); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(ERR_IO_PENDING, rv); - EXPECT_TRUE(LogContainsBeginEvent(log.entries(), 0, NetLog::TYPE_SOCKS5_CONNECT)); + EXPECT_TRUE(LogContainsBeginEvent(net_log_.entries(), 0, + NetLog::TYPE_SOCKS5_CONNECT)); rv = callback_.WaitForResult(); EXPECT_EQ(OK, rv); EXPECT_TRUE(user_sock_->IsConnected()); - EXPECT_TRUE(LogContainsEndEvent(log.entries(), -1, NetLog::TYPE_SOCKS5_CONNECT)); + EXPECT_TRUE(LogContainsEndEvent(net_log_.entries(), -1, + NetLog::TYPE_SOCKS5_CONNECT)); } // Test for partial greet response read @@ -262,15 +269,16 @@ TEST_F(SOCKS5ClientSocketTest, PartialReadWrites) { MockRead(true, kSOCKS5OkResponse, kSOCKS5OkResponseLength) }; user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - hostname, 80)); - CapturingBoundNetLog log(CapturingNetLog::kUnbounded); - int rv = user_sock_->Connect(&callback_, log.bound()); + hostname, 80, &net_log_)); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(ERR_IO_PENDING, rv); - EXPECT_TRUE(LogContainsBeginEvent(log.entries(), 0, NetLog::TYPE_SOCKS5_CONNECT)); + EXPECT_TRUE(LogContainsBeginEvent(net_log_.entries(), 0, + NetLog::TYPE_SOCKS5_CONNECT)); rv = callback_.WaitForResult(); EXPECT_EQ(OK, rv); EXPECT_TRUE(user_sock_->IsConnected()); - EXPECT_TRUE(LogContainsEndEvent(log.entries(), -1, NetLog::TYPE_SOCKS5_CONNECT)); + EXPECT_TRUE(LogContainsEndEvent(net_log_.entries(), -1, + NetLog::TYPE_SOCKS5_CONNECT)); } // Test for partial handshake request write. @@ -287,15 +295,16 @@ TEST_F(SOCKS5ClientSocketTest, PartialReadWrites) { MockRead(true, kSOCKS5OkResponse, kSOCKS5OkResponseLength) }; user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - hostname, 80)); - CapturingBoundNetLog log(CapturingNetLog::kUnbounded); - int rv = user_sock_->Connect(&callback_, log.bound()); + hostname, 80, &net_log_)); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(ERR_IO_PENDING, rv); - EXPECT_TRUE(LogContainsBeginEvent(log.entries(), 0, NetLog::TYPE_SOCKS5_CONNECT)); + EXPECT_TRUE(LogContainsBeginEvent(net_log_.entries(), 0, + NetLog::TYPE_SOCKS5_CONNECT)); rv = callback_.WaitForResult(); EXPECT_EQ(OK, rv); EXPECT_TRUE(user_sock_->IsConnected()); - EXPECT_TRUE(LogContainsEndEvent(log.entries(), -1, NetLog::TYPE_SOCKS5_CONNECT)); + EXPECT_TRUE(LogContainsEndEvent(net_log_.entries(), -1, + NetLog::TYPE_SOCKS5_CONNECT)); } // Test for partial handshake response read @@ -314,15 +323,16 @@ TEST_F(SOCKS5ClientSocketTest, PartialReadWrites) { user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - hostname, 80)); - CapturingBoundNetLog log(CapturingNetLog::kUnbounded); - int rv = user_sock_->Connect(&callback_, log.bound()); + hostname, 80, &net_log_)); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(ERR_IO_PENDING, rv); - EXPECT_TRUE(LogContainsBeginEvent(log.entries(), 0, NetLog::TYPE_SOCKS5_CONNECT)); + EXPECT_TRUE(LogContainsBeginEvent(net_log_.entries(), 0, + NetLog::TYPE_SOCKS5_CONNECT)); rv = callback_.WaitForResult(); EXPECT_EQ(OK, rv); EXPECT_TRUE(user_sock_->IsConnected()); - EXPECT_TRUE(LogContainsEndEvent(log.entries(), -1, NetLog::TYPE_SOCKS5_CONNECT)); + EXPECT_TRUE(LogContainsEndEvent(net_log_.entries(), -1, + NetLog::TYPE_SOCKS5_CONNECT)); } } diff --git a/net/socket/socks_client_socket.cc b/net/socket/socks_client_socket.cc index e5049ff..ec51099 100644 --- a/net/socket/socks_client_socket.cc +++ b/net/socket/socks_client_socket.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -73,7 +73,8 @@ SOCKSClientSocket::SOCKSClientSocket(ClientSocketHandle* transport_socket, bytes_sent_(0), bytes_received_(0), host_resolver_(host_resolver), - host_request_info_(req_info) { + host_request_info_(req_info), + net_log_(transport_socket->socket()->NetLog()) { } SOCKSClientSocket::SOCKSClientSocket(ClientSocket* transport_socket, @@ -89,7 +90,8 @@ SOCKSClientSocket::SOCKSClientSocket(ClientSocket* transport_socket, bytes_sent_(0), bytes_received_(0), host_resolver_(host_resolver), - host_request_info_(req_info) { + host_request_info_(req_info), + net_log_(transport_socket->NetLog()) { transport_->set_socket(transport_socket); } @@ -97,8 +99,7 @@ SOCKSClientSocket::~SOCKSClientSocket() { Disconnect(); } -int SOCKSClientSocket::Connect(CompletionCallback* callback, - const BoundNetLog& net_log) { +int SOCKSClientSocket::Connect(CompletionCallback* callback) { DCHECK(transport_.get()); DCHECK(transport_->socket()); DCHECK(transport_->socket()->IsConnected()); @@ -110,16 +111,14 @@ int SOCKSClientSocket::Connect(CompletionCallback* callback, return OK; next_state_ = STATE_RESOLVE_HOST; - net_log_ = net_log; - net_log.BeginEvent(NetLog::TYPE_SOCKS_CONNECT); + net_log_.BeginEvent(NetLog::TYPE_SOCKS_CONNECT); int rv = DoLoop(OK); if (rv == ERR_IO_PENDING) { user_callback_ = callback; } else { - net_log.EndEvent(NetLog::TYPE_SOCKS_CONNECT); - net_log_ = BoundNetLog(); + net_log_.EndEvent(NetLog::TYPE_SOCKS_CONNECT); } return rv; } @@ -133,7 +132,6 @@ void SOCKSClientSocket::Disconnect() { // These are the states initialized by Connect(). next_state_ = STATE_NONE; user_callback_ = NULL; - net_log_ = BoundNetLog(); } bool SOCKSClientSocket::IsConnected() const { @@ -191,7 +189,6 @@ void SOCKSClientSocket::OnIOComplete(int result) { int rv = DoLoop(result); if (rv != ERR_IO_PENDING) { net_log_.EndEvent(NetLog::TYPE_SOCKS_CONNECT); - net_log_ = BoundNetLog(); DoCallback(rv); } } diff --git a/net/socket/socks_client_socket.h b/net/socket/socks_client_socket.h index 7aabf5d..f99bff0 100644 --- a/net/socket/socks_client_socket.h +++ b/net/socket/socks_client_socket.h @@ -1,4 +1,4 @@ -// Copyright (c) 2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -47,10 +47,11 @@ class SOCKSClientSocket : public ClientSocket { // ClientSocket methods: // Does the SOCKS handshake and completes the protocol. - virtual int Connect(CompletionCallback* callback, const BoundNetLog& net_log); + virtual int Connect(CompletionCallback* callback); virtual void Disconnect(); virtual bool IsConnected() const; virtual bool IsConnectedAndIdle() const; + virtual const BoundNetLog& NetLog() const { return net_log_; } // Socket methods: virtual int Read(IOBuffer* buf, int buf_len, CompletionCallback* callback); diff --git a/net/socket/socks_client_socket_pool.cc b/net/socket/socks_client_socket_pool.cc index 246cc20..b98f9fd 100644 --- a/net/socket/socks_client_socket_pool.cc +++ b/net/socket/socks_client_socket_pool.cc @@ -128,7 +128,7 @@ int SOCKSConnectJob::DoSOCKSConnect() { socks_params_.destination(), resolver_)); } - return socket_->Connect(&callback_, net_log()); + return socket_->Connect(&callback_); } int SOCKSConnectJob::DoSOCKSConnectComplete(int result) { diff --git a/net/socket/socks_client_socket_pool_unittest.cc b/net/socket/socks_client_socket_pool_unittest.cc index 4291f3c..e2e30a3 100644 --- a/net/socket/socks_client_socket_pool_unittest.cc +++ b/net/socket/socks_client_socket_pool_unittest.cc @@ -37,8 +37,8 @@ class MockTCPClientSocketPool : public TCPClientSocketPool { ALLOW_THIS_IN_INITIALIZER_LIST( connect_callback_(this, &MockConnectJob::OnConnect)) {} - int Connect(const BoundNetLog& net_log) { - int rv = socket_->Connect(&connect_callback_, net_log); + int Connect() { + int rv = socket_->Connect(&connect_callback_); if (rv == OK) { user_callback_ = NULL; OnConnect(OK); @@ -103,10 +103,10 @@ class MockTCPClientSocketPool : public TCPClientSocketPool { CompletionCallback* callback, const BoundNetLog& net_log) { ClientSocket* socket = client_socket_factory_->CreateTCPClientSocket( - AddressList()); + AddressList(), net_log.net_log()); MockConnectJob* job = new MockConnectJob(socket, handle, callback); job_list_.push_back(job); - return job->Connect(net_log); + return job->Connect(); } virtual void CancelRequest(const std::string& group_name, diff --git a/net/socket/socks_client_socket_unittest.cc b/net/socket/socks_client_socket_unittest.cc index ef11107..eb2ab6a 100644 --- a/net/socket/socks_client_socket_unittest.cc +++ b/net/socket/socks_client_socket_unittest.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -32,7 +32,8 @@ class SOCKSClientSocketTest : public PlatformTest { SOCKSClientSocket* BuildMockSocket(MockRead reads[], size_t reads_count, MockWrite writes[], size_t writes_count, HostResolver* host_resolver, - const std::string& hostname, int port); + const std::string& hostname, int port, + NetLog* net_log); virtual void SetUp(); protected: @@ -63,14 +64,15 @@ SOCKSClientSocket* SOCKSClientSocketTest::BuildMockSocket( size_t writes_count, HostResolver* host_resolver, const std::string& hostname, - int port) { + int port, + NetLog* net_log) { TestCompletionCallback callback; data_.reset(new StaticSocketDataProvider(reads, reads_count, writes, writes_count)); - tcp_sock_ = new MockTCPClientSocket(address_list_, data_.get()); + tcp_sock_ = new MockTCPClientSocket(address_list_, net_log, data_.get()); - int rv = tcp_sock_->Connect(&callback, NULL); + int rv = tcp_sock_->Connect(&callback); EXPECT_EQ(ERR_IO_PENDING, rv); rv = callback.WaitForResult(); EXPECT_EQ(OK, rv); @@ -129,17 +131,17 @@ TEST_F(SOCKSClientSocketTest, CompleteHandshake) { MockRead data_reads[] = { MockRead(true, kSOCKSOkReply, arraysize(kSOCKSOkReply)), MockRead(true, payload_read.data(), payload_read.size()) }; + CapturingNetLog log(CapturingNetLog::kUnbounded); user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - host_resolver_, "localhost", 80)); + host_resolver_, "localhost", 80, &log)); // At this state the TCP connection is completed but not the SOCKS handshake. EXPECT_TRUE(tcp_sock_->IsConnected()); EXPECT_FALSE(user_sock_->IsConnected()); - CapturingBoundNetLog log(CapturingNetLog::kUnbounded); - int rv = user_sock_->Connect(&callback_, log.bound()); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(ERR_IO_PENDING, rv); EXPECT_TRUE( LogContainsBeginEvent(log.entries(), 0, NetLog::TYPE_SOCKS_CONNECT)); @@ -197,13 +199,13 @@ TEST_F(SOCKSClientSocketTest, HandshakeFailures) { MockWrite(false, kSOCKSOkRequest, arraysize(kSOCKSOkRequest)) }; MockRead data_reads[] = { MockRead(false, tests[i].fail_reply, arraysize(tests[i].fail_reply)) }; + CapturingNetLog log(CapturingNetLog::kUnbounded); user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - host_resolver_, "localhost", 80)); - CapturingBoundNetLog log(CapturingNetLog::kUnbounded); + host_resolver_, "localhost", 80, &log)); - int rv = user_sock_->Connect(&callback_, log.bound()); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(ERR_IO_PENDING, rv); EXPECT_TRUE(LogContainsBeginEvent( log.entries(), 0, NetLog::TYPE_SOCKS_CONNECT)); @@ -227,14 +229,13 @@ TEST_F(SOCKSClientSocketTest, PartialServerReads) { MockRead data_reads[] = { MockRead(true, kSOCKSPartialReply1, arraysize(kSOCKSPartialReply1)), MockRead(true, kSOCKSPartialReply2, arraysize(kSOCKSPartialReply2)) }; + CapturingNetLog log(CapturingNetLog::kUnbounded); user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - host_resolver_, "localhost", 80)); - CapturingBoundNetLog log(CapturingNetLog::kUnbounded); + host_resolver_, "localhost", 80, &log)); - - int rv = user_sock_->Connect(&callback_, log.bound()); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(ERR_IO_PENDING, rv); EXPECT_TRUE(LogContainsBeginEvent( log.entries(), 0, NetLog::TYPE_SOCKS_CONNECT)); @@ -260,13 +261,13 @@ TEST_F(SOCKSClientSocketTest, PartialClientWrites) { arraysize(kSOCKSPartialRequest2)) }; MockRead data_reads[] = { MockRead(true, kSOCKSOkReply, arraysize(kSOCKSOkReply)) }; + CapturingNetLog log(CapturingNetLog::kUnbounded); user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - host_resolver_, "localhost", 80)); - CapturingBoundNetLog log(CapturingNetLog::kUnbounded); + host_resolver_, "localhost", 80, &log)); - int rv = user_sock_->Connect(&callback_, log.bound()); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(ERR_IO_PENDING, rv); EXPECT_TRUE(LogContainsBeginEvent( log.entries(), 0, NetLog::TYPE_SOCKS_CONNECT)); @@ -286,14 +287,13 @@ TEST_F(SOCKSClientSocketTest, FailedSocketRead) { MockRead(true, kSOCKSOkReply, arraysize(kSOCKSOkReply) - 2), // close connection unexpectedly MockRead(false, 0) }; + CapturingNetLog log(CapturingNetLog::kUnbounded); user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - host_resolver_, "localhost", 80)); - CapturingBoundNetLog log(CapturingNetLog::kUnbounded); - + host_resolver_, "localhost", 80, &log)); - int rv = user_sock_->Connect(&callback_, log.bound()); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(ERR_IO_PENDING, rv); EXPECT_TRUE(LogContainsBeginEvent( log.entries(), 0, NetLog::TYPE_SOCKS_CONNECT)); @@ -318,13 +318,13 @@ TEST_F(SOCKSClientSocketTest, SOCKS4AFailedDNS) { MockWrite(false, request.data(), request.size()) }; MockRead data_reads[] = { MockRead(false, kSOCKSOkReply, arraysize(kSOCKSOkReply)) }; + CapturingNetLog log(CapturingNetLog::kUnbounded); user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - host_resolver_, hostname, 80)); - CapturingBoundNetLog log(CapturingNetLog::kUnbounded); + host_resolver_, hostname, 80, &log)); - int rv = user_sock_->Connect(&callback_, log.bound()); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(ERR_IO_PENDING, rv); EXPECT_TRUE(LogContainsBeginEvent( log.entries(), 0, NetLog::TYPE_SOCKS_CONNECT)); @@ -351,13 +351,13 @@ TEST_F(SOCKSClientSocketTest, SOCKS4AIfDomainInIPv6) { MockWrite(false, request.data(), request.size()) }; MockRead data_reads[] = { MockRead(false, kSOCKSOkReply, arraysize(kSOCKSOkReply)) }; + CapturingNetLog log(CapturingNetLog::kUnbounded); user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - host_resolver_, hostname, 80)); - CapturingBoundNetLog log(CapturingNetLog::kUnbounded); + host_resolver_, hostname, 80, &log)); - int rv = user_sock_->Connect(&callback_, log.bound()); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(ERR_IO_PENDING, rv); EXPECT_TRUE(LogContainsBeginEvent( log.entries(), 0, NetLog::TYPE_SOCKS_CONNECT)); @@ -381,10 +381,10 @@ TEST_F(SOCKSClientSocketTest, DisconnectWhileHostResolveInProgress) { user_sock_.reset(BuildMockSocket(data_reads, arraysize(data_reads), data_writes, arraysize(data_writes), - hanging_resolver, "foo", 80)); + hanging_resolver, "foo", 80, NULL)); // Start connecting (will get stuck waiting for the host to resolve). - int rv = user_sock_->Connect(&callback_, NULL); + int rv = user_sock_->Connect(&callback_); EXPECT_EQ(ERR_IO_PENDING, rv); EXPECT_FALSE(user_sock_->IsConnected()); diff --git a/net/socket/ssl_client_socket_mac.cc b/net/socket/ssl_client_socket_mac.cc index 9a51395..4c36009 100644 --- a/net/socket/ssl_client_socket_mac.cc +++ b/net/socket/ssl_client_socket_mac.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2008-2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -518,34 +518,33 @@ SSLClientSocketMac::SSLClientSocketMac(ClientSocket* transport_socket, handshake_interrupted_(false), client_cert_requested_(false), ssl_context_(NULL), - pending_send_error_(OK) { + pending_send_error_(OK), + net_log_(transport_socket->NetLog()) { } SSLClientSocketMac::~SSLClientSocketMac() { Disconnect(); } -int SSLClientSocketMac::Connect(CompletionCallback* callback, - const BoundNetLog& net_log) { +int SSLClientSocketMac::Connect(CompletionCallback* callback) { DCHECK(transport_.get()); DCHECK(next_handshake_state_ == STATE_NONE); DCHECK(!user_connect_callback_); - net_log.BeginEvent(NetLog::TYPE_SSL_CONNECT); + net_log_.BeginEvent(NetLog::TYPE_SSL_CONNECT); int rv = InitializeSSLContext(); if (rv != OK) { - net_log.EndEvent(NetLog::TYPE_SSL_CONNECT); + net_log_.EndEvent(NetLog::TYPE_SSL_CONNECT); return rv; } next_handshake_state_ = STATE_HANDSHAKE_START; rv = DoHandshakeLoop(OK); if (rv == ERR_IO_PENDING) { - net_log_ = net_log; user_connect_callback_ = callback; } else { - net_log.EndEvent(NetLog::TYPE_SSL_CONNECT); + net_log_.EndEvent(NetLog::TYPE_SSL_CONNECT); } return rv; } @@ -868,7 +867,6 @@ void SSLClientSocketMac::OnHandshakeIOComplete(int result) { int rv = DoHandshakeLoop(result); if (rv != ERR_IO_PENDING) { net_log_.EndEvent(NetLog::TYPE_SSL_CONNECT); - net_log_ = BoundNetLog(); DoConnectCallback(rv); } } @@ -885,7 +883,6 @@ void SSLClientSocketMac::OnTransportReadComplete(int result) { int rv = DoHandshakeLoop(result); if (rv != ERR_IO_PENDING) { net_log_.EndEvent(NetLog::TYPE_SSL_CONNECT); - net_log_ = BoundNetLog(); DoConnectCallback(rv); } return; diff --git a/net/socket/ssl_client_socket_mac.h b/net/socket/ssl_client_socket_mac.h index 09a3bc3..bb25bda 100644 --- a/net/socket/ssl_client_socket_mac.h +++ b/net/socket/ssl_client_socket_mac.h @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -39,11 +39,12 @@ class SSLClientSocketMac : public SSLClientSocket { virtual NextProtoStatus GetNextProto(std::string* proto); // ClientSocket methods: - virtual int Connect(CompletionCallback* callback, const BoundNetLog& net_log); + virtual int Connect(CompletionCallback* callback); virtual void Disconnect(); virtual bool IsConnected() const; virtual bool IsConnectedAndIdle() const; virtual int GetPeerAddress(AddressList* address) const; + virtual const BoundNetLog& NetLog() const { return net_log_; } // Socket methods: virtual int Read(IOBuffer* buf, int buf_len, CompletionCallback* callback); diff --git a/net/socket/ssl_client_socket_nss.cc b/net/socket/ssl_client_socket_nss.cc index 7fdc424..a033c79 100644 --- a/net/socket/ssl_client_socket_nss.cc +++ b/net/socket/ssl_client_socket_nss.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -253,7 +253,8 @@ SSLClientSocketNSS::SSLClientSocketNSS(ClientSocket* transport_socket, completed_handshake_(false), next_handshake_state_(STATE_NONE), nss_fd_(NULL), - nss_bufs_(NULL) { + nss_bufs_(NULL), + net_log_(transport_socket->NetLog()) { EnterFunction(""); } @@ -281,8 +282,7 @@ int SSLClientSocketNSS::Init() { return OK; } -int SSLClientSocketNSS::Connect(CompletionCallback* callback, - const BoundNetLog& net_log) { +int SSLClientSocketNSS::Connect(CompletionCallback* callback) { EnterFunction(""); DCHECK(transport_.get()); DCHECK(next_handshake_state_ == STATE_NONE); @@ -292,17 +292,17 @@ int SSLClientSocketNSS::Connect(CompletionCallback* callback, DCHECK(!user_read_buf_); DCHECK(!user_write_buf_); - net_log.BeginEvent(NetLog::TYPE_SSL_CONNECT); + net_log_.BeginEvent(NetLog::TYPE_SSL_CONNECT); int rv = Init(); if (rv != OK) { - net_log.EndEvent(NetLog::TYPE_SSL_CONNECT); + net_log_.EndEvent(NetLog::TYPE_SSL_CONNECT); return rv; } rv = InitializeSSLOptions(); if (rv != OK) { - net_log.EndEvent(NetLog::TYPE_SSL_CONNECT); + net_log_.EndEvent(NetLog::TYPE_SSL_CONNECT); return rv; } @@ -310,9 +310,8 @@ int SSLClientSocketNSS::Connect(CompletionCallback* callback, rv = DoHandshakeLoop(OK); if (rv == ERR_IO_PENDING) { user_connect_callback_ = callback; - net_log_ = net_log; } else { - net_log.EndEvent(NetLog::TYPE_SSL_CONNECT); + net_log_.EndEvent(NetLog::TYPE_SSL_CONNECT); } LeaveFunction(""); @@ -819,7 +818,6 @@ void SSLClientSocketNSS::OnHandshakeIOComplete(int result) { int rv = DoHandshakeLoop(result); if (rv != ERR_IO_PENDING) { net_log_.EndEvent(net::NetLog::TYPE_SSL_CONNECT); - net_log_ = BoundNetLog(); DoConnectCallback(rv); } LeaveFunction(""); diff --git a/net/socket/ssl_client_socket_nss.h b/net/socket/ssl_client_socket_nss.h index 7cac7fb..3543df7 100644 --- a/net/socket/ssl_client_socket_nss.h +++ b/net/socket/ssl_client_socket_nss.h @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -45,11 +45,12 @@ class SSLClientSocketNSS : public SSLClientSocket { virtual NextProtoStatus GetNextProto(std::string* proto); // ClientSocket methods: - virtual int Connect(CompletionCallback* callback, const BoundNetLog& net_log); + virtual int Connect(CompletionCallback* callback); virtual void Disconnect(); virtual bool IsConnected() const; virtual bool IsConnectedAndIdle() const; virtual int GetPeerAddress(AddressList* address) const; + virtual const BoundNetLog& NetLog() const { return net_log_; } // Socket methods: virtual int Read(IOBuffer* buf, int buf_len, CompletionCallback* callback); diff --git a/net/socket/ssl_client_socket_unittest.cc b/net/socket/ssl_client_socket_unittest.cc index 4984fc7..86243af 100644 --- a/net/socket/ssl_client_socket_unittest.cc +++ b/net/socket/ssl_client_socket_unittest.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -68,8 +68,9 @@ TEST_F(SSLClientSocketTest, Connect) { int rv = resolver_->Resolve(info, &addr, NULL, NULL, NULL); EXPECT_EQ(net::OK, rv); - net::ClientSocket *transport = new net::TCPClientSocket(addr); - rv = transport->Connect(&callback, NULL); + net::CapturingNetLog log(net::CapturingNetLog::kUnbounded); + net::ClientSocket* transport = new net::TCPClientSocket(addr, &log); + rv = transport->Connect(&callback); if (rv == net::ERR_IO_PENDING) rv = callback.WaitForResult(); EXPECT_EQ(net::OK, rv); @@ -80,10 +81,9 @@ TEST_F(SSLClientSocketTest, Connect) { EXPECT_FALSE(sock->IsConnected()); - net::CapturingBoundNetLog log(net::CapturingNetLog::kUnbounded); - rv = sock->Connect(&callback, log.bound()); + rv = sock->Connect(&callback); EXPECT_TRUE(net::LogContainsBeginEvent( - log.entries(), 0, net::NetLog::TYPE_SSL_CONNECT)); + log.entries(), 2, net::NetLog::TYPE_SSL_CONNECT)); if (rv != net::OK) { ASSERT_EQ(net::ERR_IO_PENDING, rv); EXPECT_FALSE(sock->IsConnected()); @@ -112,8 +112,9 @@ TEST_F(SSLClientSocketTest, ConnectExpired) { int rv = resolver_->Resolve(info, &addr, NULL, NULL, NULL); EXPECT_EQ(net::OK, rv); - net::ClientSocket *transport = new net::TCPClientSocket(addr); - rv = transport->Connect(&callback, NULL); + net::CapturingNetLog log(net::CapturingNetLog::kUnbounded); + net::ClientSocket* transport = new net::TCPClientSocket(addr, &log); + rv = transport->Connect(&callback); if (rv == net::ERR_IO_PENDING) rv = callback.WaitForResult(); EXPECT_EQ(net::OK, rv); @@ -124,10 +125,9 @@ TEST_F(SSLClientSocketTest, ConnectExpired) { EXPECT_FALSE(sock->IsConnected()); - net::CapturingBoundNetLog log(net::CapturingNetLog::kUnbounded); - rv = sock->Connect(&callback, log.bound()); + rv = sock->Connect(&callback); EXPECT_TRUE(net::LogContainsBeginEvent( - log.entries(), 0, net::NetLog::TYPE_SSL_CONNECT)); + log.entries(), 2, net::NetLog::TYPE_SSL_CONNECT)); if (rv != net::OK) { ASSERT_EQ(net::ERR_IO_PENDING, rv); EXPECT_FALSE(sock->IsConnected()); @@ -157,8 +157,9 @@ TEST_F(SSLClientSocketTest, ConnectMismatched) { int rv = resolver_->Resolve(info, &addr, NULL, NULL, NULL); EXPECT_EQ(net::OK, rv); - net::ClientSocket *transport = new net::TCPClientSocket(addr); - rv = transport->Connect(&callback, NULL); + net::CapturingNetLog log(net::CapturingNetLog::kUnbounded); + net::ClientSocket* transport = new net::TCPClientSocket(addr, &log); + rv = transport->Connect(&callback); if (rv == net::ERR_IO_PENDING) rv = callback.WaitForResult(); EXPECT_EQ(net::OK, rv); @@ -169,10 +170,9 @@ TEST_F(SSLClientSocketTest, ConnectMismatched) { EXPECT_FALSE(sock->IsConnected()); - net::CapturingBoundNetLog log(net::CapturingNetLog::kUnbounded); - rv = sock->Connect(&callback, log.bound()); + rv = sock->Connect(&callback); EXPECT_TRUE(net::LogContainsBeginEvent( - log.entries(), 0, net::NetLog::TYPE_SSL_CONNECT)); + log.entries(), 2, net::NetLog::TYPE_SSL_CONNECT)); if (rv != net::ERR_CERT_COMMON_NAME_INVALID) { ASSERT_EQ(net::ERR_IO_PENDING, rv); EXPECT_FALSE(sock->IsConnected()); @@ -209,8 +209,8 @@ TEST_F(SSLClientSocketTest, Read) { rv = callback.WaitForResult(); EXPECT_EQ(net::OK, rv); - net::ClientSocket *transport = new net::TCPClientSocket(addr); - rv = transport->Connect(&callback, NULL); + net::ClientSocket* transport = new net::TCPClientSocket(addr, NULL); + rv = transport->Connect(&callback); if (rv == net::ERR_IO_PENDING) rv = callback.WaitForResult(); EXPECT_EQ(net::OK, rv); @@ -220,7 +220,7 @@ TEST_F(SSLClientSocketTest, Read) { server_.kHostName, kDefaultSSLConfig)); - rv = sock->Connect(&callback, NULL); + rv = sock->Connect(&callback); if (rv != net::OK) { ASSERT_EQ(net::ERR_IO_PENDING, rv); @@ -271,8 +271,8 @@ TEST_F(SSLClientSocketTest, Read_FullDuplex) { rv = callback.WaitForResult(); EXPECT_EQ(net::OK, rv); - net::ClientSocket *transport = new net::TCPClientSocket(addr); - rv = transport->Connect(&callback, NULL); + net::ClientSocket* transport = new net::TCPClientSocket(addr, NULL); + rv = transport->Connect(&callback); if (rv == net::ERR_IO_PENDING) rv = callback.WaitForResult(); EXPECT_EQ(net::OK, rv); @@ -282,7 +282,7 @@ TEST_F(SSLClientSocketTest, Read_FullDuplex) { server_.kHostName, kDefaultSSLConfig)); - rv = sock->Connect(&callback, NULL); + rv = sock->Connect(&callback); if (rv != net::OK) { ASSERT_EQ(net::ERR_IO_PENDING, rv); @@ -330,8 +330,8 @@ TEST_F(SSLClientSocketTest, Read_SmallChunks) { int rv = resolver_->Resolve(info, &addr, NULL, NULL, NULL); EXPECT_EQ(net::OK, rv); - net::ClientSocket *transport = new net::TCPClientSocket(addr); - rv = transport->Connect(&callback, NULL); + net::ClientSocket* transport = new net::TCPClientSocket(addr, NULL); + rv = transport->Connect(&callback); if (rv == net::ERR_IO_PENDING) rv = callback.WaitForResult(); EXPECT_EQ(net::OK, rv); @@ -340,7 +340,7 @@ TEST_F(SSLClientSocketTest, Read_SmallChunks) { socket_factory_->CreateSSLClientSocket(transport, server_.kHostName, kDefaultSSLConfig)); - rv = sock->Connect(&callback, NULL); + rv = sock->Connect(&callback); if (rv != net::OK) { ASSERT_EQ(net::ERR_IO_PENDING, rv); @@ -384,8 +384,8 @@ TEST_F(SSLClientSocketTest, Read_Interrupted) { int rv = resolver_->Resolve(info, &addr, NULL, NULL, NULL); EXPECT_EQ(net::OK, rv); - net::ClientSocket *transport = new net::TCPClientSocket(addr); - rv = transport->Connect(&callback, NULL); + net::ClientSocket* transport = new net::TCPClientSocket(addr, NULL); + rv = transport->Connect(&callback); if (rv == net::ERR_IO_PENDING) rv = callback.WaitForResult(); EXPECT_EQ(net::OK, rv); @@ -394,7 +394,7 @@ TEST_F(SSLClientSocketTest, Read_Interrupted) { socket_factory_->CreateSSLClientSocket(transport, server_.kHostName, kDefaultSSLConfig)); - rv = sock->Connect(&callback, NULL); + rv = sock->Connect(&callback); if (rv != net::OK) { ASSERT_EQ(net::ERR_IO_PENDING, rv); diff --git a/net/socket/ssl_client_socket_win.cc b/net/socket/ssl_client_socket_win.cc index 6a4ed8f..1502a65 100644 --- a/net/socket/ssl_client_socket_win.cc +++ b/net/socket/ssl_client_socket_win.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -322,7 +322,8 @@ SSLClientSocketWin::SSLClientSocketWin(ClientSocket* transport_socket, writing_first_token_(false), ignore_ok_result_(false), renegotiating_(false), - need_more_data_(false) { + need_more_data_(false), + net_log_(transport_socket->NetLog()) { memset(&stream_sizes_, 0, sizeof(stream_sizes_)); memset(in_buffers_, 0, sizeof(in_buffers_)); memset(&send_buffer_, 0, sizeof(send_buffer_)); @@ -430,17 +431,16 @@ SSLClientSocketWin::GetNextProto(std::string* proto) { return kNextProtoUnsupported; } -int SSLClientSocketWin::Connect(CompletionCallback* callback, - const BoundNetLog& net_log) { +int SSLClientSocketWin::Connect(CompletionCallback* callback) { DCHECK(transport_.get()); DCHECK(next_state_ == STATE_NONE); DCHECK(!user_connect_callback_); - net_log.BeginEvent(NetLog::TYPE_SSL_CONNECT); + net_log_.BeginEvent(NetLog::TYPE_SSL_CONNECT); int rv = InitializeSSLContext(); if (rv != OK) { - net_log.EndEvent(NetLog::TYPE_SSL_CONNECT); + net_log_.EndEvent(NetLog::TYPE_SSL_CONNECT); return rv; } @@ -449,9 +449,8 @@ int SSLClientSocketWin::Connect(CompletionCallback* callback, rv = DoLoop(OK); if (rv == ERR_IO_PENDING) { user_connect_callback_ = callback; - net_log_ = net_log; } else { - net_log.EndEvent(NetLog::TYPE_SSL_CONNECT); + net_log_.EndEvent(NetLog::TYPE_SSL_CONNECT); } return rv; } @@ -656,7 +655,6 @@ void SSLClientSocketWin::OnHandshakeIOComplete(int result) { return; } net_log_.EndEvent(NetLog::TYPE_SSL_CONNECT); - net_log_ = BoundNetLog(); CompletionCallback* c = user_connect_callback_; user_connect_callback_ = NULL; c->Run(rv); diff --git a/net/socket/ssl_client_socket_win.h b/net/socket/ssl_client_socket_win.h index 40bc3c1..3a273fe0 100644 --- a/net/socket/ssl_client_socket_win.h +++ b/net/socket/ssl_client_socket_win.h @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -43,11 +43,12 @@ class SSLClientSocketWin : public SSLClientSocket { virtual NextProtoStatus GetNextProto(std::string* proto); // ClientSocket methods: - virtual int Connect(CompletionCallback* callback, const BoundNetLog& net_log); + virtual int Connect(CompletionCallback* callback); virtual void Disconnect(); virtual bool IsConnected() const; virtual bool IsConnectedAndIdle() const; virtual int GetPeerAddress(AddressList* address) const; + virtual const BoundNetLog& NetLog() const { return net_log_; } // Socket methods: virtual int Read(IOBuffer* buf, int buf_len, CompletionCallback* callback); diff --git a/net/socket/tcp_client_socket_libevent.cc b/net/socket/tcp_client_socket_libevent.cc index db00c55..b64523d 100644 --- a/net/socket/tcp_client_socket_libevent.cc +++ b/net/socket/tcp_client_socket_libevent.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -122,7 +122,8 @@ bool ShouldTryNextAddress(int os_error) { //----------------------------------------------------------------------------- -TCPClientSocketLibevent::TCPClientSocketLibevent(const AddressList& addresses) +TCPClientSocketLibevent::TCPClientSocketLibevent(const AddressList& addresses, + net::NetLog* net_log) : socket_(kInvalidSocket), addresses_(addresses), current_ai_(addresses_.head()), @@ -130,25 +131,25 @@ TCPClientSocketLibevent::TCPClientSocketLibevent(const AddressList& addresses) read_watcher_(this), write_watcher_(this), read_callback_(NULL), - write_callback_(NULL) { + write_callback_(NULL), + net_log_(BoundNetLog::Make(net_log, NetLog::SOURCE_SOCKET)) { } TCPClientSocketLibevent::~TCPClientSocketLibevent() { Disconnect(); + net_log_.AddEvent(NetLog::TYPE_TCP_SOCKET_DONE); } -int TCPClientSocketLibevent::Connect(CompletionCallback* callback, - const BoundNetLog& net_log) { +int TCPClientSocketLibevent::Connect(CompletionCallback* callback) { // If already connected, then just return OK. if (socket_ != kInvalidSocket) return OK; DCHECK(!waiting_connect_); - DCHECK(!net_log_.net_log()); TRACE_EVENT_BEGIN("socket.connect", this, ""); - net_log.BeginEvent(NetLog::TYPE_TCP_CONNECT); + net_log_.BeginEvent(NetLog::TYPE_TCP_CONNECT); int rv = DoConnect(); @@ -156,12 +157,11 @@ int TCPClientSocketLibevent::Connect(CompletionCallback* callback, // Synchronous operation not supported. DCHECK(callback); - net_log_ = net_log; waiting_connect_ = true; write_callback_ = callback; } else { TRACE_EVENT_END("socket.connect", this, ""); - net_log.EndEvent(NetLog::TYPE_TCP_CONNECT); + net_log_.EndEvent(NetLog::TYPE_TCP_CONNECT); } return rv; @@ -277,6 +277,7 @@ int TCPClientSocketLibevent::Read(IOBuffer* buf, int nread = HANDLE_EINTR(read(socket_, buf->data(), buf_len)); if (nread >= 0) { TRACE_EVENT_END("socket.read", this, StringPrintf("%d bytes", nread)); + net_log_.AddEventWithInteger(NetLog::TYPE_SOCKET_BYTES_RECEIVED, nread); return nread; } if (errno != EAGAIN && errno != EWOULDBLOCK) { @@ -311,6 +312,7 @@ int TCPClientSocketLibevent::Write(IOBuffer* buf, int nwrite = HANDLE_EINTR(write(socket_, buf->data(), buf_len)); if (nwrite >= 0) { TRACE_EVENT_END("socket.write", this, StringPrintf("%d bytes", nwrite)); + net_log_.AddEventWithInteger(NetLog::TYPE_SOCKET_BYTES_SENT, nwrite); return nwrite; } if (errno != EAGAIN && errno != EWOULDBLOCK) @@ -403,11 +405,9 @@ void TCPClientSocketLibevent::DidCompleteConnect() { const addrinfo* next = current_ai_->ai_next; Disconnect(); current_ai_ = next; - BoundNetLog net_log = net_log_; - net_log_ = BoundNetLog(); TRACE_EVENT_END("socket.connect", this, ""); - net_log.EndEvent(NetLog::TYPE_TCP_CONNECT); - result = Connect(write_callback_, net_log); + net_log_.EndEvent(NetLog::TYPE_TCP_CONNECT); + result = Connect(write_callback_); } else { result = MapConnectError(os_error); bool ok = write_socket_watcher_.StopWatchingFileDescriptor(); @@ -415,7 +415,6 @@ void TCPClientSocketLibevent::DidCompleteConnect() { waiting_connect_ = false; TRACE_EVENT_END("socket.connect", this, ""); net_log_.EndEvent(NetLog::TYPE_TCP_CONNECT); - net_log_ = BoundNetLog(); } if (result != ERR_IO_PENDING) { @@ -433,6 +432,7 @@ void TCPClientSocketLibevent::DidCompleteRead() { TRACE_EVENT_END("socket.read", this, StringPrintf("%d bytes", bytes_transferred)); result = bytes_transferred; + net_log_.AddEventWithInteger(NetLog::TYPE_SOCKET_BYTES_RECEIVED, result); } else { result = MapPosixError(errno); } @@ -456,6 +456,7 @@ void TCPClientSocketLibevent::DidCompleteWrite() { result = bytes_transferred; TRACE_EVENT_END("socket.write", this, StringPrintf("%d bytes", bytes_transferred)); + net_log_.AddEventWithInteger(NetLog::TYPE_SOCKET_BYTES_SENT, result); } else { result = MapPosixError(errno); } diff --git a/net/socket/tcp_client_socket_libevent.h b/net/socket/tcp_client_socket_libevent.h index 211149a..699ddc7 100644 --- a/net/socket/tcp_client_socket_libevent.h +++ b/net/socket/tcp_client_socket_libevent.h @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -25,16 +25,18 @@ class TCPClientSocketLibevent : public ClientSocket { // The IP address(es) and port number to connect to. The TCP socket will try // each IP address in the list until it succeeds in establishing a // connection. - explicit TCPClientSocketLibevent(const AddressList& addresses); + explicit TCPClientSocketLibevent(const AddressList& addresses, + net::NetLog* net_log); virtual ~TCPClientSocketLibevent(); // ClientSocket methods: - virtual int Connect(CompletionCallback* callback, const BoundNetLog& net_log); + virtual int Connect(CompletionCallback* callback); virtual void Disconnect(); virtual bool IsConnected() const; virtual bool IsConnectedAndIdle() const; virtual int GetPeerAddress(AddressList* address) const; + virtual const BoundNetLog& NetLog() const { return net_log_; } // Socket methods: // Multiple outstanding requests are not supported. diff --git a/net/socket/tcp_client_socket_pool.cc b/net/socket/tcp_client_socket_pool.cc index a833e01..5cf1fa1 100644 --- a/net/socket/tcp_client_socket_pool.cc +++ b/net/socket/tcp_client_socket_pool.cc @@ -124,9 +124,10 @@ int TCPConnectJob::DoResolveHostComplete(int result) { int TCPConnectJob::DoTCPConnect() { next_state_ = kStateTCPConnectComplete; - set_socket(client_socket_factory_->CreateTCPClientSocket(addresses_)); + set_socket(client_socket_factory_->CreateTCPClientSocket( + addresses_, net_log().net_log())); connect_start_time_ = base::TimeTicks::Now(); - return socket()->Connect(&callback_, net_log()); + return socket()->Connect(&callback_); } int TCPConnectJob::DoTCPConnectComplete(int result) { diff --git a/net/socket/tcp_client_socket_pool_unittest.cc b/net/socket/tcp_client_socket_pool_unittest.cc index e7c8a9f..aed9052 100644 --- a/net/socket/tcp_client_socket_pool_unittest.cc +++ b/net/socket/tcp_client_socket_pool_unittest.cc @@ -30,7 +30,7 @@ class MockClientSocket : public ClientSocket { MockClientSocket() : connected_(false) {} // ClientSocket methods: - virtual int Connect(CompletionCallback* callback, const BoundNetLog& /* net_log */) { + virtual int Connect(CompletionCallback* callback) { connected_ = true; return OK; } @@ -46,6 +46,9 @@ class MockClientSocket : public ClientSocket { virtual int GetPeerAddress(AddressList* address) const { return ERR_UNEXPECTED; } + virtual const BoundNetLog& NetLog() const { + return net_log_; + } // Socket methods: virtual int Read(IOBuffer* buf, int buf_len, @@ -61,6 +64,7 @@ class MockClientSocket : public ClientSocket { private: bool connected_; + BoundNetLog net_log_; }; class MockFailingClientSocket : public ClientSocket { @@ -68,7 +72,7 @@ class MockFailingClientSocket : public ClientSocket { MockFailingClientSocket() {} // ClientSocket methods: - virtual int Connect(CompletionCallback* callback, const BoundNetLog& /* net_log */) { + virtual int Connect(CompletionCallback* callback) { return ERR_CONNECTION_FAILED; } @@ -83,6 +87,9 @@ class MockFailingClientSocket : public ClientSocket { virtual int GetPeerAddress(AddressList* address) const { return ERR_UNEXPECTED; } + virtual const BoundNetLog& NetLog() const { + return net_log_; + } // Socket methods: virtual int Read(IOBuffer* buf, int buf_len, @@ -96,6 +103,9 @@ class MockFailingClientSocket : public ClientSocket { } virtual bool SetReceiveBufferSize(int32 size) { return true; } virtual bool SetSendBufferSize(int32 size) { return true; } + + private: + BoundNetLog net_log_; }; class MockPendingClientSocket : public ClientSocket { @@ -112,7 +122,7 @@ class MockPendingClientSocket : public ClientSocket { is_connected_(false) {} // ClientSocket methods: - virtual int Connect(CompletionCallback* callback, const BoundNetLog& /* net_log */) { + virtual int Connect(CompletionCallback* callback) { MessageLoop::current()->PostDelayedTask( FROM_HERE, method_factory_.NewRunnableMethod( @@ -131,6 +141,9 @@ class MockPendingClientSocket : public ClientSocket { virtual int GetPeerAddress(AddressList* address) const{ return ERR_UNEXPECTED; } + virtual const BoundNetLog& NetLog() const { + return net_log_; + } // Socket methods: virtual int Read(IOBuffer* buf, int buf_len, @@ -164,6 +177,7 @@ class MockPendingClientSocket : public ClientSocket { bool should_stall_; int delay_ms_; bool is_connected_; + BoundNetLog net_log_; }; class MockClientSocketFactory : public ClientSocketFactory { @@ -183,7 +197,8 @@ class MockClientSocketFactory : public ClientSocketFactory { : allocation_count_(0), client_socket_type_(MOCK_CLIENT_SOCKET), client_socket_types_(NULL), client_socket_index_(0) {} - virtual ClientSocket* CreateTCPClientSocket(const AddressList& addresses) { + virtual ClientSocket* CreateTCPClientSocket(const AddressList& addresses, + NetLog* /* net_log */) { allocation_count_++; ClientSocketType type = client_socket_type_; diff --git a/net/socket/tcp_client_socket_unittest.cc b/net/socket/tcp_client_socket_unittest.cc index 01a0783..53ec97b 100644 --- a/net/socket/tcp_client_socket_unittest.cc +++ b/net/socket/tcp_client_socket_unittest.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -26,7 +26,7 @@ const char kServerReply[] = "HTTP/1.1 404 Not Found"; class TCPClientSocketTest : public PlatformTest, public ListenSocket::ListenSocketDelegate { public: - TCPClientSocketTest() { + TCPClientSocketTest() : net_log_(CapturingNetLog::kUnbounded) { } // Implement ListenSocketDelegate methods @@ -59,6 +59,7 @@ class TCPClientSocketTest protected: int listen_port_; + CapturingNetLog net_log_; scoped_ptr<TCPClientSocket> sock_; private: @@ -92,21 +93,20 @@ void TCPClientSocketTest::SetUp() { HostResolver::RequestInfo info("localhost", listen_port_); int rv = resolver->Resolve(info, &addr, NULL, NULL, NULL); CHECK_EQ(rv, OK); - sock_.reset(new TCPClientSocket(addr)); + sock_.reset(new TCPClientSocket(addr, &net_log_)); } TEST_F(TCPClientSocketTest, Connect) { TestCompletionCallback callback; EXPECT_FALSE(sock_->IsConnected()); - CapturingBoundNetLog log(CapturingNetLog::kUnbounded); - int rv = sock_->Connect(&callback, log.bound()); + int rv = sock_->Connect(&callback); EXPECT_TRUE(net::LogContainsBeginEvent( - log.entries(), 0, net::NetLog::TYPE_TCP_CONNECT)); + net_log_.entries(), 0, net::NetLog::TYPE_TCP_CONNECT)); if (rv != OK) { ASSERT_EQ(rv, ERR_IO_PENDING); EXPECT_FALSE(net::LogContainsEndEvent( - log.entries(), -1, net::NetLog::TYPE_TCP_CONNECT)); + net_log_.entries(), -1, net::NetLog::TYPE_TCP_CONNECT)); rv = callback.WaitForResult(); EXPECT_EQ(rv, OK); @@ -114,7 +114,7 @@ TEST_F(TCPClientSocketTest, Connect) { EXPECT_TRUE(sock_->IsConnected()); EXPECT_TRUE(net::LogContainsEndEvent( - log.entries(), -1, net::NetLog::TYPE_TCP_CONNECT)); + net_log_.entries(), -1, net::NetLog::TYPE_TCP_CONNECT)); sock_->Disconnect(); EXPECT_FALSE(sock_->IsConnected()); @@ -126,7 +126,7 @@ TEST_F(TCPClientSocketTest, Connect) { TEST_F(TCPClientSocketTest, Read) { TestCompletionCallback callback; - int rv = sock_->Connect(&callback, NULL); + int rv = sock_->Connect(&callback); if (rv != OK) { ASSERT_EQ(rv, ERR_IO_PENDING); @@ -171,7 +171,7 @@ TEST_F(TCPClientSocketTest, Read) { TEST_F(TCPClientSocketTest, Read_SmallChunks) { TestCompletionCallback callback; - int rv = sock_->Connect(&callback, NULL); + int rv = sock_->Connect(&callback); if (rv != OK) { ASSERT_EQ(rv, ERR_IO_PENDING); @@ -216,7 +216,7 @@ TEST_F(TCPClientSocketTest, Read_SmallChunks) { TEST_F(TCPClientSocketTest, Read_Interrupted) { TestCompletionCallback callback; - int rv = sock_->Connect(&callback, NULL); + int rv = sock_->Connect(&callback); if (rv != OK) { ASSERT_EQ(ERR_IO_PENDING, rv); @@ -250,7 +250,7 @@ TEST_F(TCPClientSocketTest, Read_Interrupted) { TEST_F(TCPClientSocketTest, DISABLED_FullDuplex_ReadFirst) { TestCompletionCallback callback; - int rv = sock_->Connect(&callback, NULL); + int rv = sock_->Connect(&callback); if (rv != OK) { ASSERT_EQ(rv, ERR_IO_PENDING); @@ -292,7 +292,7 @@ TEST_F(TCPClientSocketTest, DISABLED_FullDuplex_ReadFirst) { TEST_F(TCPClientSocketTest, DISABLED_FullDuplex_WriteFirst) { TestCompletionCallback callback; - int rv = sock_->Connect(&callback, NULL); + int rv = sock_->Connect(&callback); if (rv != OK) { ASSERT_EQ(ERR_IO_PENDING, rv); diff --git a/net/socket/tcp_client_socket_win.cc b/net/socket/tcp_client_socket_win.cc index 8d8cdd4..24c3eca 100644 --- a/net/socket/tcp_client_socket_win.cc +++ b/net/socket/tcp_client_socket_win.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2008 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -272,7 +272,8 @@ void TCPClientSocketWin::Core::WriteDelegate::OnObjectSignaled( //----------------------------------------------------------------------------- -TCPClientSocketWin::TCPClientSocketWin(const AddressList& addresses) +TCPClientSocketWin::TCPClientSocketWin(const AddressList& addresses, + net::NetLog* net_log) : socket_(INVALID_SOCKET), addresses_(addresses), current_ai_(addresses_.head()), @@ -280,28 +281,27 @@ TCPClientSocketWin::TCPClientSocketWin(const AddressList& addresses) waiting_read_(false), waiting_write_(false), read_callback_(NULL), - write_callback_(NULL) { + write_callback_(NULL), + net_log_(BoundNetLog::Make(net_log, NetLog::SOURCE_SOCKET)) { EnsureWinsockInit(); } TCPClientSocketWin::~TCPClientSocketWin() { Disconnect(); + net_log_.AddEvent(NetLog::TYPE_TCP_SOCKET_DONE); } -int TCPClientSocketWin::Connect(CompletionCallback* callback, - const BoundNetLog& net_log) { +int TCPClientSocketWin::Connect(CompletionCallback* callback) { // If already connected, then just return OK. if (socket_ != INVALID_SOCKET) return OK; - DCHECK(!net_log_.net_log()); - static StatsCounter connects("tcp.connect"); connects.Increment(); TRACE_EVENT_BEGIN("socket.connect", this, ""); - net_log.BeginEvent(NetLog::TYPE_TCP_CONNECT); + net_log_.BeginEvent(NetLog::TYPE_TCP_CONNECT); int rv = DoConnect(); @@ -309,12 +309,11 @@ int TCPClientSocketWin::Connect(CompletionCallback* callback, // Synchronous operation not supported. DCHECK(callback); - net_log_ = net_log; waiting_connect_ = true; read_callback_ = callback; } else { TRACE_EVENT_END("socket.connect", this, ""); - net_log.EndEvent(NetLog::TYPE_TCP_CONNECT); + net_log_.EndEvent(NetLog::TYPE_TCP_CONNECT); if (rv == OK) UpdateConnectionTypeHistograms(CONNECTION_ANY); } @@ -478,6 +477,7 @@ int TCPClientSocketWin::Read(IOBuffer* buf, base::MemoryDebug::MarkAsInitialized(core_->read_buffer_.buf, num); static StatsCounter read_bytes("tcp.read_bytes"); read_bytes.Add(num); + net_log_.AddEventWithInteger(NetLog::TYPE_SOCKET_BYTES_RECEIVED, num); return static_cast<int>(num); } } else { @@ -528,6 +528,7 @@ int TCPClientSocketWin::Write(IOBuffer* buf, TRACE_EVENT_END("socket.write", this, StringPrintf("%d bytes", rv)); static StatsCounter write_bytes("tcp.write_bytes"); write_bytes.Add(rv); + net_log_.AddEventWithInteger(NetLog::TYPE_SOCKET_BYTES_SENT, rv); return rv; } } else { @@ -659,23 +660,19 @@ void TCPClientSocketWin::DidCompleteConnect() { const struct addrinfo* next = current_ai_->ai_next; Disconnect(); current_ai_ = next; - BoundNetLog net_log(net_log_); - net_log_ = BoundNetLog(); TRACE_EVENT_END("socket.connect", this, ""); - net_log.EndEvent(NetLog::TYPE_TCP_CONNECT); - result = Connect(read_callback_, net_log); + net_log_.EndEvent(NetLog::TYPE_TCP_CONNECT); + result = Connect(read_callback_); } else { result = MapConnectError(os_error); TRACE_EVENT_END("socket.connect", this, ""); net_log_.EndEvent(NetLog::TYPE_TCP_CONNECT); - net_log_ = BoundNetLog(); } } else { NOTREACHED(); result = ERR_UNEXPECTED; TRACE_EVENT_END("socket.connect", this, ""); net_log_.EndEvent(NetLog::TYPE_TCP_CONNECT); - net_log_ = BoundNetLog(); } if (result != ERR_IO_PENDING) { @@ -694,6 +691,8 @@ void TCPClientSocketWin::DidCompleteRead() { TRACE_EVENT_END("socket.read", this, StringPrintf("%d bytes", num_bytes)); waiting_read_ = false; core_->read_iobuffer_ = NULL; + if (ok) + net_log_.AddEventWithInteger(NetLog::TYPE_SOCKET_BYTES_RECEIVED, num_bytes); DoReadCallback(ok ? num_bytes : MapWinsockError(WSAGetLastError())); } @@ -718,6 +717,8 @@ void TCPClientSocketWin::DidCompleteWrite() { << core_->write_buffer_length_ << " bytes, but " << rv << " bytes reported."; rv = ERR_WINSOCK_UNEXPECTED_WRITTEN_BYTES; + } else { + net_log_.AddEventWithInteger(NetLog::TYPE_SOCKET_BYTES_SENT, rv); } } core_->write_iobuffer_ = NULL; diff --git a/net/socket/tcp_client_socket_win.h b/net/socket/tcp_client_socket_win.h index 128b72e..7e4eb8f 100644 --- a/net/socket/tcp_client_socket_win.h +++ b/net/socket/tcp_client_socket_win.h @@ -1,4 +1,4 @@ -// Copyright (c) 2006-2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -22,16 +22,17 @@ class TCPClientSocketWin : public ClientSocket { // The IP address(es) and port number to connect to. The TCP socket will try // each IP address in the list until it succeeds in establishing a // connection. - explicit TCPClientSocketWin(const AddressList& addresses); + TCPClientSocketWin(const AddressList& addresses, net::NetLog* net_log); ~TCPClientSocketWin(); // ClientSocket methods: - virtual int Connect(CompletionCallback* callback, const BoundNetLog& net_log); + virtual int Connect(CompletionCallback* callback); virtual void Disconnect(); virtual bool IsConnected() const; virtual bool IsConnectedAndIdle() const; virtual int GetPeerAddress(AddressList* address) const; + virtual const BoundNetLog& NetLog() const { return net_log_; } // Socket methods: // Multiple outstanding requests are not supported. diff --git a/net/socket/tcp_pinger.h b/net/socket/tcp_pinger.h index 94fdeea..f557e25 100644 --- a/net/socket/tcp_pinger.h +++ b/net/socket/tcp_pinger.h @@ -1,4 +1,4 @@ -// Copyright (c) 2009 The Chromium Authors. All rights reserved. +// Copyright (c) 2010 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -86,8 +86,8 @@ class TCPPinger { } void DoConnect() { - sock_.reset(new TCPClientSocket(addr_)); - int rv = sock_->Connect(&connect_callback_, NULL); + sock_.reset(new TCPClientSocket(addr_, NULL)); + int rv = sock_->Connect(&connect_callback_); // Regardless of success or failure, if we're done now, // signal the customer. if (rv != ERR_IO_PENDING) diff --git a/net/socket_stream/socket_stream.cc b/net/socket_stream/socket_stream.cc index 8a78659..5500579 100644 --- a/net/socket_stream/socket_stream.cc +++ b/net/socket_stream/socket_stream.cc @@ -499,9 +499,10 @@ int SocketStream::DoResolveHostComplete(int result) { int SocketStream::DoTcpConnect() { next_state_ = STATE_TCP_CONNECT_COMPLETE; DCHECK(factory_); - socket_.reset(factory_->CreateTCPClientSocket(addresses_)); + socket_.reset(factory_->CreateTCPClientSocket(addresses_, + net_log_.net_log())); metrics_->OnStartConnection(); - return socket_->Connect(&io_callback_, net_log_); + return socket_->Connect(&io_callback_); } int SocketStream::DoTcpConnectComplete(int result) { @@ -717,7 +718,7 @@ int SocketStream::DoSOCKSConnect() { s = new SOCKSClientSocket(s, req_info, host_resolver_.get()); socket_.reset(s); metrics_->OnSOCKSProxy(); - return socket_->Connect(&io_callback_, net_log_); + return socket_->Connect(&io_callback_); } int SocketStream::DoSOCKSConnectComplete(int result) { @@ -740,7 +741,7 @@ int SocketStream::DoSSLConnect() { socket_.release(), url_.HostNoBrackets(), ssl_config_)); next_state_ = STATE_SSL_CONNECT_COMPLETE; metrics_->OnSSLConnection(); - return socket_->Connect(&io_callback_, net_log_); + return socket_->Connect(&io_callback_); } int SocketStream::DoSSLConnectComplete(int result) { diff --git a/net/spdy/spdy_session.cc b/net/spdy/spdy_session.cc index 1d43a9f..2b03425 100644 --- a/net/spdy/spdy_session.cc +++ b/net/spdy/spdy_session.cc @@ -480,7 +480,7 @@ void SpdySession::OnTCPConnect(int result) { connection_->set_socket(socket); is_secure_ = true; // TODO(willchan): Plumb NetLog into SPDY code. - int status = connection_->socket()->Connect(&ssl_connect_callback_, NULL); + int status = connection_->socket()->Connect(&ssl_connect_callback_); if (status != ERR_IO_PENDING) OnSSLConnect(status); } else { |