Chromium Code Reviews
chromiumcodereview-hr@appspot.gserviceaccount.com (chromiumcodereview-hr) | Please choose your nickname with Settings | Help | Chromium Project | Gerrit Changes | Sign out
(36)

Issues Search
    My Issues | Starred     Open | Closed | All

Side by Side Diff: chrome/browser/net/passive_log_collector_unittest.cc

Issue 2363003: Rework the logging for sockets/connectjobs.... (Closed) Base URL: svn://chrome-svn/chrome/trunk/src/
Patch Set: '' Created 10 years, 6 months ago
Use n/p to move between diff chunks; N/P to move between comments. Draft comments are only viewable by you.
Jump to:
View unified diff | Download patch | Annotate | Revision Log
« no previous file with comments | « chrome/browser/net/passive_log_collector.cc ('k') | chrome/service/net/service_url_request_context.cc » ('j') | no next file with comments »
Toggle Intra-line Diffs ('i') | Expand Comments ('e') | Collapse Comments ('c') | Show Comments Hide Comments ('s')
OLDNEW
1 // Copyright (c) 2010 The Chromium Authors. All rights reserved. 1 // Copyright (c) 2010 The Chromium Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be 2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file. 3 // found in the LICENSE file.
4 4
5 #include "chrome/browser/net/passive_log_collector.h" 5 #include "chrome/browser/net/passive_log_collector.h"
6 6
7 #include "base/compiler_specific.h" 7 #include "base/compiler_specific.h"
8 #include "base/format_macros.h" 8 #include "base/format_macros.h"
9 #include "base/string_util.h" 9 #include "base/string_util.h"
10 #include "net/url_request/url_request_netlog_params.h" 10 #include "net/url_request/url_request_netlog_params.h"
11 #include "testing/gtest/include/gtest/gtest.h" 11 #include "testing/gtest/include/gtest/gtest.h"
12 12
13 namespace { 13 namespace {
14 14
15 typedef PassiveLogCollector::RequestTracker RequestTracker; 15 typedef PassiveLogCollector::RequestTracker RequestTracker;
16 typedef PassiveLogCollector::RequestInfoList RequestInfoList; 16 typedef PassiveLogCollector::RequestInfoList RequestInfoList;
17 typedef PassiveLogCollector::SocketTracker SocketTracker;
17 using net::NetLog; 18 using net::NetLog;
18 19
19 const NetLog::SourceType kSourceType = NetLog::SOURCE_NONE; 20 const NetLog::SourceType kSourceType = NetLog::SOURCE_NONE;
20 21
21 PassiveLogCollector::Entry MakeStartLogEntryWithURL(int source_id, 22 PassiveLogCollector::Entry MakeStartLogEntryWithURL(int source_id,
22 const std::string& url) { 23 const std::string& url) {
23 return PassiveLogCollector::Entry( 24 return PassiveLogCollector::Entry(
24 0, 25 0,
25 NetLog::TYPE_URL_REQUEST_START_JOB, 26 NetLog::TYPE_URL_REQUEST_START_JOB,
26 base::TimeTicks(), 27 base::TimeTicks(),
(...skipping 31 matching lines...) Expand 10 before | Expand all | Expand 10 after
58 collector->OnAddEntry(NetLog::TYPE_REQUEST_ALIVE, base::TimeTicks(), 59 collector->OnAddEntry(NetLog::TYPE_REQUEST_ALIVE, base::TimeTicks(),
59 NetLog::Source(NetLog::SOURCE_URL_REQUEST, id), 60 NetLog::Source(NetLog::SOURCE_URL_REQUEST, id),
60 NetLog::PHASE_END, NULL); 61 NetLog::PHASE_END, NULL);
61 } 62 }
62 63
63 std::string GetStringParam(const PassiveLogCollector::Entry& entry) { 64 std::string GetStringParam(const PassiveLogCollector::Entry& entry) {
64 return static_cast<net::NetLogStringParameter*>( 65 return static_cast<net::NetLogStringParameter*>(
65 entry.params.get())->value(); 66 entry.params.get())->value();
66 } 67 }
67 68
69 bool OrderBySourceID(const PassiveLogCollector::RequestInfo& a,
70 const PassiveLogCollector::RequestInfo& b) {
71 return a.source_id < b.source_id;
72 }
73
74 RequestInfoList GetLiveRequests(
75 const PassiveLogCollector::RequestTrackerBase& tracker) {
76 RequestInfoList result = tracker.GetAllDeadOrAliveRequests(true);
77 std::sort(result.begin(), result.end(), &OrderBySourceID);
78 return result;
79 }
80
81 RequestInfoList GetDeadRequests(
82 const PassiveLogCollector::RequestTrackerBase& tracker) {
83 RequestInfoList result = tracker.GetAllDeadOrAliveRequests(false);
84 std::sort(result.begin(), result.end(), &OrderBySourceID);
85 return result;
86 }
87
68 static const int kMaxNumLoadLogEntries = 1; 88 static const int kMaxNumLoadLogEntries = 1;
69 89
70 } // namespace 90 } // namespace
71 91
72 TEST(RequestTrackerTest, BasicBounded) { 92 TEST(RequestTrackerTest, BasicBounded) {
73 RequestTracker tracker(NULL, NULL); 93 RequestTracker tracker(NULL);
74 EXPECT_EQ(0u, tracker.GetLiveRequests().size()); 94 EXPECT_EQ(0u, GetLiveRequests(tracker).size());
75 EXPECT_EQ(0u, tracker.GetRecentlyDeceased().size()); 95 EXPECT_EQ(0u, GetDeadRequests(tracker).size());
76 96
77 tracker.OnAddEntry(MakeStartLogEntry(1)); 97 tracker.OnAddEntry(MakeStartLogEntry(1));
78 tracker.OnAddEntry(MakeStartLogEntry(2)); 98 tracker.OnAddEntry(MakeStartLogEntry(2));
79 tracker.OnAddEntry(MakeStartLogEntry(3)); 99 tracker.OnAddEntry(MakeStartLogEntry(3));
80 tracker.OnAddEntry(MakeStartLogEntry(4)); 100 tracker.OnAddEntry(MakeStartLogEntry(4));
81 tracker.OnAddEntry(MakeStartLogEntry(5)); 101 tracker.OnAddEntry(MakeStartLogEntry(5));
82 102
83 RequestInfoList live_reqs = tracker.GetLiveRequests(); 103 RequestInfoList live_reqs = GetLiveRequests(tracker);
84 104
85 ASSERT_EQ(5u, live_reqs.size()); 105 ASSERT_EQ(5u, live_reqs.size());
86 EXPECT_EQ("http://req1/", live_reqs[0].GetURL()); 106 EXPECT_EQ("http://req1/", live_reqs[0].GetURL());
87 EXPECT_EQ("http://req2/", live_reqs[1].GetURL()); 107 EXPECT_EQ("http://req2/", live_reqs[1].GetURL());
88 EXPECT_EQ("http://req3/", live_reqs[2].GetURL()); 108 EXPECT_EQ("http://req3/", live_reqs[2].GetURL());
89 EXPECT_EQ("http://req4/", live_reqs[3].GetURL()); 109 EXPECT_EQ("http://req4/", live_reqs[3].GetURL());
90 EXPECT_EQ("http://req5/", live_reqs[4].GetURL()); 110 EXPECT_EQ("http://req5/", live_reqs[4].GetURL());
91 111
92 tracker.OnAddEntry(MakeEndLogEntry(1)); 112 tracker.OnAddEntry(MakeEndLogEntry(1));
93 tracker.OnAddEntry(MakeEndLogEntry(5)); 113 tracker.OnAddEntry(MakeEndLogEntry(5));
94 tracker.OnAddEntry(MakeEndLogEntry(3)); 114 tracker.OnAddEntry(MakeEndLogEntry(3));
95 115
96 ASSERT_EQ(3u, tracker.GetRecentlyDeceased().size()); 116 ASSERT_EQ(3u, GetDeadRequests(tracker).size());
97 117
98 live_reqs = tracker.GetLiveRequests(); 118 live_reqs = GetLiveRequests(tracker);
99 119
100 ASSERT_EQ(2u, live_reqs.size()); 120 ASSERT_EQ(2u, live_reqs.size());
101 EXPECT_EQ("http://req2/", live_reqs[0].GetURL()); 121 EXPECT_EQ("http://req2/", live_reqs[0].GetURL());
102 EXPECT_EQ("http://req4/", live_reqs[1].GetURL()); 122 EXPECT_EQ("http://req4/", live_reqs[1].GetURL());
103 } 123 }
104 124
105 TEST(RequestTrackerTest, GraveyardBounded) { 125 TEST(RequestTrackerTest, GraveyardBounded) {
106 RequestTracker tracker(NULL, NULL); 126 RequestTracker tracker(NULL);
107 EXPECT_EQ(0u, tracker.GetLiveRequests().size()); 127 EXPECT_EQ(0u, GetLiveRequests(tracker).size());
108 EXPECT_EQ(0u, tracker.GetRecentlyDeceased().size()); 128 EXPECT_EQ(0u, GetDeadRequests(tracker).size());
109 129
110 // Add twice as many requests as will fit in the graveyard. 130 // Add twice as many requests as will fit in the graveyard.
111 for (size_t i = 0; i < RequestTracker::kMaxGraveyardSize * 2; ++i) { 131 for (size_t i = 0; i < RequestTracker::kMaxGraveyardSize * 2; ++i) {
112 tracker.OnAddEntry(MakeStartLogEntry(i)); 132 tracker.OnAddEntry(MakeStartLogEntry(i));
113 tracker.OnAddEntry(MakeEndLogEntry(i)); 133 tracker.OnAddEntry(MakeEndLogEntry(i));
114 } 134 }
115 135
136 EXPECT_EQ(0u, GetLiveRequests(tracker).size());
137
116 // Check that only the last |kMaxGraveyardSize| requests are in-memory. 138 // Check that only the last |kMaxGraveyardSize| requests are in-memory.
117 139
118 RequestInfoList recent_reqs = tracker.GetRecentlyDeceased(); 140 RequestInfoList recent_reqs = GetDeadRequests(tracker);
119 141
120 ASSERT_EQ(RequestTracker::kMaxGraveyardSize, recent_reqs.size()); 142 ASSERT_EQ(RequestTracker::kMaxGraveyardSize, recent_reqs.size());
121 143
122 for (size_t i = 0; i < RequestTracker::kMaxGraveyardSize; ++i) { 144 for (size_t i = 0; i < RequestTracker::kMaxGraveyardSize; ++i) {
123 size_t req_number = i + RequestTracker::kMaxGraveyardSize; 145 size_t req_number = i + RequestTracker::kMaxGraveyardSize;
124 std::string url = StringPrintf("http://req%" PRIuS "/", req_number); 146 std::string url = StringPrintf("http://req%" PRIuS "/", req_number);
125 EXPECT_EQ(url, recent_reqs[i].GetURL()); 147 EXPECT_EQ(url, recent_reqs[i].GetURL());
126 } 148 }
127 } 149 }
128 150
129 // Check that we exclude "chrome://" URLs from being saved into the recent 151 // Check that we exclude "chrome://" URLs from being saved into the recent
130 // requests list (graveyard). 152 // requests list (graveyard).
131 TEST(RequestTrackerTest, GraveyardIsFiltered) { 153 TEST(RequestTrackerTest, GraveyardIsFiltered) {
132 RequestTracker tracker(NULL, NULL); 154 RequestTracker tracker(NULL);
133 155
134 // This will be excluded. 156 // This will be excluded.
135 std::string url1 = "chrome://dontcare/"; 157 std::string url1 = "chrome://dontcare/";
136 tracker.OnAddEntry(MakeStartLogEntryWithURL(1, url1)); 158 tracker.OnAddEntry(MakeStartLogEntryWithURL(1, url1));
137 tracker.OnAddEntry(MakeEndLogEntry(1)); 159 tracker.OnAddEntry(MakeEndLogEntry(1));
138 160
139 // This will be be added to graveyard. 161 // This will be be added to graveyard.
140 std::string url2 = "chrome2://dontcare/"; 162 std::string url2 = "chrome2://dontcare/";
141 tracker.OnAddEntry(MakeStartLogEntryWithURL(2, url2)); 163 tracker.OnAddEntry(MakeStartLogEntryWithURL(2, url2));
142 tracker.OnAddEntry(MakeEndLogEntry(2)); 164 tracker.OnAddEntry(MakeEndLogEntry(2));
143 165
144 // This will be be added to graveyard. 166 // This will be be added to graveyard.
145 std::string url3 = "http://foo/"; 167 std::string url3 = "http://foo/";
146 tracker.OnAddEntry(MakeStartLogEntryWithURL(3, url3)); 168 tracker.OnAddEntry(MakeStartLogEntryWithURL(3, url3));
147 tracker.OnAddEntry(MakeEndLogEntry(3)); 169 tracker.OnAddEntry(MakeEndLogEntry(3));
148 170
149 ASSERT_EQ(2u, tracker.GetRecentlyDeceased().size()); 171 ASSERT_EQ(2u, GetDeadRequests(tracker).size());
150 EXPECT_EQ(url2, tracker.GetRecentlyDeceased()[0].GetURL()); 172 EXPECT_EQ(url2, GetDeadRequests(tracker)[0].GetURL());
151 EXPECT_EQ(url3, tracker.GetRecentlyDeceased()[1].GetURL()); 173 EXPECT_EQ(url3, GetDeadRequests(tracker)[1].GetURL());
152 }
153
154 TEST(PassiveLogCollectorTest, BasicConnectJobAssociation) {
155 PassiveLogCollector log;
156
157 RequestInfoList requests = log.url_request_tracker()->GetLiveRequests();
158 EXPECT_EQ(0u, requests.size());
159
160 AddStartURLRequestEntries(&log, 10);
161 AddStartURLRequestEntries(&log, 20);
162
163 requests = log.url_request_tracker()->GetLiveRequests();
164 EXPECT_EQ(2u, requests.size());
165
166 EXPECT_EQ(10u, requests[0].source_id);
167 EXPECT_EQ(2u, requests[0].entries.size());
168 EXPECT_EQ(20u, requests[1].source_id);
169 EXPECT_EQ(2u, requests[1].entries.size());
170
171 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
172 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
173 NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11));
174 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
175 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
176 NetLog::PHASE_BEGIN, NULL);
177
178 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
179 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
180 NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 21));
181 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
182 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
183 NetLog::PHASE_BEGIN, NULL);
184 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
185 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
186 NetLog::PHASE_END, NULL);
187
188 requests = log.url_request_tracker()->GetLiveRequests();
189 EXPECT_EQ(2u, requests.size());
190
191 EXPECT_EQ(4u, requests[0].entries.size());
192 EXPECT_EQ(5u, requests[1].entries.size());
193
194 AddEndURLRequestEntries(&log, 10);
195 AddEndURLRequestEntries(&log, 20);
196
197 requests = log.url_request_tracker()->GetLiveRequests();
198 EXPECT_EQ(0u, requests.size());
199
200 requests = log.url_request_tracker()->GetRecentlyDeceased();
201 EXPECT_EQ(2u, requests.size());
202 EXPECT_EQ(5u, requests[0].entries.size());
203 EXPECT_EQ(6u, requests[1].entries.size());
204 }
205
206 TEST(PassiveLogCollectorTest, BasicSocketAssociation) {
207 PassiveLogCollector log;
208
209 RequestInfoList requests = log.url_request_tracker()->GetLiveRequests();
210 EXPECT_EQ(0u, requests.size());
211
212 AddStartURLRequestEntries(&log, 10);
213 AddStartURLRequestEntries(&log, 20);
214
215 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
216 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
217 NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11));
218 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
219 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
220 NetLog::PHASE_BEGIN, NULL);
221 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
222 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
223 NetLog::PHASE_END, NULL);
224
225 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
226 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
227 NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 21));
228 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
229 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
230 NetLog::PHASE_BEGIN, NULL);
231 log.OnAddEntry(NetLog::TYPE_TCP_CONNECT , base::TimeTicks(),
232 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
233 NetLog::PHASE_NONE, NULL);
234 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
235 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
236 NetLog::PHASE_END, NULL);
237
238 requests = log.url_request_tracker()->GetLiveRequests();
239 EXPECT_EQ(2u, requests.size());
240
241 EXPECT_EQ(5u, requests[0].entries.size());
242 EXPECT_EQ(6u, requests[1].entries.size());
243
244 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
245 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
246 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 11));
247 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
248 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
249 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 21));
250
251 requests = log.url_request_tracker()->GetLiveRequests();
252 EXPECT_EQ(2u, requests.size());
253
254 EXPECT_EQ(6u, requests[0].entries.size());
255 EXPECT_EQ(7u, requests[1].entries.size());
256
257 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
258 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
259 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15));
260 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
261 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
262 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 25));
263
264 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
265 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
266 NetLog::PHASE_NONE, NULL);
267 log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(),
268 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
269 NetLog::PHASE_BEGIN, NULL);
270 log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(),
271 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
272 NetLog::PHASE_END, NULL);
273
274 requests = log.url_request_tracker()->GetLiveRequests();
275 EXPECT_EQ(2u, requests.size());
276
277 EXPECT_EQ(8u, requests[0].entries.size());
278 EXPECT_EQ(10u, requests[1].entries.size());
279
280 AddEndURLRequestEntries(&log, 10);
281 AddEndURLRequestEntries(&log, 20);
282
283 log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(),
284 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
285 NetLog::PHASE_NONE, NULL);
286 log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(),
287 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
288 NetLog::PHASE_NONE, NULL);
289
290 requests = log.url_request_tracker()->GetLiveRequests();
291 EXPECT_EQ(0u, requests.size());
292
293 requests = log.url_request_tracker()->GetRecentlyDeceased();
294 EXPECT_EQ(2u, requests.size());
295 EXPECT_EQ(9u, requests[0].entries.size());
296 EXPECT_EQ(11u, requests[1].entries.size());
297 }
298
299 TEST(PassiveLogCollectorTest, IdleSocketAssociation) {
300 PassiveLogCollector log;
301
302 RequestInfoList requests = log.url_request_tracker()->GetLiveRequests();
303 EXPECT_EQ(0u, requests.size());
304
305 AddStartURLRequestEntries(&log, 10);
306 AddStartURLRequestEntries(&log, 20);
307 log.OnAddEntry(NetLog::TYPE_INIT_PROXY_RESOLVER , base::TimeTicks(),
308 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
309 NetLog::PHASE_NONE, NULL);
310
311 requests = log.url_request_tracker()->GetLiveRequests();
312 EXPECT_EQ(2u, requests.size());
313
314 EXPECT_EQ(2u, requests[0].entries.size());
315 EXPECT_EQ(3u, requests[1].entries.size());
316
317 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
318 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
319 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15));
320 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
321 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
322 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 25));
323
324 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
325 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
326 NetLog::PHASE_NONE, NULL);
327 log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(),
328 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
329 NetLog::PHASE_BEGIN, NULL);
330 log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(),
331 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
332 NetLog::PHASE_END, NULL);
333
334 requests = log.url_request_tracker()->GetLiveRequests();
335 EXPECT_EQ(2u, requests.size());
336
337 EXPECT_EQ(4u, requests[0].entries.size());
338 EXPECT_EQ(6u, requests[1].entries.size());
339
340 AddEndURLRequestEntries(&log, 10);
341 AddEndURLRequestEntries(&log, 20);
342
343 log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(),
344 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
345 NetLog::PHASE_NONE, NULL);
346 log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(),
347 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
348 NetLog::PHASE_NONE, NULL);
349
350 requests = log.url_request_tracker()->GetLiveRequests();
351 EXPECT_EQ(0u, requests.size());
352
353 requests = log.url_request_tracker()->GetRecentlyDeceased();
354 EXPECT_EQ(2u, requests.size());
355 EXPECT_EQ(5u, requests[0].entries.size());
356 EXPECT_EQ(7u, requests[1].entries.size());
357 }
358
359 TEST(PassiveLogCollectorTest, IdleAssociateAfterConnectJobStarted) {
360 PassiveLogCollector log;
361
362 RequestInfoList requests = log.url_request_tracker()->GetLiveRequests();
363 EXPECT_EQ(0u, requests.size());
364
365 AddStartURLRequestEntries(&log, 10);
366 AddStartURLRequestEntries(&log, 20);
367
368 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
369 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
370 NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11));
371 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
372 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
373 NetLog::PHASE_BEGIN, NULL);
374 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
375 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
376 NetLog::PHASE_END, NULL);
377
378 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
379 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
380 NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 21));
381 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
382 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
383 NetLog::PHASE_BEGIN, NULL);
384 log.OnAddEntry(NetLog::TYPE_TCP_CONNECT , base::TimeTicks(),
385 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
386 NetLog::PHASE_NONE, NULL);
387 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
388 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
389 NetLog::PHASE_END, NULL);
390
391 requests = log.url_request_tracker()->GetLiveRequests();
392 EXPECT_EQ(2u, requests.size());
393
394 EXPECT_EQ(5u, requests[0].entries.size());
395 EXPECT_EQ(6u, requests[1].entries.size());
396
397 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
398 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
399 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15));
400 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
401 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
402 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 25));
403
404 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
405 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
406 NetLog::PHASE_NONE, NULL);
407 log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(),
408 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
409 NetLog::PHASE_BEGIN, NULL);
410 log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(),
411 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
412 NetLog::PHASE_END, NULL);
413
414 requests = log.url_request_tracker()->GetLiveRequests();
415 EXPECT_EQ(2u, requests.size());
416
417 EXPECT_EQ(5u, requests[0].entries.size());
418 EXPECT_EQ(6u, requests[1].entries.size());
419
420 AddEndURLRequestEntries(&log, 10);
421 AddEndURLRequestEntries(&log, 20);
422
423 log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(),
424 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
425 NetLog::PHASE_NONE, NULL);
426 log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(),
427 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
428 NetLog::PHASE_NONE, NULL);
429
430 requests = log.url_request_tracker()->GetLiveRequests();
431 EXPECT_EQ(0u, requests.size());
432
433 requests = log.url_request_tracker()->GetRecentlyDeceased();
434 EXPECT_EQ(2u, requests.size());
435 EXPECT_EQ(6u, requests[0].entries.size());
436 EXPECT_EQ(7u, requests[1].entries.size());
437 }
438
439 TEST(PassiveLogCollectorTest, LateBindDifferentConnectJob) {
440 PassiveLogCollector log;
441
442 RequestInfoList requests = log.url_request_tracker()->GetLiveRequests();
443 EXPECT_EQ(0u, requests.size());
444
445 AddStartURLRequestEntries(&log, 10);
446 AddStartURLRequestEntries(&log, 20);
447
448 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
449 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
450 NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11));
451 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
452 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
453 NetLog::PHASE_BEGIN, NULL);
454 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
455 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
456 NetLog::PHASE_END, NULL);
457
458 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
459 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
460 NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 21));
461 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
462 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
463 NetLog::PHASE_BEGIN, NULL);
464 log.OnAddEntry(NetLog::TYPE_TCP_CONNECT , base::TimeTicks(),
465 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
466 NetLog::PHASE_NONE, NULL);
467 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
468 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
469 NetLog::PHASE_END, NULL);
470
471 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
472 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 31),
473 NetLog::PHASE_BEGIN, NULL);
474 log.OnAddEntry(NetLog::TYPE_TCP_CONNECT , base::TimeTicks(),
475 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 31),
476 NetLog::PHASE_BEGIN, NULL);
477 log.OnAddEntry(NetLog::TYPE_TCP_CONNECT , base::TimeTicks(),
478 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 31),
479 NetLog::PHASE_END, NULL);
480 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
481 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 31),
482 NetLog::PHASE_END, NULL);
483
484 requests = log.url_request_tracker()->GetLiveRequests();
485 EXPECT_EQ(2u, requests.size());
486
487 EXPECT_EQ(5u, requests[0].entries.size());
488 EXPECT_EQ(6u, requests[1].entries.size());
489
490 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
491 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
492 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 21));
493 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
494 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
495 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 31));
496
497 requests = log.url_request_tracker()->GetLiveRequests();
498 EXPECT_EQ(2u, requests.size());
499
500 EXPECT_EQ(7u, requests[0].entries.size());
501 EXPECT_EQ(8u, requests[1].entries.size());
502
503 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
504 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
505 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15));
506 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
507 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
508 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 25));
509
510 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
511 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
512 NetLog::PHASE_NONE, NULL);
513 log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(),
514 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
515 NetLog::PHASE_BEGIN, NULL);
516 log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(),
517 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
518 NetLog::PHASE_END, NULL);
519
520 requests = log.url_request_tracker()->GetLiveRequests();
521 EXPECT_EQ(2u, requests.size());
522
523 EXPECT_EQ(9u, requests[0].entries.size());
524 EXPECT_EQ(11u, requests[1].entries.size());
525
526 AddEndURLRequestEntries(&log, 10);
527 AddEndURLRequestEntries(&log, 20);
528
529 log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(),
530 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
531 NetLog::PHASE_NONE, NULL);
532 log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(),
533 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
534 NetLog::PHASE_NONE, NULL);
535
536 requests = log.url_request_tracker()->GetLiveRequests();
537 EXPECT_EQ(0u, requests.size());
538
539 requests = log.url_request_tracker()->GetRecentlyDeceased();
540 EXPECT_EQ(2u, requests.size());
541 EXPECT_EQ(10u, requests[0].entries.size());
542 EXPECT_EQ(12u, requests[1].entries.size());
543 }
544
545 TEST(PassiveLogCollectorTest, LateBindPendingConnectJob) {
546 PassiveLogCollector log;
547
548 RequestInfoList requests = log.url_request_tracker()->GetLiveRequests();
549 EXPECT_EQ(0u, requests.size());
550
551 AddStartURLRequestEntries(&log, 10);
552 AddStartURLRequestEntries(&log, 20);
553
554 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
555 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
556 NetLog::PHASE_BEGIN, NULL);
557 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
558 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
559 NetLog::PHASE_END, NULL);
560
561 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
562 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
563 NetLog::PHASE_BEGIN, NULL);
564 log.OnAddEntry(NetLog::TYPE_TCP_CONNECT , base::TimeTicks(),
565 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
566 NetLog::PHASE_NONE, NULL);
567 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
568 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 21),
569 NetLog::PHASE_END, NULL);
570
571 requests = log.url_request_tracker()->GetLiveRequests();
572 EXPECT_EQ(2u, requests.size());
573
574 EXPECT_EQ(2u, requests[0].entries.size());
575 EXPECT_EQ(2u, requests[1].entries.size());
576
577 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
578 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
579 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 11));
580 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
581 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
582 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 21));
583
584 requests = log.url_request_tracker()->GetLiveRequests();
585 EXPECT_EQ(2u, requests.size());
586
587 EXPECT_EQ(5u, requests[0].entries.size());
588 EXPECT_EQ(6u, requests[1].entries.size());
589
590 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
591 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
592 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15));
593 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
594 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
595 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 25));
596
597 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
598 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
599 NetLog::PHASE_NONE, NULL);
600 log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(),
601 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
602 NetLog::PHASE_BEGIN, NULL);
603 log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(),
604 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
605 NetLog::PHASE_END, NULL);
606
607 requests = log.url_request_tracker()->GetLiveRequests();
608 EXPECT_EQ(2u, requests.size());
609
610 EXPECT_EQ(7u, requests[0].entries.size());
611 EXPECT_EQ(9u, requests[1].entries.size());
612
613 AddEndURLRequestEntries(&log, 10);
614 AddEndURLRequestEntries(&log, 20);
615
616 log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(),
617 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
618 NetLog::PHASE_NONE, NULL);
619 log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(),
620 NetLog::Source(NetLog::SOURCE_SOCKET, 25),
621 NetLog::PHASE_NONE, NULL);
622
623 requests = log.url_request_tracker()->GetLiveRequests();
624 EXPECT_EQ(0u, requests.size());
625
626 requests = log.url_request_tracker()->GetRecentlyDeceased();
627 EXPECT_EQ(2u, requests.size());
628 EXPECT_EQ(8u, requests[0].entries.size());
629 EXPECT_EQ(10u, requests[1].entries.size());
630 }
631
632 TEST(PassiveLogCollectorTest, ReconnectToIdleSocket) {
633 PassiveLogCollector log;
634
635 RequestInfoList requests = log.url_request_tracker()->GetLiveRequests();
636 EXPECT_EQ(0u, requests.size());
637
638 AddStartURLRequestEntries(&log, 10);
639
640 // Initial socket.
641 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
642 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
643 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15));
644 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
645 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
646 NetLog::PHASE_NONE, NULL);
647
648 requests = log.url_request_tracker()->GetLiveRequests();
649 EXPECT_EQ(1u, requests.size());
650 EXPECT_EQ(4u, requests[0].entries.size());
651
652 // Reconnect.
653 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
654 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
655 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 17));
656 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
657 NetLog::Source(NetLog::SOURCE_SOCKET, 17),
658 NetLog::PHASE_NONE, NULL);
659
660 requests = log.url_request_tracker()->GetLiveRequests();
661 EXPECT_EQ(1u, requests.size());
662 EXPECT_EQ(6u, requests[0].entries.size());
663
664 AddEndURLRequestEntries(&log, 10);
665
666 log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(),
667 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
668 NetLog::PHASE_NONE, NULL);
669
670 requests = log.url_request_tracker()->GetLiveRequests();
671 EXPECT_EQ(0u, requests.size());
672
673 requests = log.url_request_tracker()->GetRecentlyDeceased();
674 EXPECT_EQ(1u, requests.size());
675 EXPECT_EQ(7u, requests[0].entries.size());
676 }
677
678 TEST(PassiveLogCollectorTest, ReconnectToLateBoundSocket) {
679 PassiveLogCollector log;
680
681 RequestInfoList requests = log.url_request_tracker()->GetLiveRequests();
682 EXPECT_EQ(0u, requests.size());
683
684 AddStartURLRequestEntries(&log, 10);
685
686 // Initial socket.
687 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
688 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
689 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15));
690 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
691 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
692 NetLog::PHASE_NONE, NULL);
693
694 requests = log.url_request_tracker()->GetLiveRequests();
695 EXPECT_EQ(1u, requests.size());
696 EXPECT_EQ(4u, requests[0].entries.size());
697
698 // Now reconnect.
699 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
700 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
701 NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11));
702 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
703 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
704 NetLog::PHASE_BEGIN, NULL);
705
706 requests = log.url_request_tracker()->GetLiveRequests();
707 EXPECT_EQ(1u, requests.size());
708 EXPECT_EQ(6u, requests[0].entries.size());
709
710 // But we get late bound to an idle socket.
711 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
712 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
713 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 17));
714 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
715 NetLog::Source(NetLog::SOURCE_SOCKET, 17),
716 NetLog::PHASE_NONE, NULL);
717
718 requests = log.url_request_tracker()->GetLiveRequests();
719 EXPECT_EQ(1u, requests.size());
720 EXPECT_EQ(7u, requests[0].entries.size());
721
722 AddEndURLRequestEntries(&log, 10);
723
724 log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(),
725 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
726 NetLog::PHASE_NONE, NULL);
727
728 requests = log.url_request_tracker()->GetLiveRequests();
729 EXPECT_EQ(0u, requests.size());
730
731 requests = log.url_request_tracker()->GetRecentlyDeceased();
732 EXPECT_EQ(1u, requests.size());
733 EXPECT_EQ(8u, requests[0].entries.size());
734 }
735
736 TEST(PassiveLogCollectorTest, ReconnectToLateBoundConnectJob) {
737 PassiveLogCollector log;
738
739 RequestInfoList requests = log.url_request_tracker()->GetLiveRequests();
740 EXPECT_EQ(0u, requests.size());
741
742 AddStartURLRequestEntries(&log, 10);
743
744 // Initial socket.
745 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
746 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
747 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15));
748 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
749 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
750 NetLog::PHASE_NONE, NULL);
751
752 requests = log.url_request_tracker()->GetLiveRequests();
753 EXPECT_EQ(1u, requests.size());
754 EXPECT_EQ(4u, requests[0].entries.size());
755
756 // Now reconnect.
757 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
758 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
759 NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11));
760 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
761 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
762 NetLog::PHASE_BEGIN, NULL);
763
764 requests = log.url_request_tracker()->GetLiveRequests();
765 EXPECT_EQ(1u, requests.size());
766 EXPECT_EQ(6u, requests[0].entries.size());
767
768 // But we get late bound to a different ConnectJob.
769 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
770 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 12),
771 NetLog::PHASE_BEGIN, NULL);
772 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
773 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 12),
774 NetLog::PHASE_END, NULL);
775 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
776 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
777 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 12));
778
779 requests = log.url_request_tracker()->GetLiveRequests();
780 EXPECT_EQ(1u, requests.size());
781 EXPECT_EQ(8u, requests[0].entries.size());
782
783 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
784 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
785 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 17));
786 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
787 NetLog::Source(NetLog::SOURCE_SOCKET, 17),
788 NetLog::PHASE_NONE, NULL);
789
790 requests = log.url_request_tracker()->GetLiveRequests();
791 EXPECT_EQ(1u, requests.size());
792 EXPECT_EQ(10u, requests[0].entries.size());
793
794 AddEndURLRequestEntries(&log, 10);
795
796 log.OnAddEntry(NetLog::TYPE_TCP_SOCKET_DONE , base::TimeTicks(),
797 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
798 NetLog::PHASE_NONE, NULL);
799
800 requests = log.url_request_tracker()->GetLiveRequests();
801 EXPECT_EQ(0u, requests.size());
802
803 requests = log.url_request_tracker()->GetRecentlyDeceased();
804 EXPECT_EQ(1u, requests.size());
805 EXPECT_EQ(11u, requests[0].entries.size());
806 }
807
808 TEST(PassiveLogCollectorTest, LostConnectJob) {
809 PassiveLogCollector log;
810
811 RequestInfoList requests = log.url_request_tracker()->GetLiveRequests();
812 EXPECT_EQ(0u, requests.size());
813
814 AddStartURLRequestEntries(&log, 10);
815
816 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
817 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
818 NetLog::PHASE_BEGIN, new net::NetLogIntegerParameter("x", 11));
819 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
820 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
821 NetLog::PHASE_BEGIN, NULL);
822 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
823 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
824 NetLog::PHASE_NONE, NULL);
825 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB , base::TimeTicks(),
826 NetLog::Source(NetLog::SOURCE_CONNECT_JOB, 11),
827 NetLog::PHASE_END, NULL);
828
829 requests = log.url_request_tracker()->GetLiveRequests();
830 EXPECT_EQ(1u, requests.size());
831 EXPECT_EQ(6u, requests[0].entries.size());
832
833 log.connect_job_tracker_.Clear();
834
835 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_CONNECT_JOB_ID , base::TimeTicks(),
836 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
837 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 11));
838
839 requests = log.url_request_tracker()->GetLiveRequests();
840 EXPECT_EQ(1u, requests.size());
841 EXPECT_EQ(5u, requests[0].entries.size());
842 }
843
844 TEST(PassiveLogCollectorTest, LostSocket) {
845 PassiveLogCollector log;
846
847 RequestInfoList requests = log.url_request_tracker()->GetLiveRequests();
848 EXPECT_EQ(0u, requests.size());
849
850 AddStartURLRequestEntries(&log, 10);
851
852 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
853 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
854 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15));
855 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
856 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
857 NetLog::PHASE_BEGIN, NULL);
858 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
859 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
860 NetLog::PHASE_END, NULL);
861 log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(),
862 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
863 NetLog::PHASE_BEGIN, NULL);
864 log.OnAddEntry(NetLog::TYPE_SSL_CONNECT , base::TimeTicks(),
865 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
866 NetLog::PHASE_END, NULL);
867
868 requests = log.url_request_tracker()->GetLiveRequests();
869 EXPECT_EQ(1u, requests.size());
870 EXPECT_EQ(7u, requests[0].entries.size());
871
872 log.socket_tracker_.Clear();
873
874 requests = log.url_request_tracker()->GetLiveRequests();
875 EXPECT_EQ(1u, requests.size());
876 EXPECT_EQ(4u, requests[0].entries.size());
877 }
878
879 TEST(PassiveLogCollectorTest, AccumulateRxTxData) {
880 PassiveLogCollector log;
881
882 RequestInfoList requests = log.url_request_tracker()->GetLiveRequests();
883 EXPECT_EQ(0u, requests.size());
884
885 AddStartURLRequestEntries(&log, 10);
886
887 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
888 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 10),
889 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15));
890 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
891 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
892 NetLog::PHASE_NONE, NULL);
893
894 requests = log.url_request_tracker()->GetLiveRequests();
895 EXPECT_EQ(1u, requests.size());
896 EXPECT_EQ(4u, requests[0].entries.size());
897
898 log.OnAddEntry(NetLog::TYPE_SOCKET_BYTES_SENT , base::TimeTicks(),
899 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
900 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 1));
901 requests = log.url_request_tracker()->GetLiveRequests();
902 EXPECT_EQ(1u, requests.size());
903 EXPECT_EQ(5u, requests[0].entries.size());
904 EXPECT_EQ(NetLog::TYPE_TODO_STRING, requests[0].entries[4].type);
905 EXPECT_EQ("Tx/Rx: 1/0 [1/0 total on socket] (Bytes)",
906 GetStringParam(requests[0].entries[4]));
907
908 log.OnAddEntry(NetLog::TYPE_SOCKET_BYTES_RECEIVED , base::TimeTicks(),
909 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
910 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 2));
911 requests = log.url_request_tracker()->GetLiveRequests();
912 EXPECT_EQ(1u, requests.size());
913 EXPECT_EQ(5u, requests[0].entries.size());
914 EXPECT_EQ(NetLog::TYPE_TODO_STRING, requests[0].entries[4].type);
915 EXPECT_EQ("Tx/Rx: 1/2 [1/2 total on socket] (Bytes)",
916 GetStringParam(requests[0].entries[4]));
917
918 AddEndURLRequestEntries(&log, 10);
919 requests = log.url_request_tracker()->GetLiveRequests();
920 EXPECT_EQ(0u, requests.size());
921 requests = log.url_request_tracker()->GetRecentlyDeceased();
922 EXPECT_EQ(1u, requests.size());
923 EXPECT_EQ(6u, requests[0].entries.size());
924 EXPECT_EQ(NetLog::TYPE_TODO_STRING, requests[0].entries[4].type);
925 EXPECT_EQ("Tx/Rx: 1/2 [1/2 total on socket] (Bytes)",
926 GetStringParam(requests[0].entries[4]));
927
928 AddStartURLRequestEntries(&log, 20);
929
930 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_SOCKET_ID , base::TimeTicks(),
931 NetLog::Source(NetLog::SOURCE_URL_REQUEST, 20),
932 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 15));
933 log.OnAddEntry(NetLog::TYPE_SOCKS_CONNECT , base::TimeTicks(),
934 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
935 NetLog::PHASE_NONE, NULL);
936
937 requests = log.url_request_tracker()->GetLiveRequests();
938 EXPECT_EQ(1u, requests.size());
939 EXPECT_EQ(4u, requests[0].entries.size());
940
941 log.OnAddEntry(NetLog::TYPE_SOCKET_BYTES_SENT , base::TimeTicks(),
942 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
943 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 4));
944 log.OnAddEntry(NetLog::TYPE_SOCKET_BYTES_RECEIVED , base::TimeTicks(),
945 NetLog::Source(NetLog::SOURCE_SOCKET, 15),
946 NetLog::PHASE_END, new net::NetLogIntegerParameter("x", 8));
947 requests = log.url_request_tracker()->GetLiveRequests();
948 EXPECT_EQ(1u, requests.size());
949 EXPECT_EQ(5u, requests[0].entries.size());
950 EXPECT_EQ(NetLog::TYPE_TODO_STRING, requests[0].entries[4].type);
951 EXPECT_EQ("Tx/Rx: 4/8 [5/10 total on socket] (Bytes)",
952 GetStringParam(requests[0].entries[4]));
953
954 AddEndURLRequestEntries(&log, 20);
955 requests = log.url_request_tracker()->GetLiveRequests();
956 EXPECT_EQ(0u, requests.size());
957 requests = log.url_request_tracker()->GetRecentlyDeceased();
958 EXPECT_EQ(2u, requests.size());
959 EXPECT_EQ(6u, requests[0].entries.size());
960 EXPECT_EQ(6u, requests[1].entries.size());
961 } 174 }
962 175
963 TEST(SpdySessionTracker, MovesToGraveyard) { 176 TEST(SpdySessionTracker, MovesToGraveyard) {
964 PassiveLogCollector::SpdySessionTracker tracker; 177 PassiveLogCollector::SpdySessionTracker tracker;
965 EXPECT_EQ(0u, tracker.GetLiveRequests().size()); 178 EXPECT_EQ(0u, GetLiveRequests(tracker).size());
966 EXPECT_EQ(0u, tracker.GetRecentlyDeceased().size()); 179 EXPECT_EQ(0u, GetDeadRequests(tracker).size());
967 180
968 PassiveLogCollector::Entry begin( 181 PassiveLogCollector::Entry begin(
969 0u, 182 0u,
970 NetLog::TYPE_SPDY_SESSION, 183 NetLog::TYPE_SPDY_SESSION,
971 base::TimeTicks(), 184 base::TimeTicks(),
972 NetLog::Source(NetLog::SOURCE_SPDY_SESSION, 1), 185 NetLog::Source(NetLog::SOURCE_SPDY_SESSION, 1),
973 NetLog::PHASE_BEGIN, 186 NetLog::PHASE_BEGIN,
974 NULL); 187 NULL);
975 188
976 tracker.OnAddEntry(begin); 189 tracker.OnAddEntry(begin);
977 EXPECT_EQ(1u, tracker.GetLiveRequests().size()); 190 EXPECT_EQ(1u, GetLiveRequests(tracker).size());
978 EXPECT_EQ(0u, tracker.GetRecentlyDeceased().size()); 191 EXPECT_EQ(0u, GetDeadRequests(tracker).size());
979 192
980 PassiveLogCollector::Entry end( 193 PassiveLogCollector::Entry end(
981 0u, 194 0u,
982 NetLog::TYPE_SPDY_SESSION, 195 NetLog::TYPE_SPDY_SESSION,
983 base::TimeTicks(), 196 base::TimeTicks(),
984 NetLog::Source(NetLog::SOURCE_SPDY_SESSION, 1), 197 NetLog::Source(NetLog::SOURCE_SPDY_SESSION, 1),
985 NetLog::PHASE_END, 198 NetLog::PHASE_END,
986 NULL); 199 NULL);
987 200
988 tracker.OnAddEntry(end); 201 tracker.OnAddEntry(end);
989 EXPECT_EQ(0u, tracker.GetLiveRequests().size()); 202 EXPECT_EQ(0u, GetLiveRequests(tracker).size());
990 EXPECT_EQ(1u, tracker.GetRecentlyDeceased().size()); 203 EXPECT_EQ(1u, GetDeadRequests(tracker).size());
991 } 204 }
205
206 // Test that when a SOURCE_SOCKET is connected to a SOURCE_URL_REQUEST
207 // (via the TYPE_SOCKET_POOL_BOUND_TO_SOCKET event), it holds a reference
208 // to the SOURCE_SOCKET preventing it from getting deleted as long as the
209 // SOURCE_URL_REQUEST is still around.
210 TEST(PassiveLogCollectorTest, HoldReferenceToDependentSource) {
211 PassiveLogCollector log;
212
213 EXPECT_EQ(0u, GetLiveRequests(log.url_request_tracker_).size());
214 EXPECT_EQ(0u, GetLiveRequests(log.socket_tracker_).size());
215
216 uint32 next_id = 0;
217 NetLog::Source socket_source(NetLog::SOURCE_SOCKET, next_id++);
218 NetLog::Source url_request_source(NetLog::SOURCE_URL_REQUEST, next_id++);
219
220 // Start a SOURCE_SOCKET.
221 log.OnAddEntry(NetLog::TYPE_SOCKET_ALIVE,
222 base::TimeTicks(),
223 socket_source,
224 NetLog::PHASE_BEGIN,
225 NULL);
226
227 EXPECT_EQ(0u, GetLiveRequests(log.url_request_tracker_).size());
228 EXPECT_EQ(1u, GetLiveRequests(log.socket_tracker_).size());
229
230 // Start a SOURCE_URL_REQUEST.
231 log.OnAddEntry(NetLog::TYPE_REQUEST_ALIVE,
232 base::TimeTicks(),
233 url_request_source,
234 NetLog::PHASE_BEGIN,
235 NULL);
236
237 // Check that there is no association between the SOURCE_URL_REQUEST and the
238 // SOURCE_SOCKET yet.
239 ASSERT_EQ(1u, GetLiveRequests(log.url_request_tracker_).size());
240 {
241 PassiveLogCollector::RequestInfo info =
242 GetLiveRequests(log.url_request_tracker_)[0];
243 EXPECT_EQ(0, info.reference_count);
244 EXPECT_EQ(0u, info.dependencies.size());
245 }
246 ASSERT_EQ(1u, GetLiveRequests(log.socket_tracker_).size());
247 {
248 PassiveLogCollector::RequestInfo info =
249 GetLiveRequests(log.socket_tracker_)[0];
250 EXPECT_EQ(0, info.reference_count);
251 EXPECT_EQ(0u, info.dependencies.size());
252 }
253
254 // Associate the SOURCE_SOCKET with the SOURCE_URL_REQUEST.
255 log.OnAddEntry(NetLog::TYPE_SOCKET_POOL_BOUND_TO_SOCKET,
256 base::TimeTicks(),
257 url_request_source,
258 NetLog::PHASE_NONE,
259 new net::NetLogSourceParameter("x", socket_source));
260
261 // Check that an associate was made -- the SOURCE_URL_REQUEST should have
262 // added a reference to the SOURCE_SOCKET.
263 ASSERT_EQ(1u, GetLiveRequests(log.url_request_tracker_).size());
264 {
265 PassiveLogCollector::RequestInfo info =
266 GetLiveRequests(log.url_request_tracker_)[0];
267 EXPECT_EQ(0, info.reference_count);
268 EXPECT_EQ(1u, info.dependencies.size());
269 EXPECT_EQ(socket_source.id, info.dependencies[0].id);
270 }
271 ASSERT_EQ(1u, GetLiveRequests(log.socket_tracker_).size());
272 {
273 PassiveLogCollector::RequestInfo info =
274 GetLiveRequests(log.socket_tracker_)[0];
275 EXPECT_EQ(1, info.reference_count);
276 EXPECT_EQ(0u, info.dependencies.size());
277 }
278
279 // Now end both |source_socket| and |source_url_request|. This sends them
280 // to deletion queue, and they will be deleted once space runs out.
281
282 log.OnAddEntry(NetLog::TYPE_REQUEST_ALIVE,
283 base::TimeTicks(),
284 url_request_source,
285 NetLog::PHASE_END,
286 NULL);
287
288 log.OnAddEntry(NetLog::TYPE_SOCKET_ALIVE,
289 base::TimeTicks(),
290 socket_source,
291 NetLog::PHASE_END,
292 NULL);
293
294 // Verify that both sources are in fact dead, and that |source_url_request|
295 // still holds a reference to |source_socket|.
296 ASSERT_EQ(0u, GetLiveRequests(log.url_request_tracker_).size());
297 ASSERT_EQ(1u, GetDeadRequests(log.url_request_tracker_).size());
298 {
299 PassiveLogCollector::RequestInfo info =
300 GetDeadRequests(log.url_request_tracker_)[0];
301 EXPECT_EQ(0, info.reference_count);
302 EXPECT_EQ(1u, info.dependencies.size());
303 EXPECT_EQ(socket_source.id, info.dependencies[0].id);
304 }
305 EXPECT_EQ(0u, GetLiveRequests(log.socket_tracker_).size());
306 ASSERT_EQ(1u, GetDeadRequests(log.socket_tracker_).size());
307 {
308 PassiveLogCollector::RequestInfo info =
309 GetDeadRequests(log.socket_tracker_)[0];
310 EXPECT_EQ(1, info.reference_count);
311 EXPECT_EQ(0u, info.dependencies.size());
312 }
313
314 // Cycle through a bunch of SOURCE_SOCKET -- if it were not referenced, this
315 // loop will have deleted it.
316 for (size_t i = 0; i < SocketTracker::kMaxGraveyardSize; ++i) {
317 log.OnAddEntry(NetLog::TYPE_SOCKET_ALIVE,
318 base::TimeTicks(),
319 NetLog::Source(NetLog::SOURCE_SOCKET, next_id++),
320 NetLog::PHASE_END,
321 NULL);
322 }
323
324 EXPECT_EQ(0u, GetLiveRequests(log.socket_tracker_).size());
325 ASSERT_EQ(SocketTracker::kMaxGraveyardSize + 1,
326 GetDeadRequests(log.socket_tracker_).size());
327 {
328 PassiveLogCollector::RequestInfo info =
329 GetDeadRequests(log.socket_tracker_)[0];
330 EXPECT_EQ(socket_source.id, info.source_id);
331 EXPECT_EQ(1, info.reference_count);
332 EXPECT_EQ(0u, info.dependencies.size());
333 }
334
335 // Cycle through a bunch of SOURCE_URL_REQUEST -- this will cause
336 // |source_url_request| to be freed, which in turn should release the final
337 // reference to |source_socket| cause it to be freed as well.
338 for (size_t i = 0; i < RequestTracker::kMaxGraveyardSize; ++i) {
339 log.OnAddEntry(NetLog::TYPE_REQUEST_ALIVE,
340 base::TimeTicks(),
341 NetLog::Source(NetLog::SOURCE_URL_REQUEST, next_id++),
342 NetLog::PHASE_END,
343 NULL);
344 }
345
346 EXPECT_EQ(0u, GetLiveRequests(log.url_request_tracker_).size());
347 EXPECT_EQ(RequestTracker::kMaxGraveyardSize,
348 GetDeadRequests(log.url_request_tracker_).size());
349
350 EXPECT_EQ(0u, GetLiveRequests(log.socket_tracker_).size());
351 EXPECT_EQ(SocketTracker::kMaxGraveyardSize,
352 GetDeadRequests(log.socket_tracker_).size());
353 }
OLDNEW
« no previous file with comments | « chrome/browser/net/passive_log_collector.cc ('k') | chrome/service/net/service_url_request_context.cc » ('j') | no next file with comments »

Powered by Google App Engine
This is Rietveld 408576698