Adds cache lock timeout handling after finishing headers phase.

net/http/http_cache_transaction.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "net/http/http_cache_transaction.h"
 
 #include "build/build_config.h"  // For OS_POSIX
 
 #if defined(OS_POSIX)
 #include <unistd.h>
@@ skipping 150 matching lines @@
       invalid_range_(false),
       truncated_(false),
       is_sparse_(false),
       range_requested_(false),
       handling_206_(false),
       cache_pending_(false),
       done_reading_(false),
       vary_mismatch_(false),
       couldnt_conditionalize_request_(false),
       bypass_lock_for_test_(false),
+      bypass_lock_after_headers_for_test_(false),
       fail_conditionalization_for_test_(false),
       io_buf_len_(0),
       read_offset_(0),
       effective_load_flags_(0),
       write_len_(0),
       cache_entry_status_(CacheEntryStatus::ENTRY_UNDEFINED),
       validation_cause_(VALIDATION_CAUSE_UNDEFINED),
       total_received_bytes_(0),
       total_sent_bytes_(0),
       websocket_handshake_stream_base_create_helper_(NULL),
@@ skipping 665 matching lines @@
         rv = DoPartialHeadersReceived();
         break;
       case STATE_CACHE_READ_METADATA:
         DCHECK_EQ(OK, rv);
         rv = DoCacheReadMetadata();
         break;
       case STATE_CACHE_READ_METADATA_COMPLETE:
         rv = DoCacheReadMetadataComplete(rv);
         break;
       case STATE_HEADERS_PHASE_CANNOT_PROCEED:
-        rv = DoHeadersPhaseCannotProceed();
+        rv = DoHeadersPhaseCannotProceed(rv);
         break;
       case STATE_FINISH_HEADERS:
         rv = DoFinishHeaders(rv);
         break;
       case STATE_FINISH_HEADERS_COMPLETE:
         rv = DoFinishHeadersComplete(rv);
         break;
       case STATE_NETWORK_READ:
         DCHECK_EQ(OK, rv);
         rv = DoNetworkRead();
@@ skipping 49 matching lines @@
   net_log_.BeginEvent(NetLogEventType::HTTP_CACHE_GET_BACKEND);
   return cache_->GetBackendForTransaction(this);
 }
 
 int HttpCache::Transaction::DoGetBackendComplete(int result) {
   DCHECK(result == OK || result == ERR_FAILED);
   net_log_.EndEventWithNetErrorCode(NetLogEventType::HTTP_CACHE_GET_BACKEND,
                                     result);
   cache_pending_ = false;
 
+  // Reset mode_ that might get set in this function. This is done because this
+  // function can be invoked multiple times for a transaction.
+  mode_ = NONE;
+
   if (!ShouldPassThrough()) {
     cache_key_ = cache_->GenerateCacheKey(request_);
 
     // Requested cache access mode.
     if (effective_load_flags_ & LOAD_ONLY_FROM_CACHE) {
       if (effective_load_flags_ & LOAD_BYPASS_CACHE) {
         // The client has asked for nonsense.
         TransitionToState(STATE_FINISH_HEADERS);
         return ERR_CACHE_MISS;
       }
@@ skipping 188 matching lines @@
 
 int HttpCache::Transaction::DoAddToEntry() {
   TRACE_EVENT0("io", "HttpCacheTransaction::DoAddToEntry");
   DCHECK(new_entry_);
   cache_pending_ = true;
   TransitionToState(STATE_ADD_TO_ENTRY_COMPLETE);
   net_log_.BeginEvent(NetLogEventType::HTTP_CACHE_ADD_TO_ENTRY);
   DCHECK(entry_lock_waiting_since_.is_null());
   entry_lock_waiting_since_ = TimeTicks::Now();
   int rv = cache_->AddTransactionToEntry(new_entry_, this);
-  if (rv == ERR_IO_PENDING) {
-    if (bypass_lock_for_test_) {
-      base::ThreadTaskRunnerHandle::Get()->PostTask(
-          FROM_HERE,
-          base::Bind(&HttpCache::Transaction::OnAddToEntryTimeout,
-                     weak_factory_.GetWeakPtr(), entry_lock_waiting_since_));
-    } else {
-      int timeout_milliseconds = 20 * 1000;
-      if (partial_ && new_entry_->writer &&
-          new_entry_->writer->range_requested_) {
-        // Quickly timeout and bypass the cache if we're a range request and
-        // we're blocked by the reader/writer lock. Doing so eliminates a long
-        // running issue, http://crbug.com/31014, where two of the same media
-        // resources could not be played back simultaneously due to one locking
-        // the cache entry until the entire video was downloaded.
-        //
-        // Bypassing the cache is not ideal, as we are now ignoring the cache
-        // entirely for all range requests to a resource beyond the first. This
-        // is however a much more succinct solution than the alternatives, which
-        // would require somewhat significant changes to the http caching logic.
-        //
-        // Allow some timeout slack for the entry addition to complete in case
-        // the writer lock is imminently released; we want to avoid skipping
-        // the cache if at all possible. See http://crbug.com/408765
-        timeout_milliseconds = 25;
-      }
-      base::ThreadTaskRunnerHandle::Get()->PostDelayedTask(
-          FROM_HERE,
-          base::Bind(&HttpCache::Transaction::OnAddToEntryTimeout,
-                     weak_factory_.GetWeakPtr(), entry_lock_waiting_since_),
-          TimeDelta::FromMilliseconds(timeout_milliseconds));
-    }
-  }
+  if (rv == ERR_IO_PENDING)
+    AddCacheLockTimeoutHandler(new_entry_);
   return rv;
 }
 
+void HttpCache::Transaction::AddCacheLockTimeoutHandler(ActiveEntry* entry) {
+  if ((bypass_lock_for_test_ && next_state_ == STATE_ADD_TO_ENTRY_COMPLETE) ||

[Randy Smith (Not in Mondays), 2017/06/23 20:20:46]

suggestion, no need for it to be in this CL if you like it: Change the variables
to be a single "bypass_lock_for_state_" which would be set to a particular state
and then just checked against the current state here.  The positive side of this
is that it's less test code in the production binary, the negative is that it
requires any test that uses it to be a friend (so that it has visibility into
HC::T state names).  

[Randy Smith (Not in Mondays), 2017/06/23 20:20:47]

suggestion: Add DCHECK that we're in one of those two states.

+      (bypass_lock_after_headers_for_test_ &&
+       next_state_ == STATE_FINISH_HEADERS_COMPLETE)) {
+    base::ThreadTaskRunnerHandle::Get()->PostTask(
+        FROM_HERE,
+        base::Bind(&HttpCache::Transaction::OnCacheLockTimeout,
+                   weak_factory_.GetWeakPtr(), entry_lock_waiting_since_));
+  } else {
+    int timeout_milliseconds = 20 * 1000;
+    if (partial_ && entry->writer && entry->writer->range_requested_) {
+      // Quickly timeout and bypass the cache if we're a range request and
+      // we're blocked by the reader/writer lock. Doing so eliminates a long
+      // running issue, http://crbug.com/31014, where two of the same media
+      // resources could not be played back simultaneously due to one locking
+      // the cache entry until the entire video was downloaded.
+      //
+      // Bypassing the cache is not ideal, as we are now ignoring the cache
+      // entirely for all range requests to a resource beyond the first. This
+      // is however a much more succinct solution than the alternatives, which
+      // would require somewhat significant changes to the http caching logic.
+      //
+      // Allow some timeout slack for the entry addition to complete in case
+      // the writer lock is imminently released; we want to avoid skipping
+      // the cache if at all possible. See http://crbug.com/408765
+      timeout_milliseconds = 25;
+    }
+    base::ThreadTaskRunnerHandle::Get()->PostDelayedTask(
+        FROM_HERE,
+        base::Bind(&HttpCache::Transaction::OnCacheLockTimeout,
+                   weak_factory_.GetWeakPtr(), entry_lock_waiting_since_),
+        TimeDelta::FromMilliseconds(timeout_milliseconds));
+  }
+}
+
 int HttpCache::Transaction::DoAddToEntryComplete(int result) {
   TRACE_EVENT0("io", "HttpCacheTransaction::DoAddToEntryComplete");
   net_log_.EndEventWithNetErrorCode(NetLogEventType::HTTP_CACHE_ADD_TO_ENTRY,
                                     result);
   const TimeDelta entry_lock_wait =
       TimeTicks::Now() - entry_lock_waiting_since_;
   UMA_HISTOGRAM_TIMES("HttpCache.EntryLockWait", entry_lock_wait);
 
   entry_lock_waiting_since_ = TimeTicks();
   DCHECK(new_entry_);
@@ skipping 630 matching lines @@
     // We are about to return the headers for a byte-range request to the user,
     // so let's fix them.
     partial_->FixResponseHeaders(response_.headers.get(), true);
     TransitionToState(STATE_FINISH_HEADERS);
   } else {
     TransitionToState(STATE_FINISH_HEADERS);
   }
   return OK;
 }
 
-int HttpCache::Transaction::DoHeadersPhaseCannotProceed() {
+int HttpCache::Transaction::DoHeadersPhaseCannotProceed(int result) {
   // If its the Start state machine and it cannot proceed due to a cache
   // failure, restart this transaction.
   DCHECK(!reading_);
 
   // Reset before invoking SetRequest() which can reset the request info sent to
   // network transaction.
   if (network_trans_)
     network_trans_.reset();
 
   SetRequest(net_log_);
 
   entry_ = nullptr;
 
+  // Bypass the cache for timeout scenario.
+  if (result == ERR_CACHE_LOCK_TIMEOUT)
+    effective_load_flags_ |= LOAD_DISABLE_CACHE;
+
   TransitionToState(STATE_GET_BACKEND);
   return OK;
 }
 
 int HttpCache::Transaction::DoFinishHeaders(int result) {
   if (!cache_.get() || !entry_ || result != OK) {
     TransitionToState(STATE_NONE);
     return result;
   }
 
   TransitionToState(STATE_FINISH_HEADERS_COMPLETE);
 
   // If it was an auth failure or 416, this transaction should continue to be
   // headers_transaction till consumer takes an action, so no need to do
   // anything now.
   if (auth_response_.headers.get() ||
       (new_response_ && new_response_->headers &&
        new_response_->headers->response_code() == 416))
     return OK;
 
   // If the transaction needs to wait because another transaction is still
   // writing the response body, it will return ERR_IO_PENDING now and the
   // io_callback_ will be invoked when the wait is done.
-  return cache_->DoneWithResponseHeaders(entry_, this, partial_ != nullptr);
+  int rv = cache_->DoneWithResponseHeaders(entry_, this, partial_ != nullptr);
+  if (rv == ERR_IO_PENDING) {
+    DCHECK(entry_lock_waiting_since_.is_null());
+    entry_lock_waiting_since_ = TimeTicks::Now();
+    AddCacheLockTimeoutHandler(entry_);

[Randy Smith (Not in Mondays), 2017/06/23 20:20:47]

nit, suggestion, doesn't need to be in this CL if you like it: Put the
assignment to entry_lock_waiting_since_ inside of AddCacheLockTimeoutHandler()
and have a matching function (DisableCacheLockTimeoutHandler()) which resets it.
 

+  }
+  return rv;
 }
 
 int HttpCache::Transaction::DoFinishHeadersComplete(int rv) {
-  if (rv == ERR_CACHE_RACE) {
+  entry_lock_waiting_since_ = TimeTicks();
+  if (rv == ERR_CACHE_RACE || rv == ERR_CACHE_LOCK_TIMEOUT) {
     TransitionToState(STATE_HEADERS_PHASE_CANNOT_PROCEED);
-    return OK;
+    return rv;
   }
 
   TransitionToState(STATE_NONE);
   return rv;
 }
 
 int HttpCache::Transaction::DoCacheReadMetadata() {
   TRACE_EVENT0("io", "HttpCacheTransaction::DoCacheReadMetadata");
   DCHECK(entry_);
   DCHECK(!response_.metadata.get());
@@ skipping 924 matching lines @@
     is_sparse_ = false;
     partial_.reset();
     TransitionToState(STATE_GET_BACKEND);
     return OK;
   }
 
   TransitionToState(STATE_NONE);
   return ERR_CACHE_READ_FAILURE;
 }
 
-void HttpCache::Transaction::OnAddToEntryTimeout(base::TimeTicks start_time) {
+void HttpCache::Transaction::OnCacheLockTimeout(base::TimeTicks start_time) {
   if (entry_lock_waiting_since_ != start_time)
     return;
 
-  DCHECK_EQ(next_state_, STATE_ADD_TO_ENTRY_COMPLETE);
+  DCHECK(next_state_ == STATE_ADD_TO_ENTRY_COMPLETE ||
+         next_state_ == STATE_FINISH_HEADERS_COMPLETE);
 
   if (!cache_)
     return;
 
-  cache_->RemovePendingTransaction(this);
+  if (next_state_ == STATE_ADD_TO_ENTRY_COMPLETE)
+    cache_->RemovePendingTransaction(this);
+  else
+    cache_->DoneWithEntry(entry_, this, false, partial_ != nullptr);
   OnIOComplete(ERR_CACHE_LOCK_TIMEOUT);
 }
 
 void HttpCache::Transaction::DoomPartialEntry(bool delete_object) {
   DVLOG(2) << "DoomPartialEntry";
   int rv = cache_->DoomEntry(cache_key_, NULL);
   DCHECK_EQ(OK, rv);
   cache_->DoneWithEntry(entry_, this, false /* process_cancel */,
                         partial_ != nullptr);
   entry_ = NULL;
@@ skipping 309 matching lines @@
 }
 
 void HttpCache::Transaction::TransitionToState(State state) {
   // Ensure that the state is only set once per Do* state.
   DCHECK(in_do_loop_);
   DCHECK_EQ(STATE_UNSET, next_state_) << "Next state is " << state;
   next_state_ = state;
 }
 
 }  // namespace net