OLD | NEW |
| (Empty) |
1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. | |
2 // Use of this source code is governed by a BSD-style license that can be | |
3 // found in the LICENSE file. | |
4 | |
5 #include "chrome/browser/net/load_timing_observer.h" | |
6 | |
7 #include "base/compiler_specific.h" | |
8 #include "base/format_macros.h" | |
9 #include "base/message_loop.h" | |
10 #include "base/stringprintf.h" | |
11 #include "base/time.h" | |
12 #include "content/public/test/test_browser_thread.h" | |
13 #include "net/base/load_flags.h" | |
14 #include "net/url_request/url_request_netlog_params.h" | |
15 #include "testing/gtest/include/gtest/gtest.h" | |
16 | |
17 namespace { | |
18 | |
19 using base::TimeDelta; | |
20 using content::BrowserThread; | |
21 using net::NetLog; | |
22 | |
23 class TestLoadTimingObserver : public LoadTimingObserver { | |
24 public: | |
25 TestLoadTimingObserver() {} | |
26 virtual ~TestLoadTimingObserver() {} | |
27 | |
28 void IncementTime(base::TimeDelta delta) { | |
29 current_time_ += delta; | |
30 } | |
31 | |
32 virtual base::TimeTicks GetCurrentTime() const OVERRIDE { | |
33 return current_time_; | |
34 } | |
35 | |
36 private: | |
37 base::TimeTicks current_time_; | |
38 | |
39 DISALLOW_COPY_AND_ASSIGN(TestLoadTimingObserver); | |
40 }; | |
41 | |
42 // Serves to identify the current thread as the IO thread. | |
43 class LoadTimingObserverTest : public testing::Test { | |
44 public: | |
45 LoadTimingObserverTest() : io_thread_(BrowserThread::IO, &message_loop_) { | |
46 } | |
47 | |
48 protected: | |
49 TestLoadTimingObserver observer_; | |
50 | |
51 private: | |
52 MessageLoop message_loop_; | |
53 content::TestBrowserThread io_thread_; | |
54 }; | |
55 | |
56 void AddStartEntry(LoadTimingObserver& observer, | |
57 const NetLog::Source& source, | |
58 NetLog::EventType type) { | |
59 net::NetLog::Entry entry(type, | |
60 source, | |
61 NetLog::PHASE_BEGIN, | |
62 base::TimeTicks::Now(), | |
63 NULL, | |
64 NetLog::LOG_BASIC); | |
65 observer.OnAddEntry(entry); | |
66 } | |
67 | |
68 void AddStartEntry(LoadTimingObserver& observer, | |
69 const NetLog::Source& source, | |
70 NetLog::EventType type, | |
71 const NetLog::ParametersCallback& params_callback) { | |
72 net::NetLog::Entry entry(type, | |
73 source, | |
74 NetLog::PHASE_BEGIN, | |
75 base::TimeTicks::Now(), | |
76 ¶ms_callback, | |
77 NetLog::LOG_BASIC); | |
78 observer.OnAddEntry(entry); | |
79 } | |
80 | |
81 void AddEndEntry(LoadTimingObserver& observer, | |
82 const NetLog::Source& source, | |
83 NetLog::EventType type) { | |
84 net::NetLog::Entry entry(type, | |
85 source, | |
86 NetLog::PHASE_END, | |
87 base::TimeTicks::Now(), | |
88 NULL, | |
89 NetLog::LOG_BASIC); | |
90 observer.OnAddEntry(entry); | |
91 } | |
92 | |
93 void AddStartURLRequestEntries(LoadTimingObserver& observer, | |
94 uint32 id, | |
95 bool request_timing) { | |
96 NetLog::Source source(NetLog::SOURCE_URL_REQUEST, id); | |
97 AddStartEntry(observer, source, NetLog::TYPE_REQUEST_ALIVE); | |
98 | |
99 GURL url(base::StringPrintf("http://req%d", id)); | |
100 std::string method = "GET"; | |
101 AddStartEntry( | |
102 observer, | |
103 source, | |
104 NetLog::TYPE_URL_REQUEST_START_JOB, | |
105 base::Bind(&net::NetLogURLRequestStartCallback, | |
106 &url, | |
107 &method, | |
108 request_timing ? net::LOAD_ENABLE_LOAD_TIMING : 0, | |
109 net::LOW, | |
110 -1)); | |
111 } | |
112 | |
113 void AddEndURLRequestEntries(LoadTimingObserver& observer, uint32 id) { | |
114 NetLog::Source source(NetLog::SOURCE_URL_REQUEST, id); | |
115 AddEndEntry(observer, source, NetLog::TYPE_REQUEST_ALIVE); | |
116 AddEndEntry(observer, source, NetLog::TYPE_URL_REQUEST_START_JOB); | |
117 } | |
118 | |
119 void AddStartHTTPStreamJobEntries(LoadTimingObserver& observer, uint32 id) { | |
120 NetLog::Source source(NetLog::SOURCE_HTTP_STREAM_JOB, id); | |
121 AddStartEntry(observer, source, NetLog::TYPE_HTTP_STREAM_JOB); | |
122 } | |
123 | |
124 void AddEndHTTPStreamJobEntries(LoadTimingObserver& observer, uint32 id) { | |
125 NetLog::Source source(NetLog::SOURCE_HTTP_STREAM_JOB, id); | |
126 AddEndEntry(observer, source, NetLog::TYPE_HTTP_STREAM_JOB); | |
127 } | |
128 | |
129 void AddStartConnectJobEntries(LoadTimingObserver& observer, uint32 id) { | |
130 NetLog::Source source(NetLog::SOURCE_CONNECT_JOB, id); | |
131 AddStartEntry(observer, source, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB); | |
132 } | |
133 | |
134 void AddEndConnectJobEntries(LoadTimingObserver& observer, uint32 id) { | |
135 NetLog::Source source(NetLog::SOURCE_CONNECT_JOB, id); | |
136 AddEndEntry(observer, source, NetLog::TYPE_SOCKET_POOL_CONNECT_JOB); | |
137 } | |
138 | |
139 void AddStartSocketEntries(LoadTimingObserver& observer, uint32 id) { | |
140 NetLog::Source source(NetLog::SOURCE_SOCKET, id); | |
141 AddStartEntry(observer, source, NetLog::TYPE_SOCKET_ALIVE); | |
142 } | |
143 | |
144 void AddEndSocketEntries(LoadTimingObserver& observer, uint32 id) { | |
145 NetLog::Source source(NetLog::SOURCE_SOCKET, id); | |
146 AddEndEntry(observer, source, NetLog::TYPE_SOCKET_ALIVE); | |
147 } | |
148 | |
149 void BindURLRequestToHTTPStreamJob(LoadTimingObserver& observer, | |
150 NetLog::Source url_request_source, | |
151 NetLog::Source http_stream_job_source) { | |
152 AddStartEntry(observer, | |
153 url_request_source, | |
154 NetLog::TYPE_HTTP_STREAM_REQUEST_BOUND_TO_JOB, | |
155 http_stream_job_source.ToEventParametersCallback()); | |
156 } | |
157 | |
158 void BindHTTPStreamJobToConnectJob(LoadTimingObserver& observer, | |
159 NetLog::Source& http_stream_job_source, | |
160 NetLog::Source& connect_source) { | |
161 AddStartEntry(observer, | |
162 http_stream_job_source, | |
163 NetLog::TYPE_SOCKET_POOL_BOUND_TO_CONNECT_JOB, | |
164 connect_source.ToEventParametersCallback()); | |
165 } | |
166 | |
167 void BindHTTPStreamJobToSocket(LoadTimingObserver& observer, | |
168 NetLog::Source& http_stream_job_source, | |
169 NetLog::Source& socket_source) { | |
170 AddStartEntry(observer, | |
171 http_stream_job_source, | |
172 NetLog::TYPE_SOCKET_POOL_BOUND_TO_SOCKET, | |
173 socket_source.ToEventParametersCallback()); | |
174 } | |
175 | |
176 } // namespace | |
177 | |
178 // Test that net::URLRequest with no load timing flag is not processed. | |
179 TEST_F(LoadTimingObserverTest, NoLoadTimingEnabled) { | |
180 AddStartURLRequestEntries(observer_, 0, false); | |
181 LoadTimingObserver::URLRequestRecord* record = | |
182 observer_.GetURLRequestRecord(0); | |
183 ASSERT_TRUE(record == NULL); | |
184 } | |
185 | |
186 // Test that URLRequestRecord is created, deleted and is not growing unbound. | |
187 TEST_F(LoadTimingObserverTest, URLRequestRecord) { | |
188 // Create record. | |
189 AddStartURLRequestEntries(observer_, 0, true); | |
190 LoadTimingObserver::URLRequestRecord* record = | |
191 observer_.GetURLRequestRecord(0); | |
192 ASSERT_FALSE(record == NULL); | |
193 | |
194 // Collect record. | |
195 AddEndURLRequestEntries(observer_, 0); | |
196 record = observer_.GetURLRequestRecord(0); | |
197 ASSERT_TRUE(record == NULL); | |
198 | |
199 // Check unbound growth. | |
200 for (size_t i = 1; i < 1100; ++i) | |
201 AddStartURLRequestEntries(observer_, i, true); | |
202 record = observer_.GetURLRequestRecord(1); | |
203 ASSERT_TRUE(record == NULL); | |
204 } | |
205 | |
206 // Test that HTTPStreamJobRecord is created, deleted and is not growing unbound. | |
207 TEST_F(LoadTimingObserverTest, HTTPStreamJobRecord) { | |
208 // Create record. | |
209 AddStartHTTPStreamJobEntries(observer_, 0); | |
210 ASSERT_FALSE(observer_.http_stream_job_to_record_.find(0) == | |
211 observer_.http_stream_job_to_record_.end()); | |
212 | |
213 // Collect record. | |
214 AddEndHTTPStreamJobEntries(observer_, 0); | |
215 ASSERT_TRUE(observer_.http_stream_job_to_record_.find(0) == | |
216 observer_.http_stream_job_to_record_.end()); | |
217 | |
218 // Check unbound growth. | |
219 for (size_t i = 1; i < 1100; ++i) | |
220 AddStartHTTPStreamJobEntries(observer_, i); | |
221 ASSERT_TRUE(observer_.http_stream_job_to_record_.find(1) == | |
222 observer_.http_stream_job_to_record_.end()); | |
223 } | |
224 | |
225 // Test that ConnectJobRecord is created, deleted and is not growing unbound. | |
226 TEST_F(LoadTimingObserverTest, ConnectJobRecord) { | |
227 // Create record. | |
228 AddStartConnectJobEntries(observer_, 0); | |
229 ASSERT_FALSE(observer_.connect_job_to_record_.find(0) == | |
230 observer_.connect_job_to_record_.end()); | |
231 | |
232 // Collect record. | |
233 AddEndConnectJobEntries(observer_, 0); | |
234 ASSERT_TRUE(observer_.connect_job_to_record_.find(0) == | |
235 observer_.connect_job_to_record_.end()); | |
236 | |
237 // Check unbound growth. | |
238 for (size_t i = 1; i < 1100; ++i) | |
239 AddStartConnectJobEntries(observer_, i); | |
240 ASSERT_TRUE(observer_.connect_job_to_record_.find(1) == | |
241 observer_.connect_job_to_record_.end()); | |
242 } | |
243 | |
244 // Test that SocketRecord is created, deleted and is not growing unbound. | |
245 TEST_F(LoadTimingObserverTest, SocketRecord) { | |
246 // Create record. | |
247 AddStartSocketEntries(observer_, 0); | |
248 ASSERT_FALSE(observer_.socket_to_record_.find(0) == | |
249 observer_.socket_to_record_.end()); | |
250 | |
251 // Collect record. | |
252 AddEndSocketEntries(observer_, 0); | |
253 ASSERT_TRUE(observer_.socket_to_record_.find(0) == | |
254 observer_.socket_to_record_.end()); | |
255 | |
256 // Check unbound growth. | |
257 for (size_t i = 1; i < 1100; ++i) | |
258 AddStartSocketEntries(observer_, i); | |
259 ASSERT_TRUE(observer_.socket_to_record_.find(1) == | |
260 observer_.socket_to_record_.end()); | |
261 } | |
262 | |
263 // Test that basic time is set to the request. | |
264 TEST_F(LoadTimingObserverTest, BaseTicks) { | |
265 observer_.IncementTime(TimeDelta::FromSeconds(1)); | |
266 AddStartURLRequestEntries(observer_, 0, true); | |
267 | |
268 LoadTimingObserver::URLRequestRecord* record = | |
269 observer_.GetURLRequestRecord(0); | |
270 ASSERT_EQ(1000000, record->base_ticks.ToInternalValue()); | |
271 } | |
272 | |
273 // Test proxy time detection. | |
274 TEST_F(LoadTimingObserverTest, ProxyTime) { | |
275 observer_.IncementTime(TimeDelta::FromSeconds(1)); | |
276 | |
277 AddStartURLRequestEntries(observer_, 0, true); | |
278 NetLog::Source source(NetLog::SOURCE_URL_REQUEST, 0); | |
279 | |
280 observer_.IncementTime(TimeDelta::FromSeconds(2)); | |
281 AddStartEntry(observer_, source, NetLog::TYPE_PROXY_SERVICE); | |
282 observer_.IncementTime(TimeDelta::FromSeconds(3)); | |
283 AddEndEntry(observer_, source, NetLog::TYPE_PROXY_SERVICE); | |
284 | |
285 LoadTimingObserver::URLRequestRecord* record = | |
286 observer_.GetURLRequestRecord(0); | |
287 ASSERT_EQ(2000, record->timing.proxy_start); | |
288 ASSERT_EQ(5000, record->timing.proxy_end); | |
289 } | |
290 | |
291 // Test connect time detection. | |
292 TEST_F(LoadTimingObserverTest, ConnectTime) { | |
293 observer_.IncementTime(TimeDelta::FromSeconds(1)); | |
294 | |
295 AddStartURLRequestEntries(observer_, 0, true); | |
296 NetLog::Source source(NetLog::SOURCE_URL_REQUEST, 0); | |
297 | |
298 NetLog::Source http_stream_job_source(NetLog::SOURCE_HTTP_STREAM_JOB, 1); | |
299 AddStartHTTPStreamJobEntries(observer_, 1); | |
300 | |
301 observer_.IncementTime(TimeDelta::FromSeconds(2)); | |
302 AddStartEntry(observer_, http_stream_job_source, NetLog::TYPE_SOCKET_POOL); | |
303 observer_.IncementTime(TimeDelta::FromSeconds(3)); | |
304 AddEndEntry(observer_, http_stream_job_source, NetLog::TYPE_SOCKET_POOL); | |
305 | |
306 BindURLRequestToHTTPStreamJob(observer_, source, http_stream_job_source); | |
307 | |
308 LoadTimingObserver::URLRequestRecord* record = | |
309 observer_.GetURLRequestRecord(0); | |
310 ASSERT_EQ(2000, record->timing.connect_start); | |
311 ASSERT_EQ(5000, record->timing.connect_end); | |
312 } | |
313 | |
314 // Test dns time detection. | |
315 TEST_F(LoadTimingObserverTest, DnsTime) { | |
316 // Start request. | |
317 NetLog::Source source(NetLog::SOURCE_URL_REQUEST, 0); | |
318 AddStartURLRequestEntries(observer_, 0, true); | |
319 observer_.IncementTime(TimeDelta::FromSeconds(1)); | |
320 | |
321 // Add resolver entry. | |
322 AddStartConnectJobEntries(observer_, 1); | |
323 NetLog::Source connect_source(NetLog::SOURCE_CONNECT_JOB, 1); | |
324 AddStartEntry(observer_, connect_source, NetLog::TYPE_HOST_RESOLVER_IMPL); | |
325 observer_.IncementTime(TimeDelta::FromSeconds(2)); | |
326 AddEndEntry(observer_, connect_source, NetLog::TYPE_HOST_RESOLVER_IMPL); | |
327 AddEndConnectJobEntries(observer_, 1); | |
328 | |
329 NetLog::Source http_stream_job_source(NetLog::SOURCE_HTTP_STREAM_JOB, 2); | |
330 AddStartHTTPStreamJobEntries(observer_, 2); | |
331 | |
332 BindHTTPStreamJobToConnectJob(observer_, http_stream_job_source, | |
333 connect_source); | |
334 BindURLRequestToHTTPStreamJob(observer_, source, http_stream_job_source); | |
335 | |
336 LoadTimingObserver::URLRequestRecord* record = | |
337 observer_.GetURLRequestRecord(0); | |
338 ASSERT_EQ(1000, record->timing.dns_start); | |
339 ASSERT_EQ(3000, record->timing.dns_end); | |
340 } | |
341 | |
342 // Test send time detection. | |
343 TEST_F(LoadTimingObserverTest, SendTime) { | |
344 // Start request. | |
345 NetLog::Source source(NetLog::SOURCE_URL_REQUEST, 0); | |
346 AddStartURLRequestEntries(observer_, 0, true); | |
347 observer_.IncementTime(TimeDelta::FromSeconds(2)); | |
348 | |
349 // Add send request entry. | |
350 AddStartEntry(observer_, source, NetLog::TYPE_HTTP_TRANSACTION_SEND_REQUEST); | |
351 observer_.IncementTime(TimeDelta::FromSeconds(5)); | |
352 AddEndEntry(observer_, source, NetLog::TYPE_HTTP_TRANSACTION_SEND_REQUEST); | |
353 | |
354 LoadTimingObserver::URLRequestRecord* record = | |
355 observer_.GetURLRequestRecord(0); | |
356 ASSERT_EQ(2000, record->timing.send_start); | |
357 ASSERT_EQ(7000, record->timing.send_end); | |
358 } | |
359 | |
360 // Test receive time detection. | |
361 TEST_F(LoadTimingObserverTest, ReceiveTime) { | |
362 // Start request. | |
363 NetLog::Source source(NetLog::SOURCE_URL_REQUEST, 0); | |
364 AddStartURLRequestEntries(observer_, 0, true); | |
365 observer_.IncementTime(TimeDelta::FromSeconds(2)); | |
366 | |
367 // Add send request entry. | |
368 AddStartEntry(observer_, source, NetLog::TYPE_HTTP_TRANSACTION_READ_HEADERS); | |
369 observer_.IncementTime(TimeDelta::FromSeconds(5)); | |
370 AddEndEntry(observer_, source, NetLog::TYPE_HTTP_TRANSACTION_READ_HEADERS); | |
371 | |
372 LoadTimingObserver::URLRequestRecord* record = | |
373 observer_.GetURLRequestRecord(0); | |
374 ASSERT_EQ(2000, record->timing.receive_headers_start); | |
375 ASSERT_EQ(7000, record->timing.receive_headers_end); | |
376 } | |
377 | |
378 // Test ssl time detection. | |
379 TEST_F(LoadTimingObserverTest, SslTime) { | |
380 // Start request. | |
381 NetLog::Source source(NetLog::SOURCE_URL_REQUEST, 0); | |
382 AddStartURLRequestEntries(observer_, 0, true); | |
383 observer_.IncementTime(TimeDelta::FromSeconds(1)); | |
384 | |
385 // Add resolver entry. | |
386 AddStartSocketEntries(observer_, 1); | |
387 NetLog::Source socket_source(NetLog::SOURCE_SOCKET, 1); | |
388 AddStartEntry(observer_, socket_source, NetLog::TYPE_SSL_CONNECT); | |
389 observer_.IncementTime(TimeDelta::FromSeconds(2)); | |
390 AddEndEntry(observer_, socket_source, NetLog::TYPE_SSL_CONNECT); | |
391 | |
392 NetLog::Source http_stream_job_source(NetLog::SOURCE_HTTP_STREAM_JOB, 2); | |
393 AddStartHTTPStreamJobEntries(observer_, 2); | |
394 | |
395 BindHTTPStreamJobToSocket(observer_, http_stream_job_source, socket_source); | |
396 BindURLRequestToHTTPStreamJob(observer_, source, http_stream_job_source); | |
397 | |
398 LoadTimingObserver::URLRequestRecord* record = | |
399 observer_.GetURLRequestRecord(0); | |
400 ASSERT_EQ(1000, record->timing.ssl_start); | |
401 ASSERT_EQ(3000, record->timing.ssl_end); | |
402 } | |
OLD | NEW |