Google-cloud-go: storage: retry logic for internal errors incompatible with compressed objects

[Keylor42]

Client

Google Cloud Storage

Environment

Alpine Docker on GKE

Reproduced locally with Ubuntu 18.04
go version go1.13.6 linux/amd64

Code

We have a CLI running in GKE that reads files in GCS containing logs and pushes them by batches into BigQuery. Those GCS files are stored with Content-Type "text/plain" and Content-Encoding "gzip". We cannot load them directly from GCS to BQ because they are in a specific format and they need some processing before being pushed.

Code is fairly long for the whole logic but here are the steps we have:

• We create several goroutines, each one processing the objects saved in one single GCS path.
• For each path we list the objects and create for each one of them a reader with bucket.Object(attrs.Name).ReadCompressed(false).NewReader(ctx)
• We read the content of the readers line-by-line with bufio.NewReader(reader) and bufReader.ReadBytes('\n'). All the log lines for a group of readers are sent to one channel, and we create also a channel of errors.
• We select on those two channels in a loop. that takes the lines, process them, and send them by batch in BigQuery.

Expected behavior

Files are successfully read from GCS during the process.

Actual behavior

We have "storage: partial error not satisfied" errors regularly triggered in production. This error is not transient and appears systematically on a job fetching logs for a specific time range. We retry the job 10 times, it fails 10 times with this same error. Seems also that this error appears when there is a lot of files to process (22 for our test directory, files in the directory are around 7mo compressed, and 50 mo uncompressed).

Digging in the storage library code, the error is triggered in cloud.google.com/go/storage/reader.go, in the reopen closure. If I print the start, seen and offset values at the beginning of the closure after line 132, I usually see 0, 0, and 0 then objects are correctly opened and read. When the error is triggered, the function is called after a first retryable error (stream error: stream ID X; INTERNAL_ERROR). In this case, the values of start, seen and offset are not zero but something like 28642505, 28642505, and 0.

Since start is above 0 it triggers this condition, where res.StatusCode is checked against http.StatusPartialContent. Printing the status code of the response, it's 200 OK, and if I get the content of the body it looks correct. So I wonder why an error is triggered while we have an OK response with a correct body.

Then I saw this issue https://github.com/googleapis/google-cloud-go/issues/784 that introduced the retryable logic when having the INTERNAL_ERROR error, and this issue https://github.com/googleapis/google-cloud-go/issues/1734 about RangeReader not doing partial requests for gzip-compressed files but sending the whole object instead. It seems to me that we are in this situation where

• a INTERNAL_ERROR error is triggered
• a retry is done with a range request
• since the object is compressed it is returned entirely with code 200 and triggers the error.

On our side we never call NewRangeReader on our compressed files by ourselves. That's why I would expect the GCS client to check if the requested object is compressed or not and adapt the code to handle this situation, instead of sending back the error "partial request not satisfied".

[odeke-em]

@Keylor42 thank you for filing this bug and for the patience!

So given that the logic is fairly long and most likely proprietary code that you can't share, here is a fully standing mock GCS server that perhaps we can use a seed to recreate the error without having to go outside the network, so should be fast, easier and fully in our control. I've added some gzip data and the appropriate Content-Encoding of "gzip".

If you could please help me add the logic that closely recreates the problem, that'll aid in answering this question here and you'll need Go1.14 for it so that we can trivially create an HTTP/2 server

package main

import (
    "bytes"
    "compress/gzip"
    "context"
    "fmt"
    "io"
    "net/http"
    "net/http/httptest"
    "net/url"
    "os"
    "sync"

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

type alwaysToDestRoundTripper struct {
    destURL *url.URL
    hc      *http.Client
}

func (adrt *alwaysToDestRoundTripper) RoundTrip(req *http.Request) (*http.Response, error) {
    req.URL.Host = adrt.destURL.Host
    return adrt.hc.Do(req)
}

func main() {
    var bufMu sync.Mutex
    buf := new(bytes.Buffer)
    gzw := gzip.NewWriter(buf)
    original := "This is the code to be compressed"
    for i := 0; i < 100; i++ {
        if _, err := gzw.Write([]byte(original)); err != nil {
            panic(err)
        }
    }
    if err := gzw.Close(); err != nil {
        panic(err)
    }

    cst := httptest.NewUnstartedServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        switch r.URL.Path {
        case "/b/bucket/o/object":
            fmt.Fprintf(w, `{
                            "bucket": "bucket", "name": "name", "contentEncoding": "gzip",
                            "contentLength": 130000, "contentType": "text/plain",
                            "timeCreated": "2020-04-10T16:08:58-07:00", "updated": "2020-04-14T16:08:58-07:00"
                        }`)
            return

        case "/bucket/object":
            w.Header().Set("Content-Encoding", "gzip")
            w.Header().Set("Content-Length", fmt.Sprintf("%d", buf.Len()))
            bufMu.Lock()
            defer bufMu.Unlock()

            rHalfway := io.LimitReader(buf, int64(buf.Len()/2))
            io.Copy(w, rHalfway)

                        panic("Halfway through and cause a stream error")
            defer buf.Reset()

        default:
            panic(r.URL.Path + " is not yet being handled")
        }
    }))
    cst.EnableHTTP2 = true
    cst.StartTLS()
    defer cst.Close()

    ctx := context.Background()
    hc := cst.Client()
    ux, _ := url.Parse(cst.URL)
    hc.Transport.(*http.Transport).TLSClientConfig.InsecureSkipVerify = true
    wrt := &alwaysToDestRoundTripper{
        destURL: ux,
        hc:      hc,
    }

    whc := &http.Client{Transport: wrt}
    client, err := storage.NewClient(ctx, option.WithEndpoint(cst.URL), option.WithoutAuthentication(), option.WithHTTPClient(whc))
    if err != nil {
        panic(err)
    }

    obj := client.Bucket("bucket").Object("object")
    if _, err := obj.Attrs(ctx); err != nil {
        panic(err)
    }

    rd, err := obj.ReadCompressed(false).NewReader(ctx)
    if err != nil {
            fmt.Printf("Got an error: %v", err)
            return
    }
    defer rd.Close()

    io.Copy(os.Stdout, rd)
}

EDIT: I've added a panic in the server so that it can create a stream error aka stream error: stream ID 3; INTERNAL_ERROR

[odeke-em]

@Keylor42 I've updated the seed server repro to now cause a stream error so covering scenario a)

go run main.go 
2020/04/14 16:54:13 http2: panic serving 127.0.0.1:49518: Halfway through and cause a stream error
goroutine 51 [running]:
net/http.(*http2serverConn).runHandler.func1(0xc00042a0d8, 0xc000405f8e, 0xc000001500)
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/net/http/h2_bundle.go:5705 +0x16b
panic(0x151df40, 0x16c5430)
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/runtime/panic.go:969 +0x166
main.main.func1(0x16db440, 0xc00042a0d8, 0xc000422400)
    /Users/emmanuelodeke/Desktop/openSrc/bugs/google-cloud-go/1800/main.go:62 +0x52c
net/http.HandlerFunc.ServeHTTP(0xc0000b0980, 0x16db440, 0xc00042a0d8, 0xc000422400)
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/net/http/server.go:2012 +0x44
net/http.serverHandler.ServeHTTP(0xc0003c4000, 0x16db440, 0xc00042a0d8, 0xc000422400)
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/net/http/server.go:2808 +0xa3
net/http.initALPNRequest.ServeHTTP(0x16dc680, 0xc00007c1e0, 0xc000288000, 0xc0003c4000, 0x16db440, 0xc00042a0d8, 0xc000422400)
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/net/http/server.go:3380 +0x8d
net/http.(*http2serverConn).runHandler(0xc000001500, 0xc00042a0d8, 0xc000422400, 0xc000408280)
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/net/http/h2_bundle.go:5712 +0x8b
created by net/http.(*http2serverConn).processHeaders
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/net/http/h2_bundle.go:5446 +0x4db
Got an error: Get "https://127.0.0.1:49517/bucket/object": Get "https://127.0.0.1:49517/bucket/object": stream error: stream ID 3; INTERNAL_ERROR

Please help me plug in the rest to ensure a retry and then a server. We can ensure that the server returns in that order by counting the number of fetches by a specific requesting client: on the first one, panic to return a stream error; start the retry, on the second request, send back the entirely compressed object.

[Keylor42]

Hello Emmanuel, thanks for your help. I managed to reproduce the issue with the code you provided. As you suggested, the first call to the server returns an error, the second one returns the complete object. Here's the code:

```go 1.14
package main

import (
"bufio"
"bytes"
"compress/gzip"
"context"
"fmt"
"io"
"net/http"
"net/http/httptest"
"net/url"
"strings"
"sync"

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

)

type alwaysToDestRoundTripper struct {
destURL *url.URL
hc *http.Client
}

func (adrt alwaysToDestRoundTripper) RoundTrip(req *http.Request) (http.Response, error) {
req.URL.Host = adrt.destURL.Host
return adrt.hc.Do(req)
}

func main() {
var bufMu sync.Mutex
buf := new(bytes.Buffer)
gzw := gzip.NewWriter(buf)
original := strings.Repeat("I am a line\n", 1000000)
if _, err := gzw.Write([]byte(original)); err != nil {
panic(err)
}
if err := gzw.Close(); err != nil {
panic(err)
}

i := 0
cst := httptest.NewUnstartedServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
    switch r.URL.Path {
    case "/b/bucket/o/object":
        fmt.Fprintf(w, `{
                        "bucket": "bucket", "name": "name", "contentEncoding": "gzip",
                        "contentLength": %d, "contentType": "text/plain",
                        "timeCreated": "2020-04-10T16:08:58-07:00", "updated": "2020-04-14T16:08:58-07:00"
                    }`, buf.Len())
        return

    case "/bucket/object":
        i++
        w.Header().Set("Content-Encoding", "gzip")
        w.Header().Set("Content-Length", fmt.Sprintf("%d", buf.Len()))

        bufMu.Lock()
        defer bufMu.Unlock()
        defer buf.Reset()

        if i == 1 {
            // first call, we trigger an error.
            rHalfway := io.LimitReader(buf, int64(buf.Len()/2))
            _, _ = io.Copy(w, rHalfway)
            panic("Halfway through and cause a stream error")
        } else {
            // second call, send back the data in full.
            _, _ = w.Write(buf.Bytes())
        }

    default:
        panic(r.URL.Path + " is not yet being handled")
    }
}))
cst.EnableHTTP2 = true
cst.StartTLS()
defer cst.Close()

ctx := context.Background()
hc := cst.Client()
ux, _ := url.Parse(cst.URL)
hc.Transport.(*http.Transport).TLSClientConfig.InsecureSkipVerify = true
wrt := &alwaysToDestRoundTripper{
    destURL: ux,
    hc:      hc,
}

whc := &http.Client{Transport: wrt}
client, err := storage.NewClient(ctx, option.WithEndpoint(cst.URL), option.WithoutAuthentication(), option.WithHTTPClient(whc))
if err != nil {
    panic(err)
}

obj := client.Bucket("bucket").Object("object")
if _, err := obj.Attrs(ctx); err != nil {
    panic(err)
}

err = ReadGCSFile(ctx, obj)
if err != nil {
    fmt.Println("got error while reading:", err)
}

}

// ReadGCSFile reads a compressed GCS file line by line.
func ReadGCSFile(ctx context.Context, oh *storage.ObjectHandle) error {
reader, err := oh.ReadCompressed(false).NewReader(ctx)
if err != nil {
return err
}
defer reader.Close()

lines, errs := ReadLines(ctx, reader)
for {
    select {
    case err := <-errs:
        return err

    case line, ok := <-lines:
        if !ok {
            if len(line) > 0 {
                _ = line
            }
            return nil
        }

        // process the line.
        _ = line
    }
}

}

// ReadLines consumes all the readers passed as parameters line by line.
func ReadLines(ctx context.Context, reader io.ReadCloser) (<-chan []byte, <-chan error) {
lines := make(chan []byte)
errors := make(chan error)

go func() {
    err := readLines(ctx, reader, lines)
    if err != nil {
        errors <- err
    }

    close(lines)
}()

return lines, errors

}

func readLines(
ctx context.Context,
reader io.ReadCloser,
lines chan<- []byte,
) error {
bufReader := bufio.NewReader(reader)
for {
line, err := bufReader.ReadBytes('\n')
if err == io.EOF {
// in case the data is not \n terminated, return the bytes read.
if len(line) > 0 {
lines <- line
}
return nil
}
if err != nil {
return err
}

    select {
    case <-ctx.Done():
        return ctx.Err()
    case lines <- line:
    }
}

}

Running this code returns the error I mentioned:

got error while reading: storage: partial request not satisfied

FYI the content of the go.mod:

go 1.14

require (
cloud.google.com/go/storage v1.6.0
google.golang.org/api v0.21.0
)
```

[odeke-em]

Thank you for the updates @Keylor42!

I mentally ran through a whole bunch of scenarios to confirm the behavior and then I also confirmed my scenarios and your bug report by your bug's prescription:
a) Content-Type: text/plain
b) Content-Encoding: gzip

which trigger's GCS' decompressive transcoding as per https://cloud.google.com/storage/docs/transcoding#range

Issues

a) GCS acknowledges that if in the scenario of decompresive transcoding, the Range header is silently ignored and the entire file will be served back regardless of what range you pass in, so won't serve back a 206 Partial code status regardless
b) The logic in the GCS reader ALWAYS assumes that range headers will ALWAYS return a 206 Partial Content header
c) That HTTP/2 stream error can occur if GCS decides to terminate your connection say if it hasn't been used in a long time

This issue boils down to https://cloud.google.com/storage/docs/transcoding#range

aka these libraries haven't yet considered the case for Content-Encoding: gzip

Another issue here is that if you try to use the RangeReader on Content-Encoding: gzip files,
this reader error out with a 400 Bad Request.

Remedy

We can fix this by:
a) Checking the Content-Encoding and if we know decompressive transcoding applies, just permit reading to go on and also drop range requests if performsDecompressiveTranscoding(Attrs.ContentEncoding)

You found a niche case, and thank you! Perhaps all the respective language's client library implementations should implement the same logic to handle decompressive transcoding.

I shall mail a CL shortly.

[odeke-em]

I've mailed out https://code-review.googlesource.com/c/gocloud/+/54791 for this issue. Hopefully it should land soon and then we'll make a module update and then you should be on your way without disruptions.

[Keylor42]

Thanks a lot for your responsiveness.

To clarify something: I see in your PR this comment

If the object's metadata property "Content-Encoding" is set to "gzip" or satisfies
decompressive transcoding per https://cloud.google.com/storage/docs/transcoding
that file will be served back whole, regardless of the requested range as
Google Cloud Storage dictates.

Could it mean that we would end up reading some parts of the file twice ? If you take back my example, in the case where the error is sent, we already read half of the file and some lines might have already been processed. If the file is sent back full, does it mean that we could reprocess some lines ? Or there is an internal mechanism in the GCS client that somehow knows what we already read and does not reprocess it ?

[odeke-em]

Indeed, the whole file is served twice.

In either case GCS doesn’t allow range seeks so there is no way it can try
from a different range. Unfortunately there isn’t such a thing as resumable
downloads, unlike resumable uploads.

In regards to all processed bytes, we can internally try to recall where
our watermark was and the combination of conditions, but this has an edge
case for example if the file changed while we were downloading it, and then
also our stream expired, what do we do? What if the HTTP/2 stream was from
a security violation or tamper? Do we resume reading from where we were?

On Thu, Apr 16, 2020 at 1:35 AM Keylor42 [e-mail] wrote:

Thanks a lot for your responsiveness.

To clarify something: I see in your PR this comment

If the object's metadata property "Content-Encoding" is set to "gzip" or
satisfies
decompressive transcoding per
https://cloud.google.com/storage/docs/transcoding
that file will be served back whole, regardless of the requested range as
Google Cloud Storage dictates.

Could it mean that we would end up reading some parts of the file twice ?
If you take back my example, in the case where the error is sent, we
already read half of the file and some lines might have already been
processed. If the file is sent back full, does it mean that we could
reprocess some lines ? Or there is an internal mechanism in the GCS client
that somehow knows what we already read and does not reprocess it ?

—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub
https://github.com/googleapis/google-cloud-go/issues/1800#issuecomment-614500657,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/ABFL3V37LNJLWHZFSUTRXH3RM27N7ANCNFSM4K3IHIDA
.

[Keylor42]

OK, sure I understand. That's something we would need to handle on our side then. The only problem I see here is that it looks like we, as the GCS library users, don't have any way to know if the file has been re-read. But perhaps it's out of the scope of this issue.

[odeke-em]

Am going to implement a compromise in there but it will be experimental and
have an explanation for why we do it, so basically a manual state to then
discard prior bytes until a checksum is achieved and corresponding prior
byte count, then start from there after the retry. I think that’ll solve
the problem. I’ll do so when I get up in the morning. Thank for raising it
too.

On Thu, Apr 16, 2020 at 2:22 AM Keylor42 [e-mail] wrote:

OK, sure I understand. That's something we would need to handle on our
side then. The only problem I see here is that it looks like we, as the GCS
library users, don't have any way to know if the file has been re-read. But
perhaps it's out of the scope of this issue.

—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub
https://github.com/googleapis/google-cloud-go/issues/1800#issuecomment-614526465,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/ABFL3VYMTGJRYFKWFAI6PVLRM3E4VANCNFSM4K3IHIDA
.

[odeke-em]

@Keylor42 I've added the post retry discard of already seen bytes and when tested with

package main

import (
    "bufio"
    "bytes"
    "compress/gzip"
    "context"
    "crypto/md5"
    "fmt"
    "io"
    "io/ioutil"
    "net/http"
    "net/http/httptest"
    "net/url"

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

type palwaysToDestRoundTripper struct {
    destURL *url.URL
    hc      *http.Client
}

func (adrt *palwaysToDestRoundTripper) RoundTrip(req *http.Request) (*http.Response, error) {
    req.URL.Host = adrt.destURL.Host
    delete(req.Header, "Range")
    return adrt.hc.Do(req)
}

func main() {
    original := bytes.Repeat([]byte("I am a line\n"), 1000000)
    if err := ioutil.WriteFile("testing.txt", []byte(original), 0755); err != nil {
        panic(err)
    }

    i := 0
    cst := httptest.NewUnstartedServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        switch r.URL.Path {
        case "/b/bucket/o/object":
            fmt.Fprintf(w, `{
                            "bucket": "bucket", "name": "name", "contentEncoding": "gzip",
                            "contentLength": 43,
                            "contentType": "text/plain","timeCreated": "2020-04-10T16:08:58-07:00",
                            "updated": "2020-04-14T16:08:58-07:00"
                        }`)
            return

        default:
            i++
            // Serve back the file.
            w.Header().Set("Content-Type", "text/plain")
            w.Header().Set("Etag", `"c50e3e41c9bc9df34e84c94ce073f928"`)
            w.Header().Set("X-Goog-Generation", "1587012235914578")
            w.Header().Set("X-Goog-MetaGeneration", "2")
            w.Header().Set("X-Goog-Stored-Content-Encoding", "gzip")
            w.Header().Set("vary", "Accept-Encoding")
            w.Header().Set("x-goog-stored-content-length", "43")
            w.Header().Set("x-goog-storage-class", "STANDARD")
            if i == 1 {
                // When Google Cloud Storage serves it back, it will
                // be decompressed but it is impossible for us to half decompress
                // a file, hence we sent it here in the original form but halfway.
                w.Write(original[:len(original)/2])
                panic("Halfway through")
            } else {
                w.Header().Set("x-goog-hash", "crc32c=pYIWwQ==")
                w.Header().Set("x-goog-hash", "md5=xQ4+Qcm8nfNOhMlM4HP5KA==")
                w.Header().Set("Content-Encoding", "gzip")
                gz := gzip.NewWriter(w)
                gz.Write(original)
                gz.Close()
            }
        }
    }))
    cst.EnableHTTP2 = true
    cst.StartTLS()
    defer cst.Close()

    ctx := context.Background()
    hc := cst.Client()
    ux, _ := url.Parse(cst.URL)
    hc.Transport.(*http.Transport).TLSClientConfig.InsecureSkipVerify = true
    wrt := &palwaysToDestRoundTripper{
        destURL: ux,
        hc:      hc,
    }

    whc := &http.Client{Transport: wrt}
    client, err := storage.NewClient(ctx, option.WithEndpoint(cst.URL), option.WithoutAuthentication(), option.WithHTTPClient(whc))
    if err != nil {
        panic(err)
    }

    obj := client.Bucket("bucket").Object("object")
    if _, err := obj.Attrs(ctx); err != nil {
        panic(err)
    }

    rd, err := obj.NewRangeReader(ctx, 0, 1001)
    if err != nil {
        panic(err)
    }
    h := md5.New()
    _, _ = io.Copy(h, rd)
    _ = rd.Close()
    gotMD5 := fmt.Sprintf("%x", h.Sum(nil))

    h.Reset()
    h.Write([]byte(original))
    wantMD5 := fmt.Sprintf("%x", h.Sum(nil))
    fmt.Printf("GotMD5:  %q\nWantMD5: %q\n", gotMD5, wantMD5)
    if gotMD5 != wantMD5 {
        panic("MD5 checksum mismatch:\nGot:  " + gotMD5 + "\nWant: " + wantMD5)
    }

    if err := ReadGCSFile(ctx, obj); err != nil {
        fmt.Println("got error while reading:", err)
    }
}

// ReadGCSFile reads a compressed GCS file line by line.
func ReadGCSFile(ctx context.Context, oh *storage.ObjectHandle) error {
    reader, err := oh.ReadCompressed(false).NewReader(ctx)
    if err != nil {
        return err
    }
    defer reader.Close()

    lines, errs := ReadLines(ctx, reader)
    for {
        select {
        case err := <-errs:
            return err

        case line, ok := <-lines:
            if !ok {
                if len(line) > 0 {
                    _ = line
                }
                return nil
            }

            // process the line.
            _ = line
        }
    }
}

// ReadLines consumes all the readers passed as parameters line by line.
func ReadLines(ctx context.Context, reader io.ReadCloser) (<-chan []byte, <-chan error) {
    lines := make(chan []byte)
    errors := make(chan error)

    go func() {
        err := readLines(ctx, reader, lines)
        if err != nil {
            errors <- err
        }

        close(lines)
    }()

    return lines, errors
}

func readLines(
    ctx context.Context,
    reader io.ReadCloser,
    lines chan<- []byte,
) error {
    bufReader := bufio.NewReader(reader)
    for {
        line, err := bufReader.ReadBytes('\n')
        if err == io.EOF {
            // in case the data is not \n terminated, return the bytes read.
            if len(line) > 0 {
                lines <- line
            }
            return nil
        }
        if err != nil {
            return err
        }

        select {
        case <-ctx.Done():
            return ctx.Err()
        case lines <- line:
        }
    }
}

we get back

$ GO111MODULE=off go run main.go 
2020/04/16 10:07:32 http2: panic serving 127.0.0.1:58102: Halfway through
goroutine 22 [running]:
net/http.(*http2serverConn).runHandler.func1(0xc00009c0b8, 0xc000069f8e, 0xc001082300)
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/net/http/h2_bundle.go:5705 +0x16b
panic(0x15c5ca0, 0x17a33f0)
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/runtime/panic.go:969 +0x166
main.main.func1(0x17bbb20, 0xc00009c0b8, 0xc0000c2300)
    /Users/emmanuelodeke/Desktop/openSrc/bugs/google-cloud-go/1800/main.go:65 +0xcb6
net/http.HandlerFunc.ServeHTTP(0xc0001107e0, 0x17bbb20, 0xc00009c0b8, 0xc0000c2300)
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/net/http/server.go:2012 +0x44
net/http.serverHandler.ServeHTTP(0xc000012000, 0x17bbb20, 0xc00009c0b8, 0xc0000c2300)
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/net/http/server.go:2808 +0xa3
net/http.initALPNRequest.ServeHTTP(0x17bcca0, 0xc00047c000, 0xc000116000, 0xc000012000, 0x17bbb20, 0xc00009c0b8, 0xc0000c2300)
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/net/http/server.go:3380 +0x8d
net/http.(*http2serverConn).runHandler(0xc001082300, 0xc00009c0b8, 0xc0000c2300, 0xc0000ae200)
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/net/http/h2_bundle.go:5712 +0x8b
created by net/http.(*http2serverConn).processHeaders
    /Users/emmanuelodeke/go/src/go.googlesource.com/go/src/net/http/h2_bundle.go:5446 +0x4db
GotMD5:  "90d6ab70c7e44d6b3ccdec8658b56f69"
WantMD5: "90d6ab70c7e44d6b3ccdec8658b56f69"

where the most import thing are the checksums

GotMD5:  "90d6ab70c7e44d6b3ccdec8658b56f69"
WantMD5: "90d6ab70c7e44d6b3ccdec8658b56f69"

which shows that they match and the file is exactly returned to the user regardless of retries.