distribution: pull through cache (proxy): docker pull error "unexpected EOF" due to common blob expiration

This happens consistently when trying to pull an image that shares a layer with another image that has been expired. Because the TTL is 7 days we have images which we are unable to pull for multiple days until that image hits the TTL.

Steps to reproduce:

Patch the latest version of distribution to set the expiry to something small (10 minutes). This is to make the problem reproducible quickly

At https://github.com/docker/distribution/blob/06fa77aa11a3913096efcb9b5bd25db8ef55a939/registry/proxy/proxymanifeststore.go#L15 Change to: const repositoryTTL = time.Duration(10 * time.Minute)

Build and run distribution configured as proxy to registry-1.docker.io

docker build -t registry .
docker run -d -p5000:5000 \
  -e REGISTRY_PROXY_REMOTEURL=https://registry-1.docker.io \
  -e REGISTRY_STORAGE_CACHE_BLOBDESCRIPTOR=inmemory \
  --name registry registry

Pull the library/python image from the local registry proxy

docker rmi localhost:5000/library/python
docker pull localhost:5000/library/python

Wait a few minutes and pull the library/node image

docker rmi localhost:5000/library/python
docker rmi localhost:5000/library/node
docker pull localhost:5000/library/node

After waiting 10 minutes from step 3 you should see a message in registry logs about deleting blobs:

time="2017-08-15T17:25:21.516625079Z" level=debug msg="filesystem.Stat("/docker/registry/v2/blobs/sha256/81/81a1ab6955f8a17045fb4c2866b21c91445837507e86d489b03744557e6ed209/data")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=32.961µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=c635fc90-4397-4fa3-b10c-f32ed9578170 trace.line=138 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:21.516820044Z" level=debug msg="filesystem.Delete("/docker/registry/v2/repositories/library/python/_manifests/revisions/sha256/81a1ab6955f8a17045fb4c2866b21c91445837507e86d489b03744557e6ed209/link")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=107.87µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=0ff8eb93-21c9-4200-822d-01cd733c4d91 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:21.516941798Z" level=debug msg="filesystem.Delete("/docker/registry/v2/repositories/library/python/_layers/sha256/81a1ab6955f8a17045fb4c2866b21c91445837507e86d489b03744557e6ed209/link")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=54.834µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=e8c98a94-f16e-435e-b1ff-05a6db79329c trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:22.411773597Z" level=debug msg="filesystem.Delete("/docker/registry/v2/repositories/library/python/_layers/sha256/968120d8cbe8c99ab47504ffeb49e16ce3b773d14ba4eb78c7a5eca6ad34e00c/link")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=167.598µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=ef753f71-1268-4194-9dd4-44a5d1c52e8b trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:22.411921019Z" level=info msg="Deleting blob: /docker/registry/v2/blobs/sha256/96/968120d8cbe8c99ab47504ffeb49e16ce3b773d14ba4eb78c7a5eca6ad34e00c" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:22.412218761Z" level=debug msg="filesystem.Delete("/docker/registry/v2/blobs/sha256/96/968120d8cbe8c99ab47504ffeb49e16ce3b773d14ba4eb78c7a5eca6ad34e00c")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=246.403µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=1c013292-4444-4b5c-b308-23ca41022912 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:22.564524978Z" level=debug msg="filesystem.PutContent("/scheduler-state.json")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=30.512342ms trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=37717880-31f6-434b-b53b-8d995df33d65 trace.line=96 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:22.870933249Z" level=debug msg="filesystem.Stat("/")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=46.644µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=64602e0e-95de-411c-8874-7149fcc69d3b trace.line=138 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:25.771801383Z" level=debug msg="filesystem.Delete("/docker/registry/v2/repositories/library/python/_layers/sha256/2b032b8bbe8bc215ad3337035d0183fc353841ec6478d1c481e6e13628ad9e00/link")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=167.598µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=e372ab76-7ee4-4f64-a39a-d32d69cc3ec1 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:25.771924435Z" level=info msg="Deleting blob: /docker/registry/v2/blobs/sha256/2b/2b032b8bbe8bc215ad3337035d0183fc353841ec6478d1c481e6e13628ad9e00" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:25.779106183Z" level=debug msg="filesystem.Delete("/docker/registry/v2/blobs/sha256/2b/2b032b8bbe8bc215ad3337035d0183fc353841ec6478d1c481e6e13628ad9e00")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=7.123118ms trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=ec999c6f-bf75-4eae-87e8-2502741a661f trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:27.561749439Z" level=debug msg="filesystem.PutContent("/scheduler-state.json")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=27.048315ms trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=3419b00d-1ea6-42e2-8f4f-6dadca82d361 trace.line=96 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:32.872650715Z" level=debug msg="filesystem.Stat("/")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=52.137µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=0b9a662b-29f2-4b19-bc23-ae0c13957819 trace.line=138 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:33.955121366Z" level=debug msg="filesystem.Delete("/docker/registry/v2/repositories/library/python/_layers/sha256/032924b710ba95b71e9a2d971e705bab895ddf7a219994c2cf8761f6959e62ed/link")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=177.186µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=310fddc4-a281-4e1b-8386-4512515c1786 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:33.955241721Z" level=info msg="Deleting blob: /docker/registry/v2/blobs/sha256/03/032924b710ba95b71e9a2d971e705bab895ddf7a219994c2cf8761f6959e62ed" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:33.956808833Z" level=debug msg="filesystem.Delete("/docker/registry/v2/blobs/sha256/03/032924b710ba95b71e9a2d971e705bab895ddf7a219994c2cf8761f6959e62ed")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=1.512178ms trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=b6b3f5c5-ab15-4b2f-ab65-7e0310b58ea3 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:34.708783931Z" level=debug msg="filesystem.Delete("/docker/registry/v2/repositories/library/python/_layers/sha256/a9a5b35f6ead105e66a9af969454ac09b5772eeb0c6281972c48d2ce882e8eba/link")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=156.311µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=bc8112d8-f7cc-4ae8-b20b-8ddd0b191504 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:34.708953327Z" level=info msg="Deleting blob: /docker/registry/v2/blobs/sha256/a9/a9a5b35f6ead105e66a9af969454ac09b5772eeb0c6281972c48d2ce882e8eba" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:34.723095091Z" level=debug msg="filesystem.Delete("/docker/registry/v2/blobs/sha256/a9/a9a5b35f6ead105e66a9af969454ac09b5772eeb0c6281972c48d2ce882e8eba")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=14.092723ms trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=1351974e-bb2b-459a-a5c6-112ef82d163d trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:37.126646541Z" level=debug msg="filesystem.Delete("/docker/registry/v2/repositories/library/python/_layers/sha256/450f5ea3e7eafb6df380c997fa891c13693af5ef46eb7a8ac6c54b58d00fecbb/link")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=166.699µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=f878de6c-a418-4c27-aa03-13e137fe9d53 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:37.12677958Z" level=info msg="Deleting blob: /docker/registry/v2/blobs/sha256/45/450f5ea3e7eafb6df380c997fa891c13693af5ef46eb7a8ac6c54b58d00fecbb" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:37.127005209Z" level=debug msg="filesystem.Delete("/docker/registry/v2/blobs/sha256/45/450f5ea3e7eafb6df380c997fa891c13693af5ef46eb7a8ac6c54b58d00fecbb")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=172.193µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=e4e7a4ac-2356-4a5c-a4ed-d1e0682175d5 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:37.565964096Z" level=debug msg="filesystem.PutContent("/scheduler-state.json")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=30.373808ms trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=95f3b9b9-0b4a-4fac-8aba-07092f4d68e9 trace.line=96 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:38.457333866Z" level=debug msg="filesystem.Delete("/docker/registry/v2/repositories/library/python/_layers/sha256/b1dca9769b8b2f680ff0ed0de230c1d8984715ea8608e8a7df08b44a982f1fb3/link")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=161.006µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=06ada939-1974-4378-8b58-24afcbb8424e trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:38.45747999Z" level=info msg="Deleting blob: /docker/registry/v2/blobs/sha256/b1/b1dca9769b8b2f680ff0ed0de230c1d8984715ea8608e8a7df08b44a982f1fb3" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:38.458513945Z" level=debug msg="filesystem.Delete("/docker/registry/v2/blobs/sha256/b1/b1dca9769b8b2f680ff0ed0de230c1d8984715ea8608e8a7df08b44a982f1fb3")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=973.127µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=25f52868-4bd1-49f1-a9cd-453c12d29162 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:39.423246535Z" level=debug msg="filesystem.Delete("/docker/registry/v2/repositories/library/python/_layers/sha256/0d7cffe4bfd71fa93d626a4a0761dc02083eda97bfc757feafdc168a9b24fbda/link")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=162.504µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=2567d11e-85a8-467d-9521-edc039c08729 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:39.423393558Z" level=info msg="Deleting blob: /docker/registry/v2/blobs/sha256/0d/0d7cffe4bfd71fa93d626a4a0761dc02083eda97bfc757feafdc168a9b24fbda" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:39.430487012Z" level=debug msg="filesystem.Delete("/docker/registry/v2/blobs/sha256/0d/0d7cffe4bfd71fa93d626a4a0761dc02083eda97bfc757feafdc168a9b24fbda")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=7.03922ms trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=901fd0c0-2812-4164-8d08-50006117bfcd trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:39.604583279Z" level=debug msg="filesystem.Delete("/docker/registry/v2/repositories/library/python/_layers/sha256/ad74af05f5a24bcf9459ae1cf7718628c2aeb6b587eb51b6eeaf639aca3e566f/link")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=159.508µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=fedb294a-0a8b-426f-8569-15704de2eae6 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:39.604724709Z" level=info msg="Deleting blob: /docker/registry/v2/blobs/sha256/ad/ad74af05f5a24bcf9459ae1cf7718628c2aeb6b587eb51b6eeaf639aca3e566f" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:39.620825712Z" level=debug msg="filesystem.Delete("/docker/registry/v2/blobs/sha256/ad/ad74af05f5a24bcf9459ae1cf7718628c2aeb6b587eb51b6eeaf639aca3e566f")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=16.030289ms trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=973070df-b3b6-44c4-8bbb-b41a73c29417 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:42.561907601Z" level=debug msg="filesystem.PutContent("/scheduler-state.json")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=27.883109ms trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).PutContent" trace.id=7570e3b4-5552-4673-a9a3-a4b9064b2e95 trace.line=96 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:42.871661741Z" level=debug msg="filesystem.Stat("/")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=55.633µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Stat" trace.id=513ab546-9e48-4ec8-a111-b154db454013 trace.line=138 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:44.872937411Z" level=debug msg="filesystem.Delete("/docker/registry/v2/repositories/library/python/_layers/sha256/3245b5a1c52cbf0ae23d948fb94ef7b321e3dc54e13c3f6cf79951ed8237f03e/link")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=163.802µs trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=6b8af6d0-ba88-4fb8-a41d-6c758d3df506 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:44.873077842Z" level=info msg="Deleting blob: /docker/registry/v2/blobs/sha256/32/3245b5a1c52cbf0ae23d948fb94ef7b321e3dc54e13c3f6cf79951ed8237f03e" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry version=v2.6.0-rc.1-213-g06fa77aa.m 
time="2017-08-15T17:25:44.907699933Z" level=debug msg="filesystem.Delete("/docker/registry/v2/blobs/sha256/32/3245b5a1c52cbf0ae23d948fb94ef7b321e3dc54e13c3f6cf79951ed8237f03e")" environment=development go.version=go1.8.3 instance.id=cb5c9bf9-bc57-422c-9da2-51eefab7bfc6 service=registry trace.duration=34.561764ms trace.file="/go/src/github.com/docker/distribution/registry/storage/driver/base/base.go" trace.func="github.com/docker/distribution/registry/storage/driver/base.(*Base).Delete" trace.id=75af8054-f141-4211-9fa8-8182d8fd3a08 trace.line=178 version=v2.6.0-rc.1-213-g06fa77aa.m

Try to pull library/node again and see an error

docker rmi localhost:5000/library/python
docker rmi localhost:5000/library/node
docker pull localhost:5000/library/node # <--- this causes an error

Using default tag: latest
latest: Pulling from library/node
ad74af05f5a2: Retrying in 1 second
2b032b8bbe8b: Retrying in 1 second
a9a5b35f6ead: Downloading [==================================================>]  43.23MB/43.23MB
3245b5a1c52c: Waiting
afa075743392: Waiting
9fb9f21641cd: Waiting
2e38fbae54d2: Waiting
64e77472dc48: Waiting
unexpected EOF

Logs from registry on failed pull: distribution-logs-EOF-pull.txt

Repeatedly trying docker pull localhost:5000/library/node fails until 10 minutes after the first pull at which point it succeeds.

If you hit the API directly for one of the blobs that is stuck retrying you get back a 200 OK but with an empty body:

$ curl -svO localhost:5000/v2/library/node/blobs/sha256:3245b5a1c52cbf0ae23d948fb94ef7b321e3dc54e13c3f6cf79951ed8237f03e
*   Trying ::1...
* TCP_NODELAY set
* Connected to localhost (::1) port 5000 (#0)
> GET /v2/library/node/blobs/sha256:3245b5a1c52cbf0ae23d948fb94ef7b321e3dc54e13c3f6cf79951ed8237f03e HTTP/1.1
> Host: localhost:5000
> User-Agent: curl/7.54.0
> Accept: */*
>
< HTTP/1.1 200 OK
< Accept-Ranges: bytes
< Cache-Control: max-age=31536000
< Content-Length: 131858814
< Content-Type: application/octet-stream
< Docker-Content-Digest: sha256:3245b5a1c52cbf0ae23d948fb94ef7b321e3dc54e13c3f6cf79951ed8237f03e
< Docker-Distribution-Api-Version: registry/2.0
< Etag: "sha256:3245b5a1c52cbf0ae23d948fb94ef7b321e3dc54e13c3f6cf79951ed8237f03e"
< X-Content-Type-Options: nosniff
< Date: Tue, 15 Aug 2017 17:49:08 GMT
<
{ [0 bytes data]
* transfer closed with 131858814 bytes remaining to read
* Closing connection 0

Docker version/info

$ docker version
Client:
 Version:      17.06.0-ce
 API version:  1.30
 Go version:   go1.8.3
 Git commit:   02c1d87
 Built:        Fri Jun 23 21:31:53 2017
 OS/Arch:      darwin/amd64

Server:
 Version:      17.06.0-ce
 API version:  1.30 (minimum version 1.12)
 Go version:   go1.8.3
 Git commit:   02c1d87
 Built:        Fri Jun 23 21:51:55 2017
 OS/Arch:      linux/amd64
 Experimental: true


$ docker info
Containers: 4
 Running: 1
 Paused: 0
 Stopped: 3
Images: 55
Server Version: 17.06.0-ce
Storage Driver: overlay2
 Backing Filesystem: extfs
 Supports d_type: true
 Native Overlay Diff: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: bridge host ipvlan macvlan null overlay
 Log: awslogs fluentd gcplogs gelf journald json-file logentries splunk syslog
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: cfb82a876ecc11b5ca0977d1733adbe58599088a
runc version: 2d41c047c83e09a6d61d464906feb2a2f3c52aa4
init version: 949e6fa
Security Options:
 seccomp
  Profile: default
Kernel Version: 4.9.36-moby
Operating System: Alpine Linux v3.5
OSType: linux
Architecture: x86_64
CPUs: 4
Total Memory: 3.855GiB
Name: moby
ID: NWWG:VGBP:CL62:HAK7:WMUH:AVT2:7AN2:4DCR:DDT5:ST3A:HDSW:VNZI
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): true
 File Descriptors: 30
 Goroutines: 41
 System Time: 2017-08-15T17:08:28.029292033Z
 EventsListeners: 1
No Proxy: *.local, 169.254/16
Registry: https://index.docker.io/v1/
Experimental: true
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false

About this issue

Original URL
State: open
Created 7 years ago
Reactions: 22
Comments: 38 (18 by maintainers)

Commits related to this issue

Option to configure proxy cache TTL Currently when registry is run as proxy it tries to cleanup unused blobs from its cache after 7 days which is hard-coded. This PR makes that value configurable. On... — committed to manishtomar/distribution by deleted user 4 years ago
Option to configure proxy cache TTL Currently when registry is run as proxy it tries to cleanup unused blobs from its cache after 7 days which is hard-coded. This PR makes that value configurable. On... — committed to manishtomar/distribution by deleted user 4 years ago
Option to configure proxy cache TTL Currently when registry is run as proxy it tries to cleanup unused blobs from its cache after 7 days which is hard-coded. This PR makes that value configurable. On... — committed to wzshiming/distribution by deleted user 4 years ago
Option to configure proxy cache TTL Currently when registry is run as proxy it tries to cleanup unused blobs from its cache after 7 days which is hard-coded. This PR makes that value configurable. On... — committed to wzshiming/distribution by deleted user 4 years ago

Most upvoted comments

@andyxning Schema1 is disabled by default in Registry 2.7. You will need to enable it in config file:

compatibility:
  schema1:
    enabled: true

manishtomar on Jan 16, 2019

Hello,

I’m encountering the same issue with the version from the main branch.

Upon a brief review, I discovered that the registry has a garbage-collect function (https://github.com/distribution/distribution/blob/main/docs/garbage-collection.md#example).

This function is designed to delete blobs but also analyzes references to prevent the deletion of necessary blobs (a different approach than the direct blob deletion in proxyregistry.go).

So, I disabled only the blob deletion in proxyregistry.go and retained only manifest deletion. After the manifest was deleted, I ran registry garbage-collect -d /etc/docker/registry/config.yml. This deleted all unused blobs without references, and I was able to pull the image without encountering an EOF error.

I’m considering running garbage-collect as a cron job for proper cleanup.

My changes https://github.com/zagaria/distribution/pull/1/files

@milosgajdos could you please review? Will this help resolve the issue?

zagaria on Oct 9, 2023

@messiahUA you could use this image andyzhangx/registry:v2.7.0-nottl, I have set up a docker registry cache service based on this image, and works stable for more than 3 years, I use a 8TB disk to store image caches, only need to clean up once every two years, that’s quite easy to maintain.

andyzhangx on Jan 10, 2022

Hello,

Upon a brief review of the source code, I discovered that cleanup can be implemented at the proxy level - it requires adding a call to the MarkAndSweep function with parameters specified in the config.

However, invoking this function directly from the proxy code could result in a large number of queries to the storage, which is particularly costly for Cloud Storages that charge per request. In my opinion, based on the current realization of retention, this cleanup should be external to the proxy code, except for the manifests.

Additionally, I have prepared a test build (a docker image compatible with amd64/arm64) from the latest main branch (commit 13fe08d87b766610775fc92ee022ed7c271bfcc4) with patches as described in https://github.com/zagaria/distribution/pull/1/files

If anyone wishes to test it, you can use the following command: docker pull ghcr.io/zagaria/distribution/registry:main-with-proxy-retention-patches-v1-test

zagaria on Nov 21, 2023

@joshlay I don’t think #3880 does anything to actually solve this bug, it only allows you to ignore it for longer (or shorter) by configuring how long to wait before the faulty logic executes. Or never, if you disable cleanup completely.

That might be an OK workaround for some, but let’s not close this bug prematurely 😃

Maybe I didn’t get all the details correct in i my comment above, but I think there’s a real bug there that should be fixed.

Maybe some other recent change has addressed the issue?

dhedberg on Sep 19, 2023

Sorry, I accidentally closed the wrong issue 🫠 will reopen

milosgajdos on Sep 23, 2023

https://github.com/docker/distribution/blob/06fa77aa11a3913096efcb9b5bd25db8ef55a939/registry/proxy/proxymanifeststore.go#L15

@messiahUA just hardcode this num: https://github.com/docker/distribution/blob/06fa77aa11a3913096efcb9b5bd25db8ef55a939/registry/proxy/proxymanifeststore.go#L15, and then rebuild image.

andyzhangx on Jan 10, 2022