storage: Initial request for resumable uploads larger than ChunkSize not retried

[jamesl33]

Description
I'm currently investigating a case where we're seeing a large number of failures due to 503 status codes
(ServiceUnavailable). My understanding was that these errors are retried by default, however, I've observed a case
where that doesn't appear to be true.

• Requests that fall under the default chunk threshold (16MiB) are retried
• The first chunk for requests that are equal, or larger to the chunk threshold will not be retried
• Through modifying the SDK, I've observed that subsequent requests do appear to be retried (although it would be great to confirm my findings)

Walking through the code, it appears this is because the first request for an upload has req.GetBody set to nil:

// google.golang.org/api@v0.46.0/storage/v1/storage-gen.go:10253

body, getBody, cleanup := c.mediaInfo_.UploadRequest(reqHeaders, body)
defer cleanup()

<snip>

req.GetBody = getBody

This results in gensupport.SendRequestWithRetry not retrying the request because it can't retrieve the request body
for the retry.

// google.golang.org/api@v0.46.0/internal/gensupport/send.go:96

// Check if we can retry the request. A retry can only be done if the error
// is retryable and the request body can be re-created using GetBody (this
// will not be possible if the body was unbuffered).
if req.GetBody == nil || !shouldRetry(status, err) {
    break
}

I suspect this may be why we've seen so many 503 status codes surface as errors where I'd expect them to be
retried.

Client

Storage

Environment

$ uname -a
Linux <hostname> 5.19.7-arch1-1 #1 SMP PREEMPT_DYNAMIC Mon, 05 Sep 2022 18:09:09 +0000 x86_64 GNU/Linux

Go Environment

$ go version
go version go1.19 linux/amd64

$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN="/home/james/.local/bin"
GOCACHE="/home/james/.cache/go-build"
GOENV="/home/james/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/james/.local/lib/golang/pkg/mod"
GOOS="linux"
GOPATH="/home/james/.local/lib/golang:/home/james/Projects/go"
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/lib/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.19"
GCCGO="gccgo"
GOAMD64="v1"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/dev/null"
GOWORK=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build2865911939=/tmp/go-build -gno-record-gcc-switches"

Code

// server.go

package main

import (
	"fmt"
	"net/http"
)

func main() {
	http.HandleFunc("/upload/storage/v1/b/bucket/o", func(w http.ResponseWriter, req *http.Request) {
		// Log something useful so we can verify the test client is connecting
		fmt.Printf("Received request from %s\n", req.RemoteAddr)

		// Simulate that GCS is unavailable
		w.WriteHeader(http.StatusServiceUnavailable)

		// The SDK expects a JSON response
		w.Write([]byte("{}"))
	})

	http.ListenAndServe(":12345", nil)
}

// client.go

package main

import (
	"context"
	"io"
	"strings"

	"cloud.google.com/go/storage"
	"google.golang.org/api/googleapi"
	"google.golang.org/api/option"
)

func main() {
	client, err := storage.NewClient(
		context.Background(),
		option.WithEndpoint("http://localhost:12345"),
		option.WithoutAuthentication(),
	)
	if err != nil {
		panic(err)
	}

	// Setup and enable our custom request retry handling which extends that implemented in the SDK
	client.SetRetry(
		storage.WithPolicy(storage.RetryAlways),
	)

	ctx, cancel := context.WithCancel(context.Background())
	defer cancel()

	writer := client.Bucket("bucket").Object("key").NewWriter(ctx)

	// Should see indefinite retries
	body := strings.Repeat("a", googleapi.DefaultUploadChunkSize-1)

	// Should see an immediate failure
	// body := strings.Repeat("a", googleapi.DefaultUploadChunkSize)

	if _, err := io.Copy(writer, strings.NewReader(body)); err != nil {
		panic(err)
	}

	if err := writer.Close(); err != nil {
		panic(err)
	}
}

Steps to Reproduce

1. Create a directory
2. Create a server.go file with the server code provided
3. Create a client.go file with the client code provided
4. Run go mod init github.com/<username>/gcs-retries && go mod tidy
5. Run go run server.go
6. Run go run client.go (we should see multiple requests logged in the server)
7. Comment/uncomment/modify the code to use the larger body size
8. Run go run client.go (we should an immediate failure)

Expected behavior

I would expect to see this 503 error retried, however, there may be a good reason for not retrying the first request
(e.g. forced non-idempotency for requests that setup resumable uploads).

Actual behavior

I observe that the first request for an upload larger than ChunkSize is not retried.

[tritone]

Thanks for flagging this, we were able to reproduce the problem and you're entirely correct. We are working on a fix in the library that handles resumable upload logic, google-api-go-client. Follow along at googleapis/google-api-go-client#1690

[tritone]

The fix has been released in google-api-go-client; we will bump the dependency in this library as well and release tomorrow.