Content length issue with Docker Hub proxy cache and Containerd

[elchenberg]

I have an issue with my Harbor proxy cache and containerd.

Containerd seems to send a HEAD request to Harbor to get the digest and size of a tag manifest (request.method=HEAD url="https://my-registry-host.tld/v2/docker-hub/library/busybox/manifests/latest?ns=docker.io").

Harbor responds with (among others) a content-length and a docker-content-digest: response.header.content-length=2295 response.header.docker-content-digest="sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2" ).

Containerd then GETs the manifest using the digest (request.method=GET url="https://my-registry-host.tld/v2/docker-hub/library/busybox/manifests/sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2?ns=docker.io") and it expects the size to be 2295.

But Harbor now reports a different content-length (response.header.content-length=9517 response.header.docker-content-digest="sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2") and containerd's size validation fails.

I am not sure if there is something wrong with Harbor or with containerd. Is the content length in the first Harbor response wrong/outdated?

Harbor version: v2.9.1-5cbb1b01

Containerd version: 1.6.21 66c1fbccbaaac631b77184b7957e67fea4cf45ab

Containerd debug log:

Dec 18 11:57:04 my-hostname containerd[2341670]: time="2023-12-18T11:57:04.016289393Z" level=info msg="PullImage \"busybox:latest\""
Dec 18 11:57:04 my-hostname containerd[2341670]: time="2023-12-18T11:57:04.016343655Z" level=debug msg="PullImage using normalized image ref: \"docker.io/library/busybox:latest\""
Dec 18 11:57:04 my-hostname containerd[2341670]: time="2023-12-18T11:57:04.016736182Z" level=debug msg="do request" host=my-registry-host.tld request.header.accept="application/vnd.docker.distribution.manifest.v2+json, application/vnd.docker.distribution.manifest.list.v2+json, application/vnd.oci.image.manifest.v1+json, application/vnd.oci.image.index.v1+json, */*" request.header.user-agent=containerd/1.6.21 request.method=HEAD url="https://my-registry-host.tld/v2/docker-hub/library/busybox/manifests/latest?ns=docker.io"
Dec 18 11:57:04 my-hostname containerd[2341670]: time="2023-12-18T11:57:04.057507802Z" level=debug msg="fetch response received" host=my-registry-host.tld response.header.connection=keep-alive response.header.content-length=152 response.header.content-type="application/json; charset=utf-8" response.header.date="Mon, 18 Dec 2023 11:57:04 GMT" response.header.docker-distribution-api-version=registry/2.0 response.header.server=nginx response.header.set-cookie="sid=71b5d7e33be79cf029ccf2ec5ead9ca3; Path=/; HttpOnly" response.header.www-authenticate="Bearer realm=\"https://my-registry-host.tld/service/token\",service=\"harbor-registry\",scope=\"repository:docker-hub/library/busybox:pull\"" response.header.x-request-id=5f9f21ea-7aeb-4505-a9cc-b512f7326724 response.status="401 Unauthorized" url="https://my-registry-host.tld/v2/docker-hub/library/busybox/manifests/latest?ns=docker.io"
Dec 18 11:57:04 my-hostname containerd[2341670]: time="2023-12-18T11:57:04.057574978Z" level=debug msg=Unauthorized header="Bearer realm=\"https://my-registry-host.tld/service/token\",service=\"harbor-registry\",scope=\"repository:docker-hub/library/busybox:pull\"" host=my-registry-host.tld
Dec 18 11:57:04 my-hostname containerd[2341670]: time="2023-12-18T11:57:04.057615464Z" level=debug msg="do request" host=my-registry-host.tld request.header.accept="application/vnd.docker.distribution.manifest.v2+json, application/vnd.docker.distribution.manifest.list.v2+json, application/vnd.oci.image.manifest.v1+json, application/vnd.oci.image.index.v1+json, */*" request.header.user-agent=containerd/1.6.21 request.method=HEAD url="https://my-registry-host.tld/v2/docker-hub/library/busybox/manifests/latest?ns=docker.io"
Dec 18 11:57:04 my-hostname containerd[2341670]: time="2023-12-18T11:57:04.784200531Z" level=debug msg="fetch response received" host=my-registry-host.tld response.header.connection=keep-alive response.header.content-length=2295 response.header.content-security-policy="frame-ancestors 'none'" response.header.content-type=application/vnd.docker.distribution.manifest.list.v2+json response.header.date="Mon, 18 Dec 2023 11:57:04 GMT" response.header.docker-content-digest="sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2" response.header.etag="sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2" response.header.server=nginx response.header.set-cookie="sid=5a930f354521cb694f1a8135d8a80211; Path=/; HttpOnly" response.header.strict-transport-security="max-age=31536000; includeSubdomains; preload" response.header.x-frame-options=DENY response.header.x-request-id=6d30f49f-313a-41d7-a5e3-430941caac6d response.status="200 OK" url="https://my-registry-host.tld/v2/docker-hub/library/busybox/manifests/latest?ns=docker.io"
Dec 18 11:57:04 my-hostname containerd[2341670]: time="2023-12-18T11:57:04.785982207Z" level=debug msg="do request" digest="sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2" mediatype=application/vnd.docker.distribution.manifest.list.v2+json request.header.accept="application/vnd.docker.distribution.manifest.list.v2+json, */*" request.header.user-agent=containerd/1.6.21 request.method=GET size=2295 url="https://my-registry-host.tld/v2/docker-hub/library/busybox/manifests/sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2?ns=docker.io"
Dec 18 11:57:04 my-hostname containerd[2341670]: time="2023-12-18T11:57:04.801787800Z" level=debug msg="fetch response received" digest="sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2" mediatype=application/vnd.docker.distribution.manifest.list.v2+json response.header.connection=keep-alive response.header.content-length=152 response.header.content-type="application/json; charset=utf-8" response.header.date="Mon, 18 Dec 2023 11:57:04 GMT" response.header.docker-distribution-api-version=registry/2.0 response.header.server=nginx response.header.set-cookie="sid=845f42b2785df40023e8ef06d8768eb5; Path=/; HttpOnly" response.header.www-authenticate="Bearer realm=\"https://my-registry-host.tld/service/token\",service=\"harbor-registry\",scope=\"repository:docker-hub/library/busybox:pull\"" response.header.x-request-id=efb81af3-010f-4686-9f7f-d44d1f3a6542 response.status="401 Unauthorized" size=2295 url="https://my-registry-host.tld/v2/docker-hub/library/busybox/manifests/sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2?ns=docker.io"
Dec 18 11:57:04 my-hostname containerd[2341670]: time="2023-12-18T11:57:04.801841451Z" level=debug msg=Unauthorized digest="sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2" header="Bearer realm=\"https://my-registry-host.tld/service/token\",service=\"harbor-registry\",scope=\"repository:docker-hub/library/busybox:pull\"" mediatype=application/vnd.docker.distribution.manifest.list.v2+json size=2295
Dec 18 11:57:04 my-hostname containerd[2341670]: time="2023-12-18T11:57:04.801908517Z" level=debug msg="do request" digest="sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2" mediatype=application/vnd.docker.distribution.manifest.list.v2+json request.header.accept="application/vnd.docker.distribution.manifest.list.v2+json, */*" request.header.user-agent=containerd/1.6.21 request.method=GET size=2295 url="https://my-registry-host.tld/v2/docker-hub/library/busybox/manifests/sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2?ns=docker.io"
Dec 18 11:57:05 my-hostname containerd[2341670]: time="2023-12-18T11:57:05.531547077Z" level=debug msg="fetch response received" digest="sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2" mediatype=application/vnd.docker.distribution.manifest.list.v2+json response.header.connection=keep-alive response.header.content-length=9517 response.header.content-security-policy="frame-ancestors 'none'" response.header.content-type=application/vnd.oci.image.index.v1+json response.header.date="Mon, 18 Dec 2023 11:57:05 GMT" response.header.docker-content-digest="sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2" response.header.etag="sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2" response.header.server=nginx response.header.set-cookie="sid=77fc490cfa16a4f10ecbc3794095a852; Path=/; HttpOnly" response.header.strict-transport-security="max-age=31536000; includeSubdomains; preload" response.header.x-frame-options=DENY response.header.x-request-id=aa49a7c7-92ce-4cd5-9c32-6d495c438fa0 response.status="200 OK" size=2295 url="https://my-registry-host.tld/v2/docker-hub/library/busybox/manifests/sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2?ns=docker.io"
Dec 18 11:57:05 my-hostname containerd[2341670]: time="2023-12-18T11:57:05.532376645Z" level=error msg="PullImage \"busybox:latest\" failed" error="rpc error: code = FailedPrecondition desc = failed to pull and unpack image \"docker.io/library/busybox:latest\": failed commit on ref \"index-sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2\": \"index-sha256:5c63a9b46e7139d2d5841462859edcbbf57f238af891b6096578e5894cfe5ae2\" failed size validation: 9517 != 2295: failed precondition"

[yanji09]

It probably relates to this issue. #19429