Skip to content

feat(storage): log transient errors retried on the sync paths - #16467

Open
v-pratap wants to merge 1 commit into
googleapis:mainfrom
v-pratap:retry-logging-sync
Open

v-pratap wants to merge 1 commit into
googleapis:mainfrom
v-pratap:retry-logging-sync

Conversation

@v-pratap

Copy link
Copy Markdown
Contributor

Problem

When GCS returns a transient error (429, 503, 500, DEADLINE_EXCEEDED) the
client backs off and retries with no output at all. From the application's
point of view a read just takes a long time.

There is nothing to grep for, so an operator cannot tell a slow network from a
server that is shedding load. The only way to see the retries today is to enable
the rawclient tracing component and pay for a full dump of every request and
response — which you can only do after you already suspect retries, i.e. not
during the first occurrence of an incident.

This came out of a real incident where reads on a large fleet appeared to stall
and the client produced nothing to correlate against.

What this does

One WARNING record per retried attempt, nothing on success:

[gcs-retry] <where>: transient error on attempt <n>, resource=<bucket/object>, status=<status>

This PR covers the synchronous paths, which serve both the JSON/REST and the
gRPC transports — GCS gRPC sync also goes through RestRetryLoop, because
GenericStub takes a RestContext& regardless of transport.

Call site where Fires when
ConnectionImpl::ReadObject (retry lambda) ReadObject/open an attempt failed to open the stream
RetryObjectReadSource::Read ReadObject/resume the stream broke mid-download and is resumed from the last received byte
ConnectionImpl::UploadChunk UploadChunk an attempt to upload a chunk of a resumable upload failed

New helper google/cloud/storage/internal/retry_logging.{h,cc}
(IsTransientError, LogTransientRetry, RetryLogResource,
RetryLogUploadResource) so the call sites stay one line each.

Also makes LoggingStub::ReadObject report the status on failure. It cannot use
LogWrapper because unique_ptr<ObjectReadSource> has no operator<<, so it
previously logged nothing about why the call failed.

Design notes

Why WARNING, and why not behind a tracing component

LogSink::minimum_severity_ defaults to TRACE, but the default
StdClogBackend drops everything below FATAL
(log.cc#L228-L231).
So this is invisible in a default OSS build and becomes visible to anyone
who installs their own LogBackend. A diagnostic that has to be turned on first
is not useful during the first occurrence of an incident, which is exactly when
it is needed.

No changes to google/cloud/internal/** or log.cc; everything is inside
google/cloud/storage/**.

The status is flattened to one line

GCS error bodies end with a newline. Streaming the Status straight into
GCP_LOG carried that newline through, pushing the backend's (file:line)
suffix onto a second line — so grep '\[gcs-retry\]' returned a truncated
record, defeating the point of the greppable prefix.

It is also a small log-injection hazard, since the message is
service-supplied. OneLine() flattens \n, \r, \t.
Pinned by RetryLogging.StatusIsFlattenedToASingleLine.

The upload session URL is redacted

UploadChunkRequest only exposes upload_session_url(), and the upload_id in
it is a bearer capability — anyone holding it can append to or finalize that
upload with no other credential, for the lifetime of the session (~7 days).

The request's own operator<< does print it, but that is behind the opt-in
rawclient component, whereas this record is always on and lands in log
aggregators that are usually readable by more people than the bucket itself.

RetryLogUploadResource() keeps the bucket and an 8-character prefix of the id
— enough to tell concurrent uploads apart, not enough to hijack one.

Attempt numbers at sites that run before the retry policy

ReadObject/open runs inside the retry lambda, i.e. before the retry policy is
consulted, so it also reports the final give-up attempt. That attempt is real and
did fail; it just was not followed by another try. Noted in a comment at the call
site. ReadObject/resume and UploadChunk are exact.

The backoff delay is deliberately not logged: reading it requires
backoff_policy.OnCompletion(), which advances the policy.

Testbench verification

End-to-end against
storage-testbench v0.61.0
using its fault-injection API (POST /retry_test, id passed as
x-retry-test-id), with GOOGLE_CLOUD_CPP_ENABLE_CLOG=yes.

# Scenario Fault injected Site Result
1 REST ReadObject, open fails storage.objects.get: 503 ×2 ReadObject/open 2 records
2 REST ReadObject, stream breaks return-broken-stream-after-256K ReadObject/resume 1 record
3 REST resumable upload storage.objects.insert: return-503-after-256K UploadChunk 1 record
4 Control — healthy download none silent
===== 1. REST ReadObject: 503 opening the stream -> ReadObject/open =====
2026-09-21T04:24:22.129449871Z [WARNING] <140310344792704> [gcs-retry] ReadObject/open: transient error on attempt 1, resource=retry-logging-demo-bucket/retry-logging-demo.txt, status=UNAVAILABLE: {"error":{"code":"503","message":{"error":{"message":"Retry Test: Caused a 503"}}}} (google/cloud/storage/internal/retry_logging.cc:87)
2026-09-21T04:24:22.143797901Z [WARNING] <140310344792704> [gcs-retry] ReadObject/open: transient error on attempt 2, resource=retry-logging-demo-bucket/retry-logging-demo.txt, status=UNAVAILABLE: {"error":{"code":"503","message":{"error":{"message":"Retry Test: Caused a 503"}}}} (google/cloud/storage/internal/retry_logging.cc:87)

===== 2. REST ReadObject: broken stream mid-download -> ReadObject/resume =====
2026-09-21T04:24:22.804692586Z [WARNING] <140310344792704> [gcs-retry] ReadObject/resume: transient error on attempt 1, resource=retry-logging-demo-bucket/retry-logging-demo-large.bin, status=UNAVAILABLE: PerformWork() - CURL error [18]=Transferred a partial file (google/cloud/storage/internal/retry_logging.cc:87)

===== 3. REST resumable upload: 503 uploading a chunk -> UploadChunk =====
2026-09-21T04:24:23.050486395Z [WARNING] <140310344792704> [gcs-retry] UploadChunk: transient error on attempt 1, resource=http://localhost:9000/upload/storage/v1/b/retry-logging-demo-bucket/o?uploadType=resumable&upload_id=ec0a25d3...[redacted], status=UNAVAILABLE: {"error":{"code":503,"message":"Fault injected during a resumable upload"}} (google/cloud/storage/internal/retry_logging.cc:87)

===== 4. CONTROL - healthy REST download, expect NO [gcs-retry] lines =====
(nothing)

The trailing (retry_logging.cc:87) is added by the library's own log backend
(operator<<(std::ostream&, LogRecord const&) in log.cc), not by this change.

Note

The testbench run found two defects that the unit tests did not: the newline
split and the upload_id disclosure described above. Both are fixed here and
re-verified.

Tests

bazel test //google/cloud/storage:all175 / 175 PASSED on this branch
alone.

New coverage in retry_logging_test.cc, connection_impl_object_test.cc,
retry_object_read_source_test.cc, logging_stub_test.cc — including negative
tests asserting nothing is logged on success or on a permanent error.

Follow-ups

  • The async and bidi paths are handled in a stacked PR on top of this one.
  • Write coverage here is deliberately partial: only UploadChunk. A
    RetryLoggingStub GenericStub decorator installed in
    generic_stub_factory.cc would cover every unary RPC from a single place;
    worth doing separately rather than growing this PR.
  • Open question for reviewers: this logs every retried attempt. A fleet-wide
    429 storm could produce a lot of lines. Would you prefer attempt 1 and then
    powers of two? There is no LOG_FIRST_N equivalent in the library today.

Internal ref: b/547926601

@gemini-code-assist gemini-code-assist Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review

This pull request introduces a new retry logging mechanism (retry_logging.h and retry_logging.cc) to provide diagnostics for silently retried transient errors in GCS operations, integrating it into ReadObject, UploadChunk, and RetryObjectReadSource. Feedback on the changes highlights style guide violations, specifically recommending the use of std::string_view instead of absl::string_view and avoiding auto for primitive types.

Comment thread google/cloud/storage/internal/retry_logging.h Outdated
Comment thread google/cloud/storage/internal/retry_logging.h Outdated
Comment thread google/cloud/storage/internal/retry_logging.cc Outdated
@v-pratap
v-pratap marked this pull request as ready for review September 21, 2026 05:07
@v-pratap
v-pratap requested review from a team as code owners September 21, 2026 05:07
When GCS returns a transient error the client backs off and retries with
no output at all. From the application's point of view a read just takes
a long time. There is nothing to grep for, so an operator cannot tell a
slow network from a server that is shedding load, and the only way to
see the retries is to enable the `rawclient` tracing component and pay
for a full dump of every request and response.

This adds one WARNING record per retried attempt on the synchronous
paths, which cover both the JSON/REST and the gRPC transports (GCS gRPC
sync goes through `RestRetryLoop`, because `GenericStub` takes a
`RestContext&` regardless of transport).

    [gcs-retry] ReadObject/open: transient error on attempt 1,
    resource=my-bucket/my-object, status=UNAVAILABLE: ...

Call sites:

- `ConnectionImpl::ReadObject`, the retry lambda passed to
  `RestRetryLoop` -- an attempt failed to open the stream.
- `RetryObjectReadSource::Read` -- the stream broke mid-download and is
  being resumed from the last received byte.
- `ConnectionImpl::UploadChunk` -- an attempt to upload a chunk of a
  resumable upload failed.

The severity is WARNING and the record is not gated behind a tracing
component. `StdClogBackend`, the default backend, drops everything below
FATAL, so this is invisible to a default OSS build; it becomes visible
to anyone who installs a `LogBackend`. A log that has to be turned on
first is not useful during the first occurrence of an incident, which is
exactly when it is needed.

Two details worth calling out:

- The status is flattened to a single line. GCS error bodies end with a
  newline, which would otherwise push the backend's `(file:line)` suffix
  onto a second line and make the record unusable with `grep`. It also
  removes a log-injection hazard, since the message is service-supplied.
- `UploadChunkRequest` only exposes the resumable session URL, and the
  `upload_id` in it is a bearer capability: anyone holding it can append
  to or finalize the upload for the lifetime of the session. Only the
  bucket and an 8-character prefix of the id are logged, which is enough
  to tell concurrent uploads apart.

Also makes `LoggingStub::ReadObject` report the status on failure. It
cannot use `LogWrapper` because `unique_ptr<ObjectReadSource>` has no
`operator<<`, so it previously logged nothing about why the call failed.

Verified against the storage-testbench using its fault-injection API, in
addition to the unit tests.
@codecov

codecov Bot commented Sep 21, 2026

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 92.35%. Comparing base (7d9d5d0) to head (1b80cff).

Additional details and impacted files
@@            Coverage Diff             @@
##             main   #16467      +/-   ##
==========================================
+ Coverage   92.34%   92.35%   +0.01%     
==========================================
  Files        2246     2248       +2     
  Lines      214568   214806     +238     
==========================================
+ Hits       198136   198385     +249     
+ Misses      16432    16421      -11     

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

api: storage Issues related to the Cloud Storage API.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant