google / google/go-containerregistry
ContentLength mismatch in blob upload
- Dominant language
- Go
- Stars
- 4k
- Forks
- 686
- Avg merge
- 2d 12h
- Merged PRs (30d)
- 26
Description
I am having an intermittent issue with ContentLength mismatch. It may be registry-side related, I cannot reproduce it reliably, but if I call a lot of pushes, it does show up with some regularity.
I ran with debug logging enabled, here is what I got, when pushing an image from linuxkit, filtered some of the irrelevant data out:
```
INFO[0555] index.docker.io/linuxkit/containerd@sha256:5dd3ad98ff8da74de6ceb9c609bb0b7302f4b305663507c38efc56b243b34c6f: digest: sha256:5dd3ad98ff8da74de6ceb9c609bb0b7302f4b305663507c38efc56b243b34c6f size: 1311
DEBU[0555] --> PUT https://index.docker.io/v2/linuxkit/containerd/manifests/cc02c2af9c928c2faeccbe4edc78bd297ad91866
DEBU[0555] PUT /v2/linuxkit/containerd/manifests/cc02c2af9c928c2faeccbe4edc78bd297ad91866 HTTP/1.1
DEBU[0555] Host: index.docker.io
DEBU[0555] User-Agent: go-containerregistry/v0.4.1-0.20210208222243-cbafe638a7a9
DEBU[0555] Content-Length: 1821
DEBU[0555] Authorization:
DEBU[0555] Content-Type: application/vnd.oci.image.index.v1+json
DEBU[0555] Accept-Encoding: gzip
DEBU[0555]
DEBU[0555] ... lots of json ...
DEBU[0555] <-- 401 https://index.docker.io/v2/linuxkit/containerd/manifests/cc02c2af9c928c2faeccbe4edc78bd297ad91866 (156.197508ms)
DEBU[0555] HTTP/1.1 401 Unauthorized
DEBU[0555] Connection: close
DEBU[0555] Content-Length: 240
DEBU[0555] Content-Type: application/json
DEBU[0555] Date: Wed, 28 Apr 2021 09:15:23 GMT
DEBU[0555] Docker-Distribution-Api-Version: registry/2.0
DEBU[0555] Www-Authenticate: Bearer realm="https://auth.docker.io/token",service="registry.docker.io",scope="repository:linuxkit/containerd:pull,push",error="invalid_token"
DEBU[0555]
DEBU[0555] {"errors":[{"code":"UNAUTHORIZED","message":"authentication required","detail":[{"Type":"repository","Class":"","Name":"linuxkit/containerd","Action":"pull"},{"Type":"repository","Class":"","Name":"linuxkit/containerd","Action":"push"}]}]}
DEBU[0555]
DEBU[0555] --> GET https://auth.docker.io/token?scope=repository%3Alinuxkit%2Fcontainerd%3Apush%2Cpull&scope=repository%3Alinuxkit%2Fcontainerd%3Apull%2Cpush&service=registry.docker.io [body redacted: basic token response contains credentials]
DEBU[0555] GET /token?scope=repository%3Alinuxkit%2Fcontainerd%3Apush%2Cpull&scope=repository%3Alinuxkit%2Fcontainerd%3Apull%2Cpush&service=registry.docker.io HTTP/1.1
DEBU[0555] Host: auth.docker.io
DEBU[0555] User-Agent: go-containerregistry/v0.4.1-0.20210208222243-cbafe638a7a9
DEBU[0555] Authorization:
DEBU[0555] Accept-Encoding: gzip
DEBU[0555]
DEBU[0555]
DEBU[0556] <-- 200 https://auth.docker.io/token?scope=repository%3Alinuxkit%2Fcontainerd%3Apush%2Cpull&scope=repository%3Alinuxkit%2Fcontainerd%3Apull%2Cpush&service=registry.docker.io (695.513841ms) [body redacted: basic token response contains credentials]
DEBU[0556] HTTP/1.1 200 OK
DEBU[0556] Transfer-Encoding: chunked
DEBU[0556] Content-Type: application/json
DEBU[0556] Date: Wed, 28 Apr 2021 09:15:24 GMT
DEBU[0556] Strict-Transport-Security: max-age=31536000
DEBU[0556]
DEBU[0556]
DEBU[0556] --> PUT https://index.docker.io/v2/linuxkit/containerd/manifests/cc02c2af9c928c2faeccbe4edc78bd297ad91866
DEBU[0556] Failed to dump request PUT https://index.docker.io/v2/linuxkit/containerd/manifests/cc02c2af9c928c2faeccbe4edc78bd297ad91866: http: ContentLength=1821 with Body length 0
DEBU[0556] <-- http: ContentLength=1821 with Body length 0 PUT https://index.docker.io/v2/linuxkit/containerd/manifests/cc02c2af9c928c2faeccbe4edc78bd297ad91866 (553.890807ms)
Put "https://index.docker.io/v2/linuxkit/containerd/manifests/cc02c2af9c928c2faeccbe4edc78bd297ad91866": http: ContentLength=1821 with Body length 0
```
It tries to put a manifest, gets a `401`, goes to authorize, goes back with it, and gets an error. It doesn't look like it is an http error, but I cannot tell from the logs.
Interestingly, that error line looks like it comes from [here](https://github.com/google/go-containerregistry/blob/23990dab37bf92ee1207207091c9eebe549aa725/pkg/v1/remote/transport/logger.go#L58), but based on that code, it should not error out. Yet in this case it definitely does with a non-zero exit code (which I wish I had thought to capture).
When I reran, it went just fine:
```
DEBU[0023] --> PUT https://index.docker.io/v2/linuxkit/containerd/manifests/cc02c2af9c928c2faeccbe4edc78bd297ad91866
DEBU[0023] PUT /v2/linuxkit/containerd/manifests/cc02c2af9c928c2faeccbe4edc78bd297ad91866 HTTP/1.1
DEBU[0023] Host: index.docker.io
DEBU[0023] User-Agent: go-containerregistry/v0.4.1-0.20210208222243-cbafe638a7a9
DEBU[0023] Content-Length: 1821
DEBU[0023] Authorization:
DEBU[0023] Content-Type: application/vnd.oci.image.index.v1+json
DEBU[0023] Accept-Encoding: gzip
DEBU[0023]
DEBU[0023] ... lots of json content ...
DEBU[0023] <-- 201 https://index.docker.io/v2/linuxkit/containerd/manifests/cc02c2af9c928c2faeccbe4edc78bd297ad91866 (316.634923ms)
DEBU[0023] HTTP/1.1 201 Created
DEBU[0023] Content-Length: 0
DEBU[0023] Date: Wed, 28 Apr 2021 09:29:33 GMT
DEBU[0023] Docker-Content-Digest: sha256:ebd295492eff4e096bfeaa4f09cc4013c629a72c41056afee26a49419b47a75d
DEBU[0023] Docker-Distribution-Api-Version: registry/2.0
DEBU[0023] Location: https://index.docker.io/v2/linuxkit/containerd/manifests/sha256:ebd295492eff4e096bfeaa4f09cc4013c629a72c41056afee26a49419b47a75d
DEBU[0023] Strict-Transport-Security: max-age=31536000
DEBU[0023]
INFO[0023] linuxkit/containerd:cc02c2af9c928c2faeccbe4edc78bd297ad91866: digest: sha256:ebd295492eff4e096bfeaa4f09cc4013c629a72c41056afee26a49419b47a75d size: 1821
```
Contributor guide
Assessment
This issue has not been assessed yet.