"Response payload is not completed" when pointed to a pull-thru cache

[AstraLuma]

os.environ['DRCA_DEFAULT_REGISTRY'] = 'mirror.redacted.com'

from docker_registry_client_async import DockerRegistryClientAsync, FormattedSHA256, ImageName, Manifest

async def test():
    async with DockerRegistryClientAsync() as drca:
        name = ImageName.parse("busybox:1.30.1")
        result = await drca.get_manifest(name)
        manifest = result["manifest"].get_json()
        print(manifest)
        config_digest = FormattedSHA256.parse(manifest["config"]["digest"])
        mime = manifest['config']['mediaType']
        result = await drca.get_blob(name, config_digest, accept=mime)
        config = json.loads(result["blob"].decode("utf-8"))
        print(config)

asyncio.run(test())

$ ./python-pull.py 
{'schemaVersion': 2, 'mediaType': 'application/vnd.docker.distribution.manifest.v2+json', 'config': {'mediaType': 'application/vnd.docker.container.image.v1+json', 'size': 1496, 'digest': 'sha256:64f5d945efcc0f39ab11b3cd4ba403cc9fefe1fa3613123ca016cf3708e8cafb'}, 'layers': [{'mediaType': 'application/vnd.docker.image.rootfs.diff.tar.gzip', 'size': 755813, 'digest': 'sha256:53071b97a88426d4db86d0e8436ac5c869124d2c414caf4c9e4a4e48769c7f37'}]}
Traceback (most recent call last):
  File "./python-pull.py", line 75, in <module>
    asyncio.run(test())
  File "/usr/lib/python3.8/asyncio/runners.py", line 43, in run
    return loop.run_until_complete(main)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 608, in run_until_complete
    return future.result()
  File "./python-pull.py", line 71, in test
    result = await drca.get_blob(name, config_digest, accept=mime)
  File "/dogfood-home/eng_home/jbliss/ptc-testing/.venv/lib/python3.8/site-packages/docker_registry_client_async/dockerregistryclientasync.py", line 499, in get_blob
    data = await client_response.read()
  File "/dogfood-home/eng_home/jbliss/ptc-testing/.venv/lib/python3.8/site-packages/aiohttp/client_reqrep.py", line 973, in read
    self._body = await self.content.read()
  File "/dogfood-home/eng_home/jbliss/ptc-testing/.venv/lib/python3.8/site-packages/aiohttp/streams.py", line 358, in read
    block = await self.readany()
  File "/dogfood-home/eng_home/jbliss/ptc-testing/.venv/lib/python3.8/site-packages/aiohttp/streams.py", line 380, in readany
    await self._wait('readany')
  File "/dogfood-home/eng_home/jbliss/ptc-testing/.venv/lib/python3.8/site-packages/aiohttp/streams.py", line 296, in _wait
    await waiter
aiohttp.client_exceptions.ClientPayloadError: Response payload is not completed

mirror.redacted.com is running registry:2 in mirror mode. Removing the environ set causes the problem to go away.

[AstraLuma]

This might actually be an upstream issue. https://github.com/docker/distribution/issues/3264 I can reproduce in curl.

[crashvb]

Do you see any errors in the redacted registry log during the blob retrieval? (i.e. does this happen when priming the cache, or on subsequent invocations too?)

https://docs.docker.com/registry/recipes/mirror/#configure-the-docker-daemon:

time="2017-06-02T15:47:37Z" level=info msg="error statting local store, serving from upstream: unknown blob" go.version=go1.7.4

It’s telling you that the file doesn’t exist yet in the local cache and is being pulled from upstream.

Is this a timing / timeout issue, or is the connection terminated right away?

[AstraLuma]

Nothing remarkable.

time="2020-10-01T14:54:03.661223365Z" level=info msg="redis: connect localhost:6379" go.version=go1.11.2 instance.id=5c96a94a-2a6a-42c3-a58e-f012dd1a5af7 redis.connect.duration=3.174647ms version=v2.7.1
time="2020-10-01T14:54:04.06278498Z" level=info msg="redis: connect localhost:6379" go.version=go1.11.2 instance.id=5c96a94a-2a6a-42c3-a58e-f012dd1a5af7 redis.connect.duration=935.785µs version=v2.7.1
time="2020-10-01T14:54:04.065041666Z" level=info msg="Adding new scheduler entry for library/busybox@sha256:4b6ad3a68d34da29bf7c8ccb5d355ba8b4babcad1f99798204e7abb43e54ee3d with ttl=167h59m59.999997608s" go.version=go1.11.2 instance.id=5c96a94a-2a6a-42c3-a58e-f012dd1a5af7 version=v2.7.1
time="2020-10-01T14:54:04.065199294Z" level=info msg="rewriting manifest list sha256:4b6ad3a68d34da29bf7c8ccb5d355ba8b4babcad1f99798204e7abb43e54ee3d in schema1 format to support old client" go.version=go1.11.2 http.request.host=vm-jbliss-ptr.dev.purestorage.com http.request.id=425b2439-054a-4927-af23-2a3e999838ad http.request.method=GET http.request.remoteaddr="10.7.57.128:45850" http.request.uri="/v2/library/busybox/manifests/1.30.1" http.request.useragent="docker-registry-client-async/0.1.5" vars.name="library/busybox" vars.reference=1.30.1
time="2020-10-01T14:54:04.066431935Z" level=info msg="redis: connect localhost:6379" go.version=go1.11.2 instance.id=5c96a94a-2a6a-42c3-a58e-f012dd1a5af7 redis.connect.duration=1.121887ms version=v2.7.1
time="2020-10-01T14:54:04.253454367Z" level=info msg="redis: connect localhost:6379" go.version=go1.11.2 instance.id=5c96a94a-2a6a-42c3-a58e-f012dd1a5af7 redis.connect.duration=1.209895ms version=v2.7.1
10.7.57.128 - - [01/Oct/2020:14:54:03 +0000] "GET /v2/library/busybox/manifests/1.30.1 HTTP/1.1" 200 527 "" "docker-registry-client-async/0.1.5"
time="2020-10-01T14:54:04.256388097Z" level=info msg="Adding new scheduler entry for library/busybox@sha256:4fe8827f51a5e11bb83afa8227cbccb402df840d32c6b633b7ad079bc8144100 with ttl=167h59m59.999998248s" go.version=go1.11.2 instance.id=5c96a94a-2a6a-42c3-a58e-f012dd1a5af7 version=v2.7.1
time="2020-10-01T14:54:04.256730941Z" level=info msg="response completed" go.version=go1.11.2 http.request.host=vm-jbliss-ptr.dev.purestorage.com http.request.id=425b2439-054a-4927-af23-2a3e999838ad http.request.method=GET http.request.remoteaddr="10.7.57.128:45850" http.request.uri="/v2/library/busybox/manifests/1.30.1" http.request.useragent="docker-registry-client-async/0.1.5" http.response.contenttype="application/vnd.docker.distribution.manifest.v2+json" http.response.duration=1.247858356s http.response.status=200 http.response.written=527
time="2020-10-01T14:54:04.281829751Z" level=info msg="redis: connect localhost:6379" go.version=go1.11.2 instance.id=5c96a94a-2a6a-42c3-a58e-f012dd1a5af7 redis.connect.duration=1.124579ms version=v2.7.1
time="2020-10-01T14:54:04.283196948Z" level=info msg="redis: connect localhost:6379" go.version=go1.11.2 instance.id=5c96a94a-2a6a-42c3-a58e-f012dd1a5af7 redis.connect.duration=837.256µs version=v2.7.1
time="2020-10-01T14:54:04.284373245Z" level=info msg="redis: connect localhost:6379" go.version=go1.11.2 instance.id=5c96a94a-2a6a-42c3-a58e-f012dd1a5af7 redis.connect.duration=814.642µs version=v2.7.1
time="2020-10-01T14:54:04.285546936Z" level=info msg="redis: connect localhost:6379" go.version=go1.11.2 instance.id=5c96a94a-2a6a-42c3-a58e-f012dd1a5af7 redis.connect.duration=817.816µs version=v2.7.1
10.7.57.128 - - [01/Oct/2020:14:54:04 +0000] "GET /v2/library/busybox/blobs/sha256:64f5d945efcc0f39ab11b3cd4ba403cc9fefe1fa3613123ca016cf3708e8cafb HTTP/1.1" 200 0 "" "docker-registry-client-async/0.1.5"
time="2020-10-01T14:54:04.286629997Z" level=info msg="redis: connect localhost:6379" go.version=go1.11.2 instance.id=5c96a94a-2a6a-42c3-a58e-f012dd1a5af7 redis.connect.duration=897.71µs version=v2.7.1
time="2020-10-01T14:54:04.286875757Z" level=info msg="response completed" go.version=go1.11.2 http.request.contenttype="application/octet-stream" http.request.host=vm-jbliss-ptr.dev.purestorage.com http.request.id=c6ac61de-0001-4ba3-ba6a-4c7a12bee7fb http.request.method=GET http.request.remoteaddr="10.7.57.128:45850" http.request.uri="/v2/library/busybox/blobs/sha256:64f5d945efcc0f39ab11b3cd4ba403cc9fefe1fa3613123ca016cf3708e8cafb" http.request.useragent="docker-registry-client-async/0.1.5" http.response.contenttype="application/octet-stream" http.response.duration=7.575105ms http.response.status=200 http.response.written=0

[AstraLuma]

It's just kinda responding as if it was a HEAD not a GET.

[stale[bot]]

This discussion has been automatically marked as stale because it has not had recent activity. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.

[stale[bot]]

This discussion has been closed due to inactivity.