| 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 |