ContentLength mismatch in blob upload #1004

Activity

1. deitch commented on Apr 28, 2021

   

   deitch

   on Apr 28, 2021

   CollaboratorAuthor

   More actions

   Hmm, I notice the failure to PUT the index occurred after pushing lots of other sub-manifests. It seems to have carried over the auth from one to the next for the others, but not for this one, hence the 401 and auth requirement.

   In the retry, it first does an index at GET https://index.docker.io/v2/, which forces an auth, then does a bunch of HEAD for the sub-manifests, and then PUT for the index. None of the steps after the index in this case forced a re-auth. Related? Red herring? 🤷‍♂️
2. jonjohnsonjr commented on Apr 28, 2021

   

   jonjohnsonjr

   on Apr 28, 2021

   Collaborator

   More actions

   The reauth theory is pretty good actually.

   If we hit an auth challenge, we perform the token exchange and retry the request in here.

   I'm guessing if there's a request body, the body gets consumed or closed during the token handshake, and the subsequent retry fails. We should probably stash the body somewhere before retrying -- not sure how to do this most idiomatically.
3. jonjohnsonjr commented on Jun 4, 2021

   

   jonjohnsonjr

   on Jun 4, 2021

   Collaborator

   More actions

   I can't remember if I even tried to fix this. Do you still hit this ever?
4. github-actions commented on Sep 3, 2021

   

   github-actionsbot

   on Sep 3, 2021

   More actions

   This issue is stale because it has been open for 90 days with no
   activity. It will automatically close after 30 more days of
   inactivity. Keep fresh with the 'lifecycle/frozen' label.
5. github-actions

   added

   lifecycle/stale

   on Sep 3, 2021
6. jonjohnsonjr

   added

   lifecycle/frozen

   and removed

   lifecycle/stale

   on Sep 3, 2021
7. deitch commented on Nov 8, 2021

   

   deitch

   on Nov 8, 2021

   CollaboratorAuthor

   More actions

   Coming back to this, as I keep coming across it. I often will retry, and then it goes fine, or sometimes not.

   Can this be a retry issue? I looked at the Moby source code, which just does 5 retries on errors, see here. I am not quite sure how our retries work?
8. jonjohnsonjr commented on Nov 8, 2021

   

   jonjohnsonjr

   on Nov 8, 2021

   Last edited by jonjohnsonjr

   Collaborator

   More actions

   I believe the problem is that we often retry failed requests without considering whether the body of the request has been consumed.

   For blob uploads, we actually wrap the whole blob upload in some retry logic, so we probably mask that issue when we just restart the upload from scratch.

   For manifest uploads, this was added somewhat recently: #1041

   What version are you using for this?

   It may also be the case that whatever error we're hitting because of the consumed request body doesn't pass our test of "shouldRetry"...

   My theory is:

   1. Original request gets 401 and has to reauth, here.
   2. After we reauth, we retry that request, here.
   3. The body of the request in has already been consumed, so the second request fails.

   Looking at http godoc, there are some interesting things to tug on: https://pkg.go.dev/net/http#Transport

   Transport only retries a request upon encountering a network error if the request is idempotent and either has no body or has its Request.GetBody defined. HTTP requests are considered idempotent if they have HTTP methods GET, HEAD, OPTIONS, or TRACE; or if their Header map contains an "Idempotency-Key" or "X-Idempotency-Key" entry. If the idempotency key value is a zero-length slice, the request is treated as idempotent but the header is not sent on the wire.

   We could use similar logic to the stdlib and start setting the GetBody method on our outgoing requests, as well as idempotency key headers, see here.

   (This would have the bonus effect of getting the http stdlib transport to help with retrying requests)

   We can do something similar to rewindBody after we auth: https://github.com/golang/go/blob/dbd3cf884986c88f5b3350709c0f51fa02330805/src/net/http/transport.go#L655-L676
9. deitch commented on Nov 8, 2021

   

   deitch

   on Nov 8, 2021

   CollaboratorAuthor

   More actions

   For manifest uploads

   Actually, the majority of the errors I see (anecdotally) are around manifests/indexes, not blobs. Everything is wrapped up in remote.Write() or remote.WriteIndex(), so I am working completely from memory and from log messages, but I am fairly confident that is the majority of what I am seeing.

   this was added somewhat recently
   What version are you using?

   My go.mod shows v0.4.1-0.20210208222243-cbafe638a7a9 so clearly earlier than the above. I will try an update in any case to see if it helps.

   My theory is:

   I like that theory. Those messages when it fails (not all of the time, but most of it), with:

   ContentLength=1821 with Body length 0
   

   fits pretty well with the theory.

   👍React with 👍1Reacted by Jon Johnson
10. jonjohnsonjr commented on Dec 31, 2021

    

    jonjohnsonjr

    on Dec 31, 2021

    Collaborator

    More actions

    I spent more time than I probably should have digging into https://github.com/golang/go/blob/6178d25fc0b28724b1b5aec2b1b74fc06d9294c7/src/net/http/transfer.go#L388-L391

    I cannot actually reproduce this failure to confirm my theory in any meaningful way with a unit test, but I did learn that golang will automagically set GetBody for certain request body types (which we fall into) so that the body can be rewound: https://github.com/golang/go/blob/6178d25fc0b28724b1b5aec2b1b74fc06d9294c7/src/net/http/request.go#L890-L912

    Unfortunately, it won't replay requests that aren't "safe" unless you set a magic header: https://github.com/golang/go/blob/4d8db00641cc9ff4f44de7df9b8c4f4a4f9416ee/src/net/http/request.go#L1415-L1429

    I'm going to do this for now for our PUT requests, which might help a bit?
11. joaopapereira commented on Feb 22, 2023

    

    joaopapereira

    on Feb 22, 2023

    Contributor

    More actions

    Hey, @jonjohnsonjr did you end up implementing what you suggested above? (Adding the header to the PUT request?)
    In imgpkg we are experiencing this issue when we are copying bundles that contain multiple large images to the registry. My assumption is that in the middle of the requests we do get a reauth and that is causing the same error reported here.
12. jonjohnsonjr commented on Feb 23, 2023

    

    jonjohnsonjr

    on Feb 23, 2023

    Collaborator

    More actions

    I did not! I think wrapping the the PUT in a retry solved this ~mostly:

    go-containerregistry/pkg/v1/remote/write.go

    Line 689 in 4a0e0af

    tryUpload := func() error {

    It is probably worth adding the header, if you're still seeing those failures. Do you have any way to repro or have logs?
13. joaopapereira commented on Feb 23, 2023

    

    joaopapereira

    on Feb 23, 2023

    Contributor

    More actions

    Hey,
    This is the amount of logs I have right now

    2023/02/08 19:43:47 <-- net/http: timeout awaiting response headers PUT https://my.registry.io/v2/my-package/manifests/sha256-423d64a60197ecf4bab1283df883a902b5fea8efff08e4c1dd2cb8e1151dc195.imgpkg (30.445465629s)
    2023/02/08 19:43:48 --> PUT https://my.registry.io/v2/my-package/manifests/sha256-423d64a60197ecf4bab1283df883a902b5fea8efff08e4c1dd2cb8e1151dc195.imgpkg
    2023/02/08 19:43:48 Failed to dump request PUT https://my.registry.io/v2/my-package/manifests/sha256-423d64a60197ecf4bab1283df883a902b5fea8efff08e4c1dd2cb8e1151dc195.imgpkg: http: ContentLength=915 with Body length 0
    2023/02/08 19:43:48 <-- http: ContentLength=915 with Body length 0 PUT https://my.registry.io/v2/my-package/manifests/sha256-423d64a60197ecf4bab1283df883a902b5fea8efff08e4c1dd2cb8e1151dc195.imgpkg (499.610204ms)
    2023/02/08 19:43:48 <-- context canceled PUT https://my.registry.io/v2/my-package/manifests/sha256-db1299f35bf28ac1d90a4dd2c8398d398be7e744e879b4df870eddf4a0b065f6.imgpkg (25.670816509s)
    2023/02/08 19:43:48 <-- context canceled PUT https://my.registry.io/v2/my-package/manifests/sha256-dbf0dedb6848ad8a7704c1c19465a1ddae9039b0e63c1dd0df3e2ed9cbda6093.imgpkg (884.515058ms)
    2023/02/08 19:43:48 <-- context canceled PUT https://my.registry.io/v2/my-package/manifests/sha256-b93ccb81309e767f9850ad90dac5986c25a86822dda0c8faee48bf0ab7c8f353.imgpkg (10.506871586s)
    2023/02/08 19:43:48 <-- context canceled PUT https://my.registry.io/v2/my-package/manifests/sha256-19d16a033e9605444f17e6066652ffbf4b10cef84e6e5846ecef78730cf4f2a0.imgpkg (20.406599514s)
    copy |
    copy | done uploading images
    
    
14. jonjohnsonjr commented on Feb 23, 2023

    

    jonjohnsonjr

    on Feb 23, 2023

    Collaborator

    More actions

    Thanks -- what version of go-containerregistry is that with?
15. joaopapereira commented on Apr 4, 2023

    

    joaopapereira

    on Apr 4, 2023

    Contributor

    More actions

    Sorry I dropped the ball on this. We were fairly up to date so I think it was 0.13.0
16. hunseonglee commented on Sep 16, 2026

    

    hunseonglee

    on Sep 16, 2026

    More actions

    I dug into this and I believe the http: ContentLength=N with Body length 0 failures come from the two places where we resend a request without rewinding its body:

    1. bearerTransport.RoundTrip: when we hit a WWW-Authenticate challenge we refresh the token and then call bt.inner.RoundTrip(in) again — but the first attempt already consumed in.Body, so the retried request goes out with an empty body while ContentLength is still set. This matches the debug logs above (manifest PUT gets a 401, reauth succeeds, the retried PUT fails).
    2. retryTransport.RoundTrip: temporary network errors are retried with the same, possibly consumed, request body.

    Following the direction discussed here, the fix mirrors what net/http's rewindBody does before it transparently retries a request: obtain a fresh body from req.GetBody before resending. GetBody is already populated for the affected requests — http.NewRequest sets it automatically for manifest PUTs (bytes.Buffer body), and streamBlob sets it explicitly for non-streaming layer PATCHes. Requests without GetBody (streaming layers) keep today's behavior.

    Opening a PR shortly.
17. hunseonglee

    added a commit that references this issue on Sep 16, 2026

    Rewind request body before retrying requests in transport

    ...

    This issue will close once commit 2d79185 is merged into the 'main' branch.

    2d79185