net: Return LoadTiming information in the case of a cache hit.

If the request went over the wire before headers were returned,
return information about the last over the wire request.  Otherwise,
set send times to be when the cache entry was opened, and
receive_header_start to be when the headers were read.

BUG=239842

Review URL: https://chromiumcodereview.appspot.com/14625012

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@200356 0039d316-1c4b-4281-b951-d872f2087c98

14 files changed, 405 insertions, 104 deletions

diff --git a/net/http/http_cache_transaction.cc b/net/http/http_cache_transaction.cc
index 9559597..33bfd46 100644
--- a/net/http/http_cache_transaction.cc
+++ b/net/http/http_cache_transaction.cc
@@ -24,6 +24,7 @@
 #include "net/base/completion_callback.h"
 #include "net/base/io_buffer.h"
 #include "net/base/load_flags.h"
+#include "net/base/load_timing_info.h"
 #include "net/base/net_errors.h"
 #include "net/base/net_log.h"
 #include "net/base/upload_data_stream.h"
@@ -488,9 +489,21 @@ bool HttpCache::Transaction::GetLoadTimingInfo(
     LoadTimingInfo* load_timing_info) const {
   if (network_trans_)
     return network_trans_->GetLoadTimingInfo(load_timing_info);
-  // Don't modify |load_timing_info| when reading from the cache instead of the
-  // network.
-  return false;
+
+  if (old_network_trans_load_timing_) {
+    *load_timing_info = *old_network_trans_load_timing_;
+    return true;
+  }
+
+  if (first_cache_access_since_.is_null())
+    return false;
+
+  // If the cache entry was opened, return that time.
+  load_timing_info->send_start = first_cache_access_since_;
+  // This time doesn't make much sense when reading from the cache, so just use
+  // the same time as send_start.
+  load_timing_info->send_end = first_cache_access_since_;
+  return true;
 }
 
 void HttpCache::Transaction::SetPriority(RequestPriority priority) {
@@ -826,6 +839,9 @@ int HttpCache::Transaction::DoSendRequest() {
   if (rv != OK)
     return rv;
 
+  // Old load timing information, if any, is now obsolete.
+  old_network_trans_load_timing_.reset();
+
   ReportNetworkActionStart();
   next_state_ = STATE_SEND_REQUEST_COMPLETE;
   rv = network_trans_->Start(request_, io_callback_, net_log_);
@@ -907,7 +923,7 @@ int HttpCache::Transaction::DoSuccessfulSendRequest() {
     // the new response.
     UpdateTransactionPattern(PATTERN_NOT_COVERED);
     response_ = HttpResponseInfo();
-    network_trans_.reset();
+    ResetNetworkTransaction();
     new_response_ = NULL;
     next_state_ = STATE_SEND_REQUEST;
     return OK;
@@ -1259,13 +1275,13 @@ int HttpCache::Transaction::DoUpdateCachedResponseComplete(int result) {
     }
     // We no longer need the network transaction, so destroy it.
     final_upload_progress_ = network_trans_->GetUploadProgress();
-    network_trans_.reset();
+    ResetNetworkTransaction();
   } else if (entry_ && handling_206_ && truncated_ &&
              partial_->initial_validation()) {
     // We just finished the validation of a truncated entry, and the server
     // is willing to resume the operation. Now we go back and start serving
     // the first part to the user.
-    network_trans_.reset();
+    ResetNetworkTransaction();
     new_response_ = NULL;
     next_state_ = STATE_START_PARTIAL_CACHE_VALIDATION;
     partial_->SetRangeToStartDownload();
@@ -2170,7 +2186,8 @@ void HttpCache::Transaction::FailRangeRequest() {
 }
 
 int HttpCache::Transaction::SetupEntryForRead() {
-  network_trans_.reset();
+  if (network_trans_)
+    ResetNetworkTransaction();
   if (partial_.get()) {
     if (truncated_ || is_sparse_ || !invalid_range_) {
       // We are going to return the saved response headers to the caller, so
@@ -2319,7 +2336,7 @@ int HttpCache::Transaction::DoPartialNetworkReadCompleted(int result) {
 
   if (result == 0) {
     // We need to move on to the next range.
-    network_trans_.reset();
+    ResetNetworkTransaction();
     next_state_ = STATE_START_PARTIAL_CACHE_VALIDATION;
   }
   return result;
@@ -2561,4 +2578,13 @@ int HttpCache::Transaction::ResetCacheIOStart(int return_value) {
   return return_value;
 }
 
+void HttpCache::Transaction::ResetNetworkTransaction() {
+  DCHECK(!old_network_trans_load_timing_);
+  DCHECK(network_trans_);
+  LoadTimingInfo load_timing;
+  if (network_trans_->GetLoadTimingInfo(&load_timing))
+    old_network_trans_load_timing_.reset(new LoadTimingInfo(load_timing));
+  network_trans_.reset();
+}
+
 }  // namespace net
diff --git a/net/http/http_cache_transaction.h b/net/http/http_cache_transaction.h
index a5ddfcd..0e1ae7f 100644
--- a/net/http/http_cache_transaction.h
+++ b/net/http/http_cache_transaction.h
@@ -24,6 +24,7 @@ namespace net {
 class PartialData;
 struct HttpRequestInfo;
 class HttpTransactionDelegate;
+struct LoadTimingInfo;
 
 // This is the transaction that is returned by the HttpCache transaction
 // factory.
@@ -385,6 +386,10 @@ class HttpCache::Transaction : public HttpTransaction {
   void RunDelayedLoop(base::TimeTicks delay_start_time,
                       base::TimeDelta intended_delay, int result);
 
+  // Resets |network_trans_|, which must be non-NULL.  Also updates
+  // |old_network_trans_load_timing_|, which must be NULL when this is called.
+  void ResetNetworkTransaction();
+
   State next_state_;
   const HttpRequestInfo* request_;
   RequestPriority priority_;
@@ -447,6 +452,11 @@ class HttpCache::Transaction : public HttpTransaction {
   int sensitivity_analysis_percent_increase_;
 
   HttpTransactionDelegate* transaction_delegate_;
+
+  // Load timing information for the last network request, if any.  Set in the
+  // 304 and 206 response cases, as the network transaction may be destroyed
+  // before the caller requests load timing information.
+  scoped_ptr<LoadTimingInfo> old_network_trans_load_timing_;
 };
 
 }  // namespace net
diff --git a/net/http/http_cache_unittest.cc b/net/http/http_cache_unittest.cc
index 19c690c..113359c 100644
--- a/net/http/http_cache_unittest.cc
+++ b/net/http/http_cache_unittest.cc
@@ -13,6 +13,8 @@
 #include "net/base/cache_type.h"
 #include "net/base/host_port_pair.h"
 #include "net/base/load_flags.h"
+#include "net/base/load_timing_info.h"
+#include "net/base/load_timing_info_test_util.h"
 #include "net/base/net_errors.h"
 #include "net/base/net_log_unittest.h"
 #include "net/base/upload_bytes_element_reader.h"
@@ -36,6 +38,49 @@ using base::Time;
 
 namespace {
 
+// Tests the load timing values of a request that goes through a
+// MockNetworkTransaction.
+void TestLoadTimingNetworkRequest(const net::LoadTimingInfo& load_timing_info) {
+  EXPECT_FALSE(load_timing_info.socket_reused);
+  EXPECT_NE(net::NetLog::Source::kInvalidId, load_timing_info.socket_log_id);
+
+  EXPECT_TRUE(load_timing_info.proxy_resolve_start.is_null());
+  EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null());
+
+  net::ExpectConnectTimingHasTimes(load_timing_info.connect_timing,
+                                   net::CONNECT_TIMING_HAS_CONNECT_TIMES_ONLY);
+  EXPECT_LE(load_timing_info.connect_timing.connect_end,
+            load_timing_info.send_start);
+
+  EXPECT_LE(load_timing_info.send_start, load_timing_info.send_end);
+
+  // Set by URLRequest / URLRequestHttpJob, at a higher level.
+  EXPECT_TRUE(load_timing_info.request_start_time.is_null());
+  EXPECT_TRUE(load_timing_info.request_start.is_null());
+  EXPECT_TRUE(load_timing_info.receive_headers_end.is_null());
+}
+
+// Tests the load timing values of a request that receives a cached response.
+void TestLoadTimingCachedResponse(const net::LoadTimingInfo& load_timing_info) {
+  EXPECT_FALSE(load_timing_info.socket_reused);
+  EXPECT_EQ(net::NetLog::Source::kInvalidId, load_timing_info.socket_log_id);
+
+  EXPECT_TRUE(load_timing_info.proxy_resolve_start.is_null());
+  EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null());
+
+  net::ExpectConnectTimingHasNoTimes(load_timing_info.connect_timing);
+
+  // Only the send start / end times should be sent, and they should have the
+  // same value.
+  EXPECT_FALSE(load_timing_info.send_start.is_null());
+  EXPECT_EQ(load_timing_info.send_start, load_timing_info.send_end);
+
+  // Set by URLRequest / URLRequestHttpJob, at a higher level.
+  EXPECT_TRUE(load_timing_info.request_start_time.is_null());
+  EXPECT_TRUE(load_timing_info.request_start.is_null());
+  EXPECT_TRUE(load_timing_info.receive_headers_end.is_null());
+}
+
 class DeleteCacheCompletionCallback : public net::TestCompletionCallbackBase {
  public:
   explicit DeleteCacheCompletionCallback(MockHttpCache* cache)
@@ -127,14 +172,15 @@ void ReadAndVerifyTransaction(net::HttpTransaction* trans,
 
 const int kNoDelegateTransactionCheck = -1;
 
-void RunTransactionTestWithRequestAndLogAndDelegate(
+void RunTransactionTestWithRequestAndDelegateAndGetTiming(
     net::HttpCache* cache,
     const MockTransaction& trans_info,
     const MockHttpRequest& request,
     net::HttpResponseInfo* response_info,
-    const net::BoundNetLog& net_log,
     int num_cache_delegate_actions,
-    int num_network_delegate_actions) {
+    int num_network_delegate_actions,
+    const net::BoundNetLog& net_log,
+    net::LoadTimingInfo* load_timing_info) {
   net::TestCompletionCallback callback;
 
   // write to the cache
@@ -166,38 +212,61 @@ void RunTransactionTestWithRequestAndLogAndDelegate(
   if (response_info)
     *response_info = *response;
 
+  if (load_timing_info) {
+    // If a fake network connection is used, need a NetLog to get a fake socket
+    // ID.
+    EXPECT_TRUE(net_log.net_log());
+    *load_timing_info = net::LoadTimingInfo();
+    trans->GetLoadTimingInfo(load_timing_info);
+  }
+
   ReadAndVerifyTransaction(trans.get(), trans_info);
 }
 
+void RunTransactionTestWithRequestAndDelegate(
+    net::HttpCache* cache,
+    const MockTransaction& trans_info,
+    const MockHttpRequest& request,
+    net::HttpResponseInfo* response_info,
+    int num_cache_delegate_actions,
+    int num_network_delegate_actions) {
+  RunTransactionTestWithRequestAndDelegateAndGetTiming(
+      cache, trans_info, request, response_info, num_cache_delegate_actions,
+      num_network_delegate_actions, net::BoundNetLog(), NULL);
+}
+
 void RunTransactionTestWithRequest(net::HttpCache* cache,
                                    const MockTransaction& trans_info,
                                    const MockHttpRequest& request,
                                    net::HttpResponseInfo* response_info) {
-  RunTransactionTestWithRequestAndLogAndDelegate(
-      cache, trans_info, request, response_info, net::BoundNetLog(),
-      kNoDelegateTransactionCheck, kNoDelegateTransactionCheck);
+  RunTransactionTestWithRequestAndDelegate(
+      cache, trans_info, request, response_info, kNoDelegateTransactionCheck,
+      kNoDelegateTransactionCheck);
 }
 
-void RunTransactionTestWithLog(net::HttpCache* cache,
-                               const MockTransaction& trans_info,
-                               const net::BoundNetLog& log) {
-  RunTransactionTestWithRequestAndLogAndDelegate(
-      cache, trans_info, MockHttpRequest(trans_info), NULL, log,
-      kNoDelegateTransactionCheck, kNoDelegateTransactionCheck);
+void RunTransactionTestAndGetTiming(
+    net::HttpCache* cache,
+    const MockTransaction& trans_info,
+    const net::BoundNetLog& log,
+    net::LoadTimingInfo* load_timing_info) {
+  RunTransactionTestWithRequestAndDelegateAndGetTiming(
+      cache, trans_info, MockHttpRequest(trans_info), NULL,
+      kNoDelegateTransactionCheck, kNoDelegateTransactionCheck, log,
+      load_timing_info);
 }
 
 void RunTransactionTestWithDelegate(net::HttpCache* cache,
                                     const MockTransaction& trans_info,
                                     int num_cache_delegate_actions,
                                     int num_network_delegate_actions) {
-  RunTransactionTestWithRequestAndLogAndDelegate(
-      cache, trans_info, MockHttpRequest(trans_info), NULL, net::BoundNetLog(),
+  RunTransactionTestWithRequestAndDelegate(
+      cache, trans_info, MockHttpRequest(trans_info), NULL,
       num_cache_delegate_actions, num_network_delegate_actions);
 }
 
 void RunTransactionTest(net::HttpCache* cache,
                         const MockTransaction& trans_info) {
-  RunTransactionTestWithLog(cache, trans_info, net::BoundNetLog());
+  RunTransactionTestAndGetTiming(cache, trans_info, net::BoundNetLog(), NULL);
 }
 
 void RunTransactionTestWithResponseInfo(net::HttpCache* cache,
@@ -207,6 +276,18 @@ void RunTransactionTestWithResponseInfo(net::HttpCache* cache,
       cache, trans_info, MockHttpRequest(trans_info), response);
 }
 
+void RunTransactionTestWithResponseInfoAndGetTiming(
+    net::HttpCache* cache,
+    const MockTransaction& trans_info,
+    net::HttpResponseInfo* response,
+    const net::BoundNetLog& log,
+    net::LoadTimingInfo* load_timing_info) {
+  RunTransactionTestWithRequestAndDelegateAndGetTiming(
+      cache, trans_info, MockHttpRequest(trans_info), response,
+      kNoDelegateTransactionCheck, kNoDelegateTransactionCheck, log,
+      load_timing_info);
+}
+
 void RunTransactionTestWithResponse(net::HttpCache* cache,
                                     const MockTransaction& trans_info,
                                     std::string* response_headers) {
@@ -215,6 +296,20 @@ void RunTransactionTestWithResponse(net::HttpCache* cache,
   response.headers->GetNormalizedHeaders(response_headers);
 }
 
+void RunTransactionTestWithResponseAndGetTiming(
+    net::HttpCache* cache,
+    const MockTransaction& trans_info,
+    std::string* response_headers,
+    const net::BoundNetLog& log,
+    net::LoadTimingInfo* load_timing_info) {
+  net::HttpResponseInfo response;
+  RunTransactionTestWithRequestAndDelegateAndGetTiming(
+      cache, trans_info, MockHttpRequest(trans_info), &response,
+      kNoDelegateTransactionCheck, kNoDelegateTransactionCheck,
+      log, load_timing_info);
+  response.headers->GetNormalizedHeaders(response_headers);
+}
+
 // This class provides a handler for kFastNoStoreGET_Transaction so that the
 // no-store header can be included on demand.
 class FastTransactionServer {
@@ -507,13 +602,17 @@ TEST(HttpCache, GetBackend) {
 
 TEST(HttpCache, SimpleGET) {
   MockHttpCache cache;
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
 
-  // write to the cache
-  RunTransactionTest(cache.http_cache(), kSimpleGET_Transaction);
+  // Write to the cache.
+  RunTransactionTestAndGetTiming(cache.http_cache(), kSimpleGET_Transaction,
+                                 log.bound(), &load_timing_info);
 
   EXPECT_EQ(1, cache.network_layer()->transaction_count());
   EXPECT_EQ(0, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 }
 
 TEST(HttpCache, SimpleGETNoDiskCache) {
@@ -523,10 +622,11 @@ TEST(HttpCache, SimpleGETNoDiskCache) {
 
   net::CapturingBoundNetLog log;
   log.SetLogLevel(net::NetLog::LOG_BASIC);
+  net::LoadTimingInfo load_timing_info;
 
   // Read from the network, and don't use the cache.
-  RunTransactionTestWithLog(cache.http_cache(), kSimpleGET_Transaction,
-                            log.bound());
+  RunTransactionTestAndGetTiming(cache.http_cache(), kSimpleGET_Transaction,
+                                 log.bound(), &load_timing_info);
 
   // Check that the NetLog was filled as expected.
   // (We attempted to both Open and Create entries, but both failed).
@@ -550,6 +650,7 @@ TEST(HttpCache, SimpleGETNoDiskCache) {
   EXPECT_EQ(1, cache.network_layer()->transaction_count());
   EXPECT_EQ(0, cache.disk_cache()->open_count());
   EXPECT_EQ(0, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 }
 
 TEST(HttpCache, SimpleGETNoDiskCache2) {
@@ -694,9 +795,11 @@ TEST(HttpCache, SimpleGET_LoadOnlyFromCache_Hit) {
   // This prevents a number of write events from being logged.
   log.SetLogLevel(net::NetLog::LOG_BASIC);
 
-  // write to the cache
-  RunTransactionTestWithLog(cache.http_cache(), kSimpleGET_Transaction,
-                            log.bound());
+  net::LoadTimingInfo load_timing_info;
+
+  // Write to the cache.
+  RunTransactionTestAndGetTiming(cache.http_cache(), kSimpleGET_Transaction,
+                                 log.bound(), &load_timing_info);
 
   // Check that the NetLog was filled as expected.
   net::CapturingNetLog::CapturedEntryList entries;
@@ -720,13 +823,16 @@ TEST(HttpCache, SimpleGET_LoadOnlyFromCache_Hit) {
   EXPECT_TRUE(net::LogContainsEndEvent(
       entries, 7, net::NetLog::TYPE_HTTP_CACHE_ADD_TO_ENTRY));
 
-  // force this transaction to read from the cache
+  TestLoadTimingNetworkRequest(load_timing_info);
+
+  // Force this transaction to read from the cache.
   MockTransaction transaction(kSimpleGET_Transaction);
   transaction.load_flags |= net::LOAD_ONLY_FROM_CACHE;
 
   log.Clear();
 
-  RunTransactionTestWithLog(cache.http_cache(), transaction, log.bound());
+  RunTransactionTestAndGetTiming(cache.http_cache(), transaction, log.bound(),
+                                 &load_timing_info);
 
   // Check that the NetLog was filled as expected.
   log.GetEntries(&entries);
@@ -752,6 +858,7 @@ TEST(HttpCache, SimpleGET_LoadOnlyFromCache_Hit) {
   EXPECT_EQ(1, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingCachedResponse(load_timing_info);
 }
 
 TEST(HttpCache, SimpleGET_LoadOnlyFromCache_Miss) {
@@ -851,11 +958,15 @@ TEST(HttpCache, SimpleGET_LoadPreferringCache_VaryMismatch) {
   // the network again.
   transaction.load_flags |= net::LOAD_PREFERRING_CACHE;
   transaction.request_headers = "Foo: none\r\n";
-  RunTransactionTest(cache.http_cache(), transaction);
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
+  RunTransactionTestAndGetTiming(cache.http_cache(), transaction, log.bound(),
+                                 &load_timing_info);
 
   EXPECT_EQ(2, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
   RemoveMockTransaction(&transaction);
 }
 
@@ -1013,8 +1124,11 @@ TEST(HttpCache, SimpleGET_LoadBypassCache) {
 
   // This prevents a number of write events from being logged.
   log.SetLogLevel(net::NetLog::LOG_BASIC);
+  net::LoadTimingInfo load_timing_info;
 
-  RunTransactionTestWithLog(cache.http_cache(), transaction, log.bound());
+  // Write to the cache.
+  RunTransactionTestAndGetTiming(cache.http_cache(), transaction, log.bound(),
+                                 &load_timing_info);
 
   // Check that the NetLog was filled as expected.
   net::CapturingNetLog::CapturedEntryList entries;
@@ -1041,6 +1155,7 @@ TEST(HttpCache, SimpleGET_LoadBypassCache) {
   EXPECT_EQ(2, cache.network_layer()->transaction_count());
   EXPECT_EQ(0, cache.disk_cache()->open_count());
   EXPECT_EQ(2, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 }
 
 TEST(HttpCache, SimpleGET_LoadBypassCache_Implicit) {
@@ -1080,24 +1195,28 @@ TEST(HttpCache, SimpleGET_LoadBypassCache_Implicit2) {
 TEST(HttpCache, SimpleGET_LoadValidateCache) {
   MockHttpCache cache;
 
-  // write to the cache
+  // Write to the cache.
   RunTransactionTest(cache.http_cache(), kSimpleGET_Transaction);
 
-  // read from the cache
+  // Read from the cache.
   RunTransactionTest(cache.http_cache(), kSimpleGET_Transaction);
 
-  // force this transaction to validate the cache
+  // Force this transaction to validate the cache.
   MockTransaction transaction(kSimpleGET_Transaction);
   transaction.load_flags |= net::LOAD_VALIDATE_CACHE;
 
   net::HttpResponseInfo response_info;
-  RunTransactionTestWithResponseInfo(cache.http_cache(), transaction,
-                                     &response_info);
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
+  RunTransactionTestWithResponseInfoAndGetTiming(
+      cache.http_cache(), transaction, &response_info, log.bound(),
+      &load_timing_info);
 
   EXPECT_EQ(2, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
   EXPECT_TRUE(response_info.network_accessed);
+  TestLoadTimingNetworkRequest(load_timing_info);
 }
 
 TEST(HttpCache, SimpleGET_LoadValidateCache_Implicit) {
@@ -1866,13 +1985,17 @@ TEST(HttpCache, TypicalGET_ConditionalRequest) {
   EXPECT_EQ(0, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
 
-  // get the same URL again, but this time we expect it to result
+  // Get the same URL again, but this time we expect it to result
   // in a conditional request.
-  RunTransactionTest(cache.http_cache(), kTypicalGET_Transaction);
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
+  RunTransactionTestAndGetTiming(cache.http_cache(), kTypicalGET_Transaction,
+                                 log.bound(), &load_timing_info);
 
   EXPECT_EQ(2, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 }
 
 static void ETagGet_ConditionalRequest_Handler(
@@ -1899,15 +2022,19 @@ TEST(HttpCache, ETagGET_ConditionalRequest_304) {
   EXPECT_EQ(0, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
 
-  // get the same URL again, but this time we expect it to result
+  // Get the same URL again, but this time we expect it to result
   // in a conditional request.
   transaction.load_flags = net::LOAD_VALIDATE_CACHE;
   transaction.handler = ETagGet_ConditionalRequest_Handler;
-  RunTransactionTest(cache.http_cache(), transaction);
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
+  RunTransactionTestAndGetTiming(cache.http_cache(), transaction, log.bound(),
+                                 &load_timing_info);
 
   EXPECT_EQ(2, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 }
 
 class RevalidationServer {
@@ -1974,13 +2101,17 @@ TEST(HttpCache, SimpleGET_LoadValidateCache_VaryMatch) {
   // Read from the cache.
   RevalidationServer server;
   transaction.handler = server.Handler;
-  RunTransactionTest(cache.http_cache(), transaction);
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
+  RunTransactionTestAndGetTiming(cache.http_cache(), transaction, log.bound(),
+                                 &load_timing_info);
 
   EXPECT_TRUE(server.EtagUsed());
   EXPECT_TRUE(server.LastModifiedUsed());
   EXPECT_EQ(2, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
   RemoveMockTransaction(&transaction);
 }
 
@@ -2004,13 +2135,17 @@ TEST(HttpCache, SimpleGET_LoadValidateCache_VaryMismatch) {
   RevalidationServer server;
   transaction.handler = server.Handler;
   transaction.request_headers = "Foo: none\r\n";
-  RunTransactionTest(cache.http_cache(), transaction);
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
+  RunTransactionTestAndGetTiming(cache.http_cache(), transaction, log.bound(),
+                                 &load_timing_info);
 
   EXPECT_TRUE(server.EtagUsed());
   EXPECT_FALSE(server.LastModifiedUsed());
   EXPECT_EQ(2, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
   RemoveMockTransaction(&transaction);
 }
 
@@ -2033,13 +2168,17 @@ TEST(HttpCache, SimpleGET_LoadDontValidateCache_VaryMismatch) {
   RevalidationServer server;
   transaction.handler = server.Handler;
   transaction.request_headers = "Foo: none\r\n";
-  RunTransactionTest(cache.http_cache(), transaction);
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
+  RunTransactionTestAndGetTiming(cache.http_cache(), transaction, log.bound(),
+                                 &load_timing_info);
 
   EXPECT_FALSE(server.EtagUsed());
   EXPECT_FALSE(server.LastModifiedUsed());
   EXPECT_EQ(2, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
   RemoveMockTransaction(&transaction);
 }
 
@@ -3240,12 +3379,17 @@ TEST(HttpCache, RangeGET_OK) {
   // Write and read from the cache (20-59).
   transaction.request_headers = "Range: bytes = 20-59\r\n" EXTRA_HEADER;
   transaction.data = "rg: 20-29 rg: 30-39 rg: 40-49 rg: 50-59 ";
-  RunTransactionTestWithResponse(cache.http_cache(), transaction, &headers);
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
+  RunTransactionTestWithResponseAndGetTiming(
+      cache.http_cache(), transaction, &headers, log.bound(),
+      &load_timing_info);
 
   Verify206Response(headers, 20, 59);
   EXPECT_EQ(4, cache.network_layer()->transaction_count());
   EXPECT_EQ(3, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 
   RemoveMockTransaction(&kRangeGET_TransactionOK);
 }
@@ -3295,12 +3439,17 @@ TEST(HttpCache, RangeGET_SyncOK) {
   // Write and read from the cache (20-59).
   transaction.request_headers = "Range: bytes = 20-59\r\n" EXTRA_HEADER;
   transaction.data = "rg: 20-29 rg: 30-39 rg: 40-49 rg: 50-59 ";
-  RunTransactionTestWithResponse(cache.http_cache(), transaction, &headers);
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
+  RunTransactionTestWithResponseAndGetTiming(
+      cache.http_cache(), transaction, &headers, log.bound(),
+      &load_timing_info);
 
   Verify206Response(headers, 20, 59);
   EXPECT_EQ(4, cache.network_layer()->transaction_count());
   EXPECT_EQ(2, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 
   RemoveMockTransaction(&transaction);
 }
@@ -3327,21 +3476,29 @@ TEST(HttpCache, RangeGET_Revalidate1) {
   EXPECT_EQ(1, cache.disk_cache()->create_count());
 
   // Read from the cache (40-49).
-  RunTransactionTestWithResponse(cache.http_cache(), transaction, &headers);
-  Verify206Response(headers, 40, 49);
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
+  RunTransactionTestWithResponseAndGetTiming(
+      cache.http_cache(), transaction, &headers, log.bound(),
+      &load_timing_info);
 
+  Verify206Response(headers, 40, 49);
   EXPECT_EQ(1, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingCachedResponse(load_timing_info);
 
   // Read again forcing the revalidation.
   transaction.load_flags |= net::LOAD_VALIDATE_CACHE;
-  RunTransactionTestWithResponse(cache.http_cache(), transaction, &headers);
+  RunTransactionTestWithResponseAndGetTiming(
+      cache.http_cache(), transaction, &headers, log.bound(),
+      &load_timing_info);
 
   Verify206Response(headers, 40, 49);
   EXPECT_EQ(2, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 
   RemoveMockTransaction(&transaction);
 }
@@ -3576,27 +3733,34 @@ TEST(HttpCache, GET_Previous206) {
   MockHttpCache cache;
   AddMockTransaction(&kRangeGET_TransactionOK);
   std::string headers;
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
 
   // Write to the cache (40-49).
-  RunTransactionTestWithResponse(cache.http_cache(), kRangeGET_TransactionOK,
-                                 &headers);
+  RunTransactionTestWithResponseAndGetTiming(
+      cache.http_cache(), kRangeGET_TransactionOK, &headers, log.bound(),
+      &load_timing_info);
 
   Verify206Response(headers, 40, 49);
   EXPECT_EQ(1, cache.network_layer()->transaction_count());
   EXPECT_EQ(0, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 
   // Write and read from the cache (0-79), when not asked for a range.
   MockTransaction transaction(kRangeGET_TransactionOK);
   transaction.request_headers = EXTRA_HEADER;
   transaction.data = "rg: 00-09 rg: 10-19 rg: 20-29 rg: 30-39 rg: 40-49 "
                      "rg: 50-59 rg: 60-69 rg: 70-79 ";
-  RunTransactionTestWithResponse(cache.http_cache(), transaction, &headers);
+  RunTransactionTestWithResponseAndGetTiming(
+      cache.http_cache(), transaction, &headers, log.bound(),
+      &load_timing_info);
 
   EXPECT_EQ(0U, headers.find("HTTP/1.1 200 OK\n"));
   EXPECT_EQ(3, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 
   RemoveMockTransaction(&kRangeGET_TransactionOK);
 }
@@ -3609,34 +3773,45 @@ TEST(HttpCache, GET_Previous206_NotModified) {
   MockTransaction transaction(kRangeGET_TransactionOK);
   AddMockTransaction(&transaction);
   std::string headers;
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
 
   // Write to the cache (0-9).
   transaction.request_headers = "Range: bytes = 0-9\r\n" EXTRA_HEADER;
   transaction.data = "rg: 00-09 ";
-  RunTransactionTestWithResponse(cache.http_cache(), transaction, &headers);
+  RunTransactionTestWithResponseAndGetTiming(
+      cache.http_cache(), transaction, &headers, log.bound(),
+      &load_timing_info);
   Verify206Response(headers, 0, 9);
+  TestLoadTimingNetworkRequest(load_timing_info);
 
   // Write to the cache (70-79).
   transaction.request_headers = "Range: bytes = 70-79\r\n" EXTRA_HEADER;
   transaction.data = "rg: 70-79 ";
-  RunTransactionTestWithResponse(cache.http_cache(), transaction, &headers);
+  RunTransactionTestWithResponseAndGetTiming(
+      cache.http_cache(), transaction, &headers, log.bound(),
+      &load_timing_info);
   Verify206Response(headers, 70, 79);
 
   EXPECT_EQ(2, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 
   // Read from the cache (0-9), write and read from cache (10 - 79).
   transaction.load_flags |= net::LOAD_VALIDATE_CACHE;
   transaction.request_headers = "Foo: bar\r\n" EXTRA_HEADER;
   transaction.data = "rg: 00-09 rg: 10-19 rg: 20-29 rg: 30-39 rg: 40-49 "
-                      "rg: 50-59 rg: 60-69 rg: 70-79 ";
-  RunTransactionTestWithResponse(cache.http_cache(), transaction, &headers);
+                     "rg: 50-59 rg: 60-69 rg: 70-79 ";
+  RunTransactionTestWithResponseAndGetTiming(
+      cache.http_cache(), transaction, &headers, log.bound(),
+      &load_timing_info);
 
   EXPECT_EQ(0U, headers.find("HTTP/1.1 200 OK\n"));
   EXPECT_EQ(4, cache.network_layer()->transaction_count());
   EXPECT_EQ(2, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 
   RemoveMockTransaction(&transaction);
 }
@@ -3669,12 +3844,17 @@ TEST(HttpCache, GET_Previous206_NewContent) {
   transaction2.data = "Not a range";
   RangeTransactionServer handler;
   handler.set_modified(true);
-  RunTransactionTestWithResponse(cache.http_cache(), transaction2, &headers);
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
+  RunTransactionTestWithResponseAndGetTiming(
+      cache.http_cache(), transaction2, &headers, log.bound(),
+      &load_timing_info);
 
   EXPECT_EQ(0U, headers.find("HTTP/1.1 200 OK\n"));
   EXPECT_EQ(3, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 
   // Verify that the previous request deleted the entry.
   RunTransactionTest(cache.http_cache(), transaction);
@@ -3712,8 +3892,11 @@ TEST(HttpCache, GET_Previous206_NotSparse) {
 
   // Now see that we don't use the stored entry.
   std::string headers;
-  RunTransactionTestWithResponse(cache.http_cache(), kSimpleGET_Transaction,
-                                 &headers);
+  net::CapturingBoundNetLog log;
+  net::LoadTimingInfo load_timing_info;
+  RunTransactionTestWithResponseAndGetTiming(
+      cache.http_cache(), kSimpleGET_Transaction, &headers, log.bound(),
+      &load_timing_info);
 
   // We are expecting a 200.
   std::string expected_headers(kSimpleGET_Transaction.status);
@@ -3723,6 +3906,7 @@ TEST(HttpCache, GET_Previous206_NotSparse) {
   EXPECT_EQ(1, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(2, cache.disk_cache()->create_count());
+  TestLoadTimingNetworkRequest(load_timing_info);
 }
 
 // Tests that we can handle cached 206 responses that are not sparse. This time
diff --git a/net/http/http_network_transaction.cc b/net/http/http_network_transaction.cc
index 9fba93b..e111e41 100644
--- a/net/http/http_network_transaction.cc
+++ b/net/http/http_network_transaction.cc
@@ -397,7 +397,6 @@ bool HttpNetworkTransaction::GetLoadTimingInfo(
   load_timing_info->proxy_resolve_end = proxy_info_.proxy_resolve_end_time();
   load_timing_info->send_start = send_start_time_;
   load_timing_info->send_end = send_end_time_;
-  load_timing_info->receive_headers_end = receive_headers_end_;
   return true;
 }
 
@@ -846,8 +845,6 @@ int HttpNetworkTransaction::HandleConnectionClosedBeforeEndOfHeaders() {
 }
 
 int HttpNetworkTransaction::DoReadHeadersComplete(int result) {
-  receive_headers_end_ = base::TimeTicks::Now();
-
   // We can get a certificate error or ERR_SSL_CLIENT_AUTH_CERT_NEEDED here
   // due to SSL renegotiation.
   if (IsCertificateError(result)) {
@@ -1308,7 +1305,6 @@ void HttpNetworkTransaction::ResetStateForRestart() {
 void HttpNetworkTransaction::ResetStateForAuthRestart() {
   send_start_time_ = base::TimeTicks();
   send_end_time_ = base::TimeTicks();
-  receive_headers_end_ = base::TimeTicks();
 
   pending_auth_target_ = HttpAuth::AUTH_NONE;
   read_buf_ = NULL;
diff --git a/net/http/http_network_transaction.h b/net/http/http_network_transaction.h
index a98778d..23c8e67 100644
--- a/net/http/http_network_transaction.h
+++ b/net/http/http_network_transaction.h
@@ -301,9 +301,6 @@ class NET_EXPORT_PRIVATE HttpNetworkTransaction
   base::TimeTicks send_start_time_;
   base::TimeTicks send_end_time_;
 
-  // When the transaction finished reading the request headers.
-  base::TimeTicks receive_headers_end_;
-
   // The next state in the state machine.
   State next_state_;
 
diff --git a/net/http/http_network_transaction_spdy2_unittest.cc b/net/http/http_network_transaction_spdy2_unittest.cc
index 1b8b8bf..42eea1a 100644
--- a/net/http/http_network_transaction_spdy2_unittest.cc
+++ b/net/http/http_network_transaction_spdy2_unittest.cc
@@ -147,11 +147,11 @@ void TestLoadTimingReused(const net::LoadTimingInfo& load_timing_info) {
   EXPECT_FALSE(load_timing_info.send_start.is_null());
 
   EXPECT_LE(load_timing_info.send_start, load_timing_info.send_end);
-  EXPECT_LE(load_timing_info.send_end, load_timing_info.receive_headers_end);
 
-  // Set by URLRequest, at a higher level.
+  // Set at a higher level.
   EXPECT_TRUE(load_timing_info.request_start_time.is_null());
   EXPECT_TRUE(load_timing_info.request_start.is_null());
+  EXPECT_TRUE(load_timing_info.receive_headers_end.is_null());
 }
 
 // Tests LoadTimingInfo in the case a new socket is used and no PAC script is
@@ -165,16 +165,16 @@ void TestLoadTimingNotReused(const net::LoadTimingInfo& load_timing_info,
   EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null());
 
   net::ExpectConnectTimingHasTimes(load_timing_info.connect_timing,
-                                    connect_timing_flags);
+                                   connect_timing_flags);
   EXPECT_LE(load_timing_info.connect_timing.connect_end,
             load_timing_info.send_start);
 
   EXPECT_LE(load_timing_info.send_start, load_timing_info.send_end);
-  EXPECT_LE(load_timing_info.send_end, load_timing_info.receive_headers_end);
 
-  // Set by URLRequest, at a higher level.
+  // Set at a higher level.
   EXPECT_TRUE(load_timing_info.request_start_time.is_null());
   EXPECT_TRUE(load_timing_info.request_start.is_null());
+  EXPECT_TRUE(load_timing_info.receive_headers_end.is_null());
 }
 
 // Tests LoadTimingInfo in the case a socket is reused and a PAC script is
@@ -191,11 +191,11 @@ void TestLoadTimingReusedWithPac(const net::LoadTimingInfo& load_timing_info) {
   EXPECT_LE(load_timing_info.proxy_resolve_end,
             load_timing_info.send_start);
   EXPECT_LE(load_timing_info.send_start, load_timing_info.send_end);
-  EXPECT_LE(load_timing_info.send_end, load_timing_info.receive_headers_end);
 
-  // Set by URLRequest, at a higher level.
+  // Set at a higher level.
   EXPECT_TRUE(load_timing_info.request_start_time.is_null());
   EXPECT_TRUE(load_timing_info.request_start.is_null());
+  EXPECT_TRUE(load_timing_info.receive_headers_end.is_null());
 }
 
 // Tests LoadTimingInfo in the case a new socket is used and a PAC script is
@@ -216,11 +216,11 @@ void TestLoadTimingNotReusedWithPac(const net::LoadTimingInfo& load_timing_info,
             load_timing_info.send_start);
 
   EXPECT_LE(load_timing_info.send_start, load_timing_info.send_end);
-  EXPECT_LE(load_timing_info.send_end, load_timing_info.receive_headers_end);
 
-  // Set by URLRequest, at a higher level.
+  // Set at a higher level.
   EXPECT_TRUE(load_timing_info.request_start_time.is_null());
   EXPECT_TRUE(load_timing_info.request_start.is_null());
+  EXPECT_TRUE(load_timing_info.receive_headers_end.is_null());
 }
 
 }  // namespace
diff --git a/net/http/http_network_transaction_spdy3_unittest.cc b/net/http/http_network_transaction_spdy3_unittest.cc
index 173b16f..706a8bb 100644
--- a/net/http/http_network_transaction_spdy3_unittest.cc
+++ b/net/http/http_network_transaction_spdy3_unittest.cc
@@ -158,11 +158,11 @@ void TestLoadTimingReused(const net::LoadTimingInfo& load_timing_info) {
   EXPECT_FALSE(load_timing_info.send_start.is_null());
 
   EXPECT_LE(load_timing_info.send_start, load_timing_info.send_end);
-  EXPECT_LE(load_timing_info.send_end, load_timing_info.receive_headers_end);
 
-  // Set by URLRequest, at a higher level.
+  // Set at a higher level.
   EXPECT_TRUE(load_timing_info.request_start_time.is_null());
   EXPECT_TRUE(load_timing_info.request_start.is_null());
+  EXPECT_TRUE(load_timing_info.receive_headers_end.is_null());
 }
 
 // Tests LoadTimingInfo in the case a new socket is used and no PAC script is
@@ -176,16 +176,16 @@ void TestLoadTimingNotReused(const net::LoadTimingInfo& load_timing_info,
   EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null());
 
   net::ExpectConnectTimingHasTimes(load_timing_info.connect_timing,
-                                    connect_timing_flags);
+                                   connect_timing_flags);
   EXPECT_LE(load_timing_info.connect_timing.connect_end,
             load_timing_info.send_start);
 
   EXPECT_LE(load_timing_info.send_start, load_timing_info.send_end);
-  EXPECT_LE(load_timing_info.send_end, load_timing_info.receive_headers_end);
 
-  // Set by URLRequest, at a higher level.
+  // Set at a higher level.
   EXPECT_TRUE(load_timing_info.request_start_time.is_null());
   EXPECT_TRUE(load_timing_info.request_start.is_null());
+  EXPECT_TRUE(load_timing_info.receive_headers_end.is_null());
 }
 
 // Tests LoadTimingInfo in the case a socket is reused and a PAC script is
@@ -202,11 +202,11 @@ void TestLoadTimingReusedWithPac(const net::LoadTimingInfo& load_timing_info) {
   EXPECT_LE(load_timing_info.proxy_resolve_end,
             load_timing_info.send_start);
   EXPECT_LE(load_timing_info.send_start, load_timing_info.send_end);
-  EXPECT_LE(load_timing_info.send_end, load_timing_info.receive_headers_end);
 
-  // Set by URLRequest, at a higher level.
+  // Set at a higher level.
   EXPECT_TRUE(load_timing_info.request_start_time.is_null());
   EXPECT_TRUE(load_timing_info.request_start.is_null());
+  EXPECT_TRUE(load_timing_info.receive_headers_end.is_null());
 }
 
 // Tests LoadTimingInfo in the case a new socket is used and a PAC script is
@@ -227,11 +227,11 @@ void TestLoadTimingNotReusedWithPac(const net::LoadTimingInfo& load_timing_info,
             load_timing_info.send_start);
 
   EXPECT_LE(load_timing_info.send_start, load_timing_info.send_end);
-  EXPECT_LE(load_timing_info.send_end, load_timing_info.receive_headers_end);
 
-  // Set by URLRequest, at a higher level.
+  // Set at a higher level.
   EXPECT_TRUE(load_timing_info.request_start_time.is_null());
   EXPECT_TRUE(load_timing_info.request_start.is_null());
+  EXPECT_TRUE(load_timing_info.receive_headers_end.is_null());
 }
 
 }  // namespace
diff --git a/net/http/http_transaction.h b/net/http/http_transaction.h
index c162b01..c23bf93 100644
--- a/net/http/http_transaction.h
+++ b/net/http/http_transaction.h
@@ -113,9 +113,11 @@ class NET_EXPORT_PRIVATE HttpTransaction {
   // zero will be returned.  This does not include the request headers.
   virtual UploadProgress GetUploadProgress() const = 0;
 
-  // Populates all of load timing, except for request start times.
+  // Populates all of load timing, except for request start times and receive
+  // headers time.
   // |load_timing_info| must have all null times when called.  Returns false and
-  // does not modify |load_timing_info| if not currently connected.
+  // does not modify |load_timing_info| if there's no timing information to
+  // provide.
   virtual bool GetLoadTimingInfo(LoadTimingInfo* load_timing_info) const = 0;
 
   // Called when the priority of the parent job changes.
diff --git a/net/http/http_transaction_unittest.cc b/net/http/http_transaction_unittest.cc
index f84ddae..ab5688d4 100644
--- a/net/http/http_transaction_unittest.cc
+++ b/net/http/http_transaction_unittest.cc
@@ -9,8 +9,10 @@
 #include "base/bind.h"
 #include "base/message_loop.h"
 #include "base/stringprintf.h"
+#include "base/time.h"
 #include "net/base/net_errors.h"
 #include "net/base/load_flags.h"
+#include "net/base/load_timing_info.h"
 #include "net/disk_cache/disk_cache.h"
 #include "net/http/http_cache.h"
 #include "net/http/http_request_info.h"
@@ -227,7 +229,8 @@ MockNetworkTransaction::MockNetworkTransaction(
     : weak_factory_(this),
       data_cursor_(0),
       priority_(priority),
-      transaction_factory_(factory->AsWeakPtr()) {
+      transaction_factory_(factory->AsWeakPtr()),
+      socket_log_id_(net::NetLog::Source::kInvalidId) {
 }
 
 MockNetworkTransaction::~MockNetworkTransaction() {}
@@ -241,7 +244,7 @@ int MockNetworkTransaction::Start(const net::HttpRequestInfo* request,
 
   test_mode_ = t->test_mode;
 
-  // Return immediately if we're returning in error.
+  // Return immediately if we're returning an error.
   if (net::OK != t->return_code) {
     if (test_mode_ & TEST_MODE_SYNC_NET_START)
       return t->return_code;
@@ -275,6 +278,9 @@ int MockNetworkTransaction::Start(const net::HttpRequestInfo* request,
   response_.ssl_info.cert_status = t->cert_status;
   data_ = resp_data;
 
+  if (net_log.net_log())
+    socket_log_id_ = net_log.net_log()->NextID();
+
   if (test_mode_ & TEST_MODE_SYNC_NET_START)
     return net::OK;
 
@@ -341,7 +347,24 @@ net::UploadProgress MockNetworkTransaction::GetUploadProgress() const {
 
 bool MockNetworkTransaction::GetLoadTimingInfo(
     net::LoadTimingInfo* load_timing_info) const {
-  return false;
+  if (socket_log_id_ != net::NetLog::Source::kInvalidId) {
+    // The minimal set of times for a request that gets a response, assuming it
+    // gets a new socket.
+    load_timing_info->socket_reused = false;
+    load_timing_info->socket_log_id = socket_log_id_;
+    load_timing_info->connect_timing.connect_start = base::TimeTicks::Now();
+    load_timing_info->connect_timing.connect_end = base::TimeTicks::Now();
+    load_timing_info->send_start = base::TimeTicks::Now();
+    load_timing_info->send_end = base::TimeTicks::Now();
+  } else {
+    // If there's no valid socket ID, just use the generic socket reused values.
+    // No tests currently depend on this, just should not match the values set
+    // by a cache hit.
+    load_timing_info->socket_reused = true;
+    load_timing_info->send_start = base::TimeTicks::Now();
+    load_timing_info->send_end = base::TimeTicks::Now();
+  }
+  return true;
 }
 
 void MockNetworkTransaction::SetPriority(net::RequestPriority priority) {
diff --git a/net/http/http_transaction_unittest.h b/net/http/http_transaction_unittest.h
index 6e31097..a84c86b 100644
--- a/net/http/http_transaction_unittest.h
+++ b/net/http/http_transaction_unittest.h
@@ -16,6 +16,7 @@
 #include "net/base/io_buffer.h"
 #include "net/base/load_flags.h"
 #include "net/base/net_errors.h"
+#include "net/base/net_log.h"
 #include "net/base/request_priority.h"
 #include "net/base/test_completion_callback.h"
 #include "net/disk_cache/disk_cache.h"
@@ -213,6 +214,11 @@ class MockNetworkTransaction
   int test_mode_;
   net::RequestPriority priority_;
   base::WeakPtr<MockNetworkLayer> transaction_factory_;
+
+  // NetLog ID of the fake / non-existent underlying socket used by the
+  // connection. Requires Start() be passed a BoundNetLog with a real NetLog to
+  // be initialized.
+  unsigned int socket_log_id_;
 };
 
 class MockNetworkLayer : public net::HttpTransactionFactory,
diff --git a/net/url_request/url_request.cc b/net/url_request/url_request.cc
index 0713062..c6daf04 100644
--- a/net/url_request/url_request.cc
+++ b/net/url_request/url_request.cc
@@ -1034,7 +1034,18 @@ void URLRequest::OnHeadersComplete() {
   // socket is closed and the ClientSocketHandle is Reset, which will happen
   // once the body is complete.  The start times should already be populated.
   if (job_) {
+    // Keep a copy of the two times the URLRequest sets.
+    base::TimeTicks request_start = load_timing_info_.request_start;
+    base::Time request_start_time = load_timing_info_.request_start_time;
+
+    // Clear load times.  Shouldn't be neded, but gives the GetLoadTimingInfo a
+    // consistent place to start from.
+    load_timing_info_ = LoadTimingInfo();
     job_->GetLoadTimingInfo(&load_timing_info_);
+
+    load_timing_info_.request_start = request_start;
+    load_timing_info_.request_start_time = request_start_time;
+
     ConvertRealLoadTimesToBlockingTimes(&load_timing_info_);
   }
 }
diff --git a/net/url_request/url_request_http_job.cc b/net/url_request/url_request_http_job.cc
index 71904a5..bed2687 100644
--- a/net/url_request/url_request_http_job.cc
+++ b/net/url_request/url_request_http_job.cc
@@ -416,6 +416,7 @@ void URLRequestHttpJob::DestroyTransaction() {
   DoneWithRequest(ABORTED);
   transaction_.reset();
   response_info_ = NULL;
+  receive_headers_end_ = base::TimeTicks();
 }
 
 void URLRequestHttpJob::StartTransaction() {
@@ -819,6 +820,8 @@ void URLRequestHttpJob::OnStartCompleted(int result) {
   if (!transaction_.get())
     return;
 
+  receive_headers_end_ = base::TimeTicks::Now();
+
   // Clear the IO_PENDING status
   SetStatus(URLRequestStatus());
 
@@ -918,6 +921,7 @@ void URLRequestHttpJob::RestartTransactionWithAuth(
 
   // These will be reset in OnStartCompleted.
   response_info_ = NULL;
+  receive_headers_end_ = base::TimeTicks();
   response_cookies_.clear();
 
   ResetTimer();
@@ -982,8 +986,12 @@ void URLRequestHttpJob::GetResponseInfo(HttpResponseInfo* info) {
 
 void URLRequestHttpJob::GetLoadTimingInfo(
     LoadTimingInfo* load_timing_info) const {
-  if (transaction_)
-    transaction_->GetLoadTimingInfo(load_timing_info);
+  // If haven't made it far enough to receive any headers, don't return
+  // anything.  This makes for more consistent behavior in the case of errors.
+  if (!transaction_ || receive_headers_end_.is_null())
+    return;
+  if (transaction_->GetLoadTimingInfo(load_timing_info))
+    load_timing_info->receive_headers_end = receive_headers_end_;
 }
 
 bool URLRequestHttpJob::GetResponseCookies(std::vector<std::string>* cookies) {
@@ -1124,6 +1132,7 @@ void URLRequestHttpJob::CancelAuth() {
 
   // These will be reset in OnStartCompleted.
   response_info_ = NULL;
+  receive_headers_end_ = base::TimeTicks::Now();
   response_cookies_.clear();
 
   ResetTimer();
@@ -1147,6 +1156,7 @@ void URLRequestHttpJob::ContinueWithCertificate(
   DCHECK(transaction_.get());
 
   DCHECK(!response_info_) << "should not have a response yet";
+  receive_headers_end_ = base::TimeTicks();
 
   ResetTimer();
 
@@ -1172,6 +1182,7 @@ void URLRequestHttpJob::ContinueDespiteLastError() {
     return;
 
   DCHECK(!response_info_) << "should not have a response yet";
+  receive_headers_end_ = base::TimeTicks();
 
   ResetTimer();
 
diff --git a/net/url_request/url_request_http_job.h b/net/url_request/url_request_http_job.h
index 73d216f..e7a2292 100644
--- a/net/url_request/url_request_http_job.h
+++ b/net/url_request/url_request_http_job.h
@@ -239,6 +239,9 @@ class NET_EXPORT_PRIVATE URLRequestHttpJob : public URLRequestJob {
   // The start time for the job, ignoring re-starts.
   base::TimeTicks start_time_;
 
+  // When the transaction finished reading the request headers.
+  base::TimeTicks receive_headers_end_;
+
   scoped_ptr<HttpFilterContext> filter_context_;
   base::WeakPtrFactory<URLRequestHttpJob> weak_factory_;
 
diff --git a/net/url_request/url_request_unittest.cc b/net/url_request/url_request_unittest.cc
index 8f7864f..ca08f25 100644
--- a/net/url_request/url_request_unittest.cc
+++ b/net/url_request/url_request_unittest.cc
@@ -156,10 +156,28 @@ void TestLoadTimingReusedWithProxy(
   EXPECT_LE(load_timing_info.send_end, load_timing_info.receive_headers_end);
 }
 
-// Tests load timing in the case that there is no underlying connection.  This
-// can be used to test in the case of cached responses, errors, or non-HTTP
-// requests.
-void TestLoadTimingNoHttpConnection(
+// Tests load timing information in the case of a cache hit, when no cache
+// validation request was sent over the wire.
+void TestLoadTimingCacheHitNoNetwork(
+    const net::LoadTimingInfo& load_timing_info) {
+  EXPECT_FALSE(load_timing_info.socket_reused);
+  EXPECT_EQ(net::NetLog::Source::kInvalidId, load_timing_info.socket_log_id);
+
+  EXPECT_FALSE(load_timing_info.request_start_time.is_null());
+  EXPECT_FALSE(load_timing_info.request_start.is_null());
+
+  ExpectConnectTimingHasNoTimes(load_timing_info.connect_timing);
+  EXPECT_LE(load_timing_info.request_start, load_timing_info.send_start);
+  EXPECT_LE(load_timing_info.send_start, load_timing_info.send_end);
+  EXPECT_LE(load_timing_info.send_end, load_timing_info.receive_headers_end);
+
+  EXPECT_TRUE(load_timing_info.proxy_resolve_start.is_null());
+  EXPECT_TRUE(load_timing_info.proxy_resolve_end.is_null());
+}
+
+// Tests load timing in the case that there is no HTTP response.  This can be
+// used to test in the case of errors or non-HTTP requests.
+void TestLoadTimingNoHttpResponse(
     const net::LoadTimingInfo& load_timing_info) {
   EXPECT_FALSE(load_timing_info.socket_reused);
   EXPECT_EQ(net::NetLog::Source::kInvalidId, load_timing_info.socket_log_id);
@@ -4023,7 +4041,7 @@ TEST_F(URLRequestTestHTTP, CancelDeferredRedirect) {
 TEST_F(URLRequestTestHTTP, VaryHeader) {
   ASSERT_TRUE(test_server_.Start());
 
-  // populate the cache
+  // Populate the cache.
   {
     TestDelegate d;
     URLRequest req(
@@ -4033,9 +4051,13 @@ TEST_F(URLRequestTestHTTP, VaryHeader) {
     req.SetExtraRequestHeaders(headers);
     req.Start();
     MessageLoop::current()->Run();
+
+    LoadTimingInfo load_timing_info;
+    req.GetLoadTimingInfo(&load_timing_info);
+    TestLoadTimingNotReused(load_timing_info, CONNECT_TIMING_HAS_DNS_TIMES);
   }
 
-  // expect a cache hit
+  // Expect a cache hit.
   {
     TestDelegate d;
     URLRequest req(
@@ -4047,9 +4069,13 @@ TEST_F(URLRequestTestHTTP, VaryHeader) {
     MessageLoop::current()->Run();
 
     EXPECT_TRUE(req.was_cached());
+
+    LoadTimingInfo load_timing_info;
+    req.GetLoadTimingInfo(&load_timing_info);
+    TestLoadTimingCacheHitNoNetwork(load_timing_info);
   }
 
-  // expect a cache miss
+  // Expect a cache miss.
   {
     TestDelegate d;
     URLRequest req(
@@ -4061,6 +4087,10 @@ TEST_F(URLRequestTestHTTP, VaryHeader) {
     MessageLoop::current()->Run();
 
     EXPECT_FALSE(req.was_cached());
+
+    LoadTimingInfo load_timing_info;
+    req.GetLoadTimingInfo(&load_timing_info);
+    TestLoadTimingNotReused(load_timing_info, CONNECT_TIMING_HAS_DNS_TIMES);
   }
 }
 
@@ -4194,8 +4224,8 @@ TEST_F(URLRequestTestHTTP, BasicAuthLoadTiming) {
               load_timing_info.connect_timing.connect_start);
   }
 
-  // repeat request with end-to-end validation.  since auth-basic results in a
-  // cachable page, we expect this test to result in a 304.  in which case, the
+  // Repeat request with end-to-end validation.  Since auth-basic results in a
+  // cachable page, we expect this test to result in a 304.  In which case, the
   // response should be fetched from the cache.
   {
     TestDelegate d;
@@ -4212,9 +4242,11 @@ TEST_F(URLRequestTestHTTP, BasicAuthLoadTiming) {
     // Should be the same cached document.
     EXPECT_TRUE(r.was_cached());
 
+    // Since there was a request that went over the wire, the load timing
+    // information should include connection times.
     LoadTimingInfo load_timing_info;
     r.GetLoadTimingInfo(&load_timing_info);
-    TestLoadTimingNoHttpConnection(load_timing_info);
+    TestLoadTimingNotReused(load_timing_info, CONNECT_TIMING_HAS_DNS_TIMES);
   }
 }
 
@@ -5576,7 +5608,7 @@ TEST_F(URLRequestTestFTP, DISABLED_FTPGetTest) {
 
     LoadTimingInfo load_timing_info;
     r.GetLoadTimingInfo(&load_timing_info);
-    TestLoadTimingNoHttpConnection(load_timing_info);
+    TestLoadTimingNoHttpResponse(load_timing_info);
   }
 }