fix(storage): only backoff before resume attempts (#14427)

`storage::Client::ReadObject()` resumes a download that gets
interrupted (controlled by policy). On the first resume attempt, the
library does not back off (sleep), becuase there is no reason to believe
the problem is load related. If the first resume fails, the library
backsoff before each attempt, as the problem might be load related after
this point.

The library was *also* backing off before issuing the first `Read()` on
the newly created source of data. That effectively doubles the backoff
time, and leaves the resumed connection idle for (potentially) a long
time when there are multiple resume attempts needed.

google/cloud/storage/internal/retry_object_read_source.cc

@@ -18,6 +18,7 @@
 #include <sstream>
 #include <string>
 #include <thread>
+#include <utility>
 
 namespace google {
 namespace cloud {
@@ -87,19 +88,23 @@ StatusOr<ReadSourceResult> RetryObjectReadSource::Read(char* buf,
   auto backoff_policy = backoff_policy_prototype_->clone();
   auto retry_policy = retry_policy_prototype_->clone();
   int counter = 0;
-  for (; !result && retry_policy->OnFailure(result.status());
-       backoff_(backoff_policy->OnCompletion()),
-       result = child_->Read(buf, n)) {
+  while (!result && retry_policy->OnFailure(result.status())) {
     // A Read() request failed, most likely that means the connection failed or
     // stalled. The current child might no longer be usable, so we will try to
     // create a new one and replace it. Should that fail, the retry policy would
     // already be exhausted, so we should fail this operation too.
     child_.reset();
 
+    // The first attempt does not get to backoff.  The previous download was
+    // working fine, so whatever caused the download to stop may not be an
+    // overload condition.
+    if (++counter != 1) {
+      backoff_(backoff_policy->OnCompletion());
+    }
     if (has_emulator_instructions) {
       request_.set_multiple_options(
           CustomHeader("x-goog-emulator-instructions",
-                       instructions + "/retry-" + std::to_string(++counter)));
+                       instructions + "/retry-" + std::to_string(counter)));
     }
 
     if (offset_direction_ == kFromEnd) {
@@ -111,7 +116,11 @@ StatusOr<ReadSourceResult> RetryObjectReadSource::Read(char* buf,
       request_.set_option(Generation(*generation_));
     }
     auto status = MakeChild(*retry_policy, *backoff_policy);
-    if (!status.ok()) return status;
+    if (!status.ok()) {
+      result = status;
+      continue;
+    }
+    result = child_->Read(buf, n);
   }
   if (HandleResult(result)) return result;
   // We have exhausted the retry policy, return the error.
@@ -122,7 +131,7 @@ StatusOr<ReadSourceResult> RetryObjectReadSource::Read(char* buf,
   } else {
     os << "Retry policy exhausted in Read(): " << status.message();
   }
-  return Status(status.code(), std::move(os).str());
+  return Status(status.code(), std::move(os).str(), status.error_info());
 }
 
 bool RetryObjectReadSource::HandleResult(StatusOr<ReadSourceResult> const& r) {
@@ -140,7 +149,6 @@ bool RetryObjectReadSource::HandleResult(StatusOr<ReadSourceResult> const& r) {
   return true;
 }
 
-// NOLINTNEXTLINE(misc-no-recursion)
 Status RetryObjectReadSource::MakeChild(RetryPolicy& retry_policy,
                                         BackoffPolicy& backoff_policy) {
   auto on_success = [this](std::unique_ptr<ObjectReadSource> child) {
@@ -158,12 +166,7 @@ Status RetryObjectReadSource::MakeChild(RetryPolicy& retry_policy,
   // first byte.
   child = ReadDiscard(*std::move(child), current_offset_);
   if (child) return on_success(*std::move(child));
-
-  // Try again, eventually the retry policy will expire and this will fail.
-  if (!retry_policy.OnFailure(child.status())) return std::move(child).status();
-  backoff_(backoff_policy.OnCompletion());
-
-  return MakeChild(retry_policy, backoff_policy);
+  return std::move(child).status();
 }
 
 StatusOr<std::unique_ptr<ObjectReadSource>> RetryObjectReadSource::ReadDiscard(

google/cloud/storage/internal/retry_object_read_source_test.cc

@@ -12,6 +12,7 @@
 // See the License for the specific language governing permissions and
 // limitations under the License.
 
+#include "google/cloud/storage/internal/retry_object_read_source.h"
 #include "google/cloud/storage/internal/connection_impl.h"
 #include "google/cloud/storage/retry_policy.h"
 #include "google/cloud/storage/testing/canonical_errors.h"
@@ -32,6 +33,7 @@ using ::google::cloud::storage::testing::MockGenericStub;
 using ::google::cloud::storage::testing::MockObjectReadSource;
 using ::google::cloud::storage::testing::canonical_errors::PermanentError;
 using ::google::cloud::storage::testing::canonical_errors::TransientError;
+using ::google::cloud::testing_util::StatusIs;
 using ::testing::_;
 using ::testing::Contains;
 using ::testing::HasSubstr;
@@ -212,7 +214,7 @@ TEST(RetryObjectReadSourceTest, BackoffPolicyResetOnSuccess) {
 
   EXPECT_EQ(0, num_backoff_policy_called);
 
-  // We really do not care how many times the policy is closed before we make
+  // We really do not care how many times the policy is cloned before we make
   // the first `Read()` call.  We only care about how it increases.
   auto const initial_clone_count = backoff_policy_mock.NumClones();
   auto source = client->ReadObject(ReadObjectRangeRequest{});
@@ -222,21 +224,22 @@ TEST(RetryObjectReadSourceTest, BackoffPolicyResetOnSuccess) {
 
   // raw_source1 and raw_source2 fail, then a success
   ASSERT_STATUS_OK((*source)->Read(nullptr, 1024));
-  // Two retries, so the backoff policy was called twice.
-  EXPECT_EQ(2, num_backoff_policy_called);
-  // The backoff should have been cloned during the read.
+  // Two retries, the first one does not get a backoff, so there should be one
+  // call to OnCompletion.
+  EXPECT_EQ(1, num_backoff_policy_called);
+  // The backoff should have been cloned during the Read() call.
   EXPECT_EQ(initial_clone_count + 2, backoff_policy_mock.NumClones());
-  // The backoff policy was used twice in the first retry.
-  EXPECT_EQ(2, backoff_policy_mock.NumCallsFromLastClone());
+  // The backoff policy was used once in the first retry.
+  EXPECT_EQ(1, backoff_policy_mock.NumCallsFromLastClone());
 
   // raw_source3 fails, then a success
   ASSERT_STATUS_OK((*source)->Read(nullptr, 1024));
-  // This read caused a third retry.
-  EXPECT_EQ(3, num_backoff_policy_called);
+  // This read caused another retry, but no call to backoff.
+  EXPECT_EQ(1, num_backoff_policy_called);
   // The backoff should have been cloned during the read.
   EXPECT_EQ(initial_clone_count + 3, backoff_policy_mock.NumClones());
-  // The backoff policy was only once in the second retry.
-  EXPECT_EQ(1, backoff_policy_mock.NumCallsFromLastClone());
+  // The backoff policy was cloned once, but never used in the second retry.
+  EXPECT_EQ(0, backoff_policy_mock.NumCallsFromLastClone());
 }
 
 /// @test Check that retry policy is shared between reads and resetting session
@@ -269,6 +272,49 @@ TEST(RetryObjectReadSourceTest, RetryPolicyExhaustedOnResetSession) {
   EXPECT_THAT(res.status().message(), HasSubstr("Retry policy exhausted"));
 }
 
+/// @test Check that retry policy is shared between reads and resetting session
+TEST(RetryObjectReadSourceTest, ResumePolicyOrder) {
+  ::testing::MockFunction<void(std::chrono::milliseconds)> backoff;
+  ::testing::MockFunction<StatusOr<std::unique_ptr<ObjectReadSource>>(
+      ReadObjectRangeRequest const&, RetryPolicy&, BackoffPolicy&)>
+      factory;
+
+  auto make_partial = [] {
+    auto source = std::make_unique<MockObjectReadSource>();
+    EXPECT_CALL(*source, Read).WillOnce(Return(TransientError()));
+    return std::unique_ptr<ObjectReadSource>(std::move(source));
+  };
+
+  auto source = std::make_unique<MockObjectReadSource>();
+  {
+    ::testing::InSequence sequence;
+    EXPECT_CALL(*source, Read)
+        .WillOnce(Return(ReadSourceResult{static_cast<std::size_t>(512 * 1024),
+                                          HttpResponse{100, "", {}}}));
+    EXPECT_CALL(*source, Read).WillOnce(Return(TransientError()));
+    // No backoffs to resume after a (partially) successful request:
+    EXPECT_CALL(factory, Call).WillOnce(make_partial);
+    EXPECT_CALL(backoff, Call).Times(1);
+    EXPECT_CALL(factory, Call).WillOnce(make_partial);
+    EXPECT_CALL(backoff, Call).Times(1);
+    EXPECT_CALL(factory, Call).WillOnce(make_partial);
+  }
+
+  auto options = BasicTestPolicies();
+  auto retry_policy = options.get<RetryPolicyOption>()->clone();
+  auto backoff_policy = options.get<BackoffPolicyOption>()->clone();
+
+  RetryObjectReadSource tested(
+      factory.AsStdFunction(),
+      google::cloud::internal::MakeImmutableOptions(std::move(options)),
+      ReadObjectRangeRequest{}, std::move(source), std::move(retry_policy),
+      std::move(backoff_policy), backoff.AsStdFunction());
+
+  ASSERT_STATUS_OK(tested.Read(nullptr, 1024));
+  auto response = tested.Read(nullptr, 1024);
+  EXPECT_THAT(response, StatusIs(TransientError().code()));
+}
+
 /// @test `ReadLast` behaviour after a transient failure
 TEST(RetryObjectReadSourceTest, TransientFailureWithReadLastOption) {
   auto mock = std::make_unique<MockGenericStub>();