New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Push to private registry fails with BLOB_UNKNOWN v2.1.1 #928

Closed
ccrosby7 opened this Issue Aug 26, 2015 · 14 comments

Comments

Projects
None yet
5 participants
@ccrosby7

ccrosby7 commented Aug 26, 2015

I have a private registry sitting behind a pair of nginx proxies. The first terminates the TLS, while the second simply routes any information between the registry (:443) and a separate docker container (:80). The config files for both, version info, and other relevant information is contained in the gist.

https://gist.github.com/caladbolg7/56488f65c108e5ae7ca1

I can curl to /v2/ and /v2/_catalog just fine, but any attempt at pushing to the registry ends in a single push then a 'blob upload unknown'. Personally, I'm not sure what exactly is happening, as I had this set up working initially with 2.0 around two weeks ago, but after retesting yesterday, I receive this error, regardless of version (2.0/2.0.1/2.1.0/2.1.1).

Currently, the private registry stores to the local file system.

Error log:

{"http.request.host":"--------------","http.request.id":"78a5be0a-5d9a-4d14-b4cb-36d56efda82b","http.request.method":"GET","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"4354d02c-5be5-45d4-a189-c1832b51daef","level":"debug","msg":"authorizing request","service":"registry","time":"2015-08-26T14:43:02.08135772Z","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"78a5be0a-5d9a-4d14-b4cb-36d56efda82b","http.request.method":"GET","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","http.response.contenttype":"application/json; charset=utf-8","http.response.duration":"4.747105ms","http.response.status":200,"http.response.written":2,"instance.id":"4354d02c-5be5-45d4-a189-c1832b51daef","level":"info","msg":"response completed","service":"registry","time":"2015-08-26T14:43:02.081767837Z","version":"v2.1.1"}
172.17.0.47 - - [26/Aug/2015:14:43:02 +0000] "GET /v2/ HTTP/1.0" 200 2 "" "docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64"
{"http.request.host":"--------------","http.request.id":"f6ac44a9-d53e-40c2-ad27-3c590c964a7a","http.request.method":"HEAD","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"4354d02c-5be5-45d4-a189-c1832b51daef","level":"debug","msg":"authorizing request","service":"registry","time":"2015-08-26T14:43:02.54730768Z","vars.digest":"sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","vars.name":"ubuntu2","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"f6ac44a9-d53e-40c2-ad27-3c590c964a7a","http.request.method":"HEAD","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"4354d02c-5be5-45d4-a189-c1832b51daef","level":"debug","msg":"GetBlob","service":"registry","time":"2015-08-26T14:43:02.547555181Z","vars.digest":"sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","vars.name":"ubuntu2","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"f6ac44a9-d53e-40c2-ad27-3c590c964a7a","http.request.method":"HEAD","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"4354d02c-5be5-45d4-a189-c1832b51daef","level":"debug","msg":"filesystem.GetContent(\"/docker/registry/v2/repositories/ubuntu2/_layers/sha256/a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4/link\")","service":"registry","time":"2015-08-26T14:43:02.547881629Z","trace.duration":89812,"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).GetContent","trace.id":"c8ef96a7-d0e9-445c-9c01-cc32c10c3da4","trace.line":55,"vars.digest":"sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","vars.name":"ubuntu2","version":"v2.1.1"}
{"err.code":"BLOB_UNKNOWN","err.detail":"sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","err.message":"blob unknown to registry","http.request.host":"--------------","http.request.id":"f6ac44a9-d53e-40c2-ad27-3c590c964a7a","http.request.method":"HEAD","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","http.response.contenttype":"application/json; charset=utf-8","http.response.duration":"4.199659ms","http.response.status":404,"http.response.written":157,"instance.id":"4354d02c-5be5-45d4-a189-c1832b51daef","level":"error","msg":"response completed with error","service":"registry","time":"2015-08-26T14:43:02.548199108Z","vars.digest":"sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","vars.name":"ubuntu2","version":"v2.1.1"}
172.17.0.47 - - [26/Aug/2015:14:43:02 +0000] "HEAD /v2/ubuntu2/blobs/sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4 HTTP/1.0" 404 157 "" "docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64"
{"http.request.host":"--------------","http.request.id":"e041587f-c7c8-403a-a193-cbd0ae4b27a8","http.request.method":"POST","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/uploads/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"4354d02c-5be5-45d4-a189-c1832b51daef","level":"debug","msg":"authorizing request","service":"registry","time":"2015-08-26T14:43:02.948769616Z","vars.name":"ubuntu2","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"e041587f-c7c8-403a-a193-cbd0ae4b27a8","http.request.method":"POST","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/uploads/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"4354d02c-5be5-45d4-a189-c1832b51daef","level":"debug","msg":"(*linkedBlobStore).Writer","service":"registry","time":"2015-08-26T14:43:02.949089633Z","vars.name":"ubuntu2","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"e041587f-c7c8-403a-a193-cbd0ae4b27a8","http.request.method":"POST","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/uploads/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"4354d02c-5be5-45d4-a189-c1832b51daef","level":"debug","msg":"filesystem.PutContent(\"/docker/registry/v2/repositories/ubuntu2/_uploads/072e3e64-1d82-421c-b7cd-c6f9be4c3fa4/startedat\")","service":"registry","time":"2015-08-26T14:43:02.950257626Z","trace.duration":914106,"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":"8a59b089-6e54-4818-bd09-d13265c467fb","trace.line":67,"vars.name":"ubuntu2","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"e041587f-c7c8-403a-a193-cbd0ae4b27a8","http.request.method":"POST","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/uploads/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"4354d02c-5be5-45d4-a189-c1832b51daef","level":"debug","msg":"filesystem.Stat(\"/docker/registry/v2/repositories/ubuntu2/_uploads/072e3e64-1d82-421c-b7cd-c6f9be4c3fa4/data\")","service":"registry","time":"2015-08-26T14:43:02.950585909Z","trace.duration":50927,"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":"a60c9f24-4afc-4342-a91a-00a5c8df567a","trace.line":111,"vars.name":"ubuntu2","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"e041587f-c7c8-403a-a193-cbd0ae4b27a8","http.request.method":"POST","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/uploads/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","http.response.duration":"11.405644ms","http.response.status":202,"http.response.written":0,"instance.id":"4354d02c-5be5-45d4-a189-c1832b51daef","level":"info","msg":"response completed","service":"registry","time":"2015-08-26T14:43:02.954582117Z","version":"v2.1.1"}
172.17.0.47 - - [26/Aug/2015:14:43:02 +0000] "POST /v2/ubuntu2/blobs/uploads/ HTTP/1.0" 202 0 "" "docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64"

I'm sure it's likely something I'm glossing over, but if there's any extra info I need to supply I'll get it as quickly as possible.

Thanks.

@dmp42

This comment has been minimized.

Member

dmp42 commented Aug 26, 2015

Is it working if you access your layer-2 nginx? Or directly the backend registry?

When it fails, can you copy your docker daemon logs output? (launched in debug mode with -D)

Thanks.

@ccrosby7

This comment has been minimized.

ccrosby7 commented Aug 26, 2015

DEBU[0124] Calling GET /containers/json
INFO[0124] GET /v1.19/containers/json?all=1&limit=-1&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Duser%22%2C+%22com.docker.compose.service%3Dcf-registry%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&size=0
DEBU[0124] Calling GET /images/{name:.*}/json
INFO[0124] GET /v1.19/images/user_cf-registry/json
DEBU[0124] Calling GET /containers/{name:.*}/json
INFO[0124] GET /v1.19/containers/744c8840e55a93914b374bb1d520cde5119bf5f77916c66ef2360248d5ed3655/json
DEBU[0124] Calling GET /containers/json
INFO[0124] GET /v1.19/containers/json?all=1&limit=-1&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Duser%22%2C+%22com.docker.compose.service%3Dcf-nginx%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&size=0
DEBU[0124] Calling GET /images/{name:.*}/json
INFO[0124] GET /v1.19/images/user_cf-nginx/json
DEBU[0124] Calling GET /containers/{name:.*}/json
INFO[0124] GET /v1.19/containers/7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3/json
DEBU[0124] Calling POST /containers/{name:.*}/start
INFO[0124] POST /v1.19/containers/740f91c98aa4ee440401c7e86c11147b271253e852f430ffcf210aafda37bb88/start
DEBU[0124] Update /etc/hosts of eab4b6ce3d96574d6729f38c56036e41771b22df6e535079c3ce04449759c38a for alias postgres with ip 172.17.0.2
DEBU[0124] Update /etc/hosts of eab4b6ce3d96574d6729f38c56036e41771b22df6e535079c3ce04449759c38a for alias postgres_1 with ip 172.17.0.2
DEBU[0124] Update /etc/hosts of eab4b6ce3d96574d6729f38c56036e41771b22df6e535079c3ce04449759c38a for alias user_postgres_1 with ip 172.17.0.2
DEBU[0124] Calling POST /containers/{name:.*}/start
INFO[0124] POST /v1.19/containers/eab4b6ce3d96574d6729f38c56036e41771b22df6e535079c3ce04449759c38a/start
DEBU[0124] Update /etc/hosts of 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3 for alias cf-node with ip 172.17.0.3
DEBU[0124] Update /etc/hosts of 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3 for alias cf-node_1 with ip 172.17.0.3
DEBU[0124] Update /etc/hosts of 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3 for alias user_cf-node_1 with ip 172.17.0.3
DEBU[0124] Calling POST /containers/{name:.*}/start
INFO[0124] POST /v1.19/containers/744c8840e55a93914b374bb1d520cde5119bf5f77916c66ef2360248d5ed3655/start
DEBU[0124] Update /etc/hosts of 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3 for alias cf-registry with ip 172.17.0.4
DEBU[0124] Update /etc/hosts of 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3 for alias cf-registry_1 with ip 172.17.0.4
DEBU[0124] Update /etc/hosts of 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3 for alias user_cf-registry_1 with ip 172.17.0.4
DEBU[0124] Calling POST /containers/{name:.*}/start
INFO[0124] POST /v1.19/containers/7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3/start
DEBU[0124] /sbin/iptables, [--wait -t nat -A DOCKER -p tcp -d 0/0 --dport 443 -j DNAT --to-destination 172.17.0.5:443 ! -i docker0]
DEBU[0124] /sbin/iptables, [--wait -t filter -A DOCKER ! -i docker0 -o docker0 -p tcp -d 172.17.0.5 --dport 443 -j ACCEPT]
DEBU[0124] /sbin/iptables, [--wait -t nat -A POSTROUTING -p tcp -s 172.17.0.5 -d 172.17.0.5 --dport 443 -j MASQUERADE]
DEBU[0124] /sbin/iptables, [--wait -t nat -A DOCKER -p tcp -d 0/0 --dport 80 -j DNAT --to-destination 172.17.0.5:80 ! -i docker0]
DEBU[0124] /sbin/iptables, [--wait -t filter -A DOCKER ! -i docker0 -o docker0 -p tcp -d 172.17.0.5 --dport 80 -j ACCEPT]
DEBU[0124] /sbin/iptables, [--wait -t nat -A POSTROUTING -p tcp -s 172.17.0.5 -d 172.17.0.5 --dport 80 -j MASQUERADE]

It's not working from either, even through the 2 layer nginx, GET requests to /v2/ and /v2/_catalog work just fine.

@dmp42

This comment has been minimized.

Member

dmp42 commented Aug 26, 2015

I see you are using your own registry image ("cf-registry").

Can you provide details about what's in there? Also, can you provide:

  • registry version: docker exec registry -version
  • registry logs
@ccrosby7

This comment has been minimized.

ccrosby7 commented Aug 26, 2015

As of now, cf-registry is basically a copy of registry:2.1.1.

Version: registry github.com/docker/distribution v2.1.1
Logs:

{"level":"debug","msg":"using \"json\" logging formatter","time":"2015-08-26T21:18:09.821610963Z"}
{"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"warning","msg":"No HTTP secret provided - generated random secret. This may cause problems with uploads if multiple registries are behind a load-balancer. To provide a shared secret, fill in http.secret in the configuration file or set the REGISTRY_HTTP_SECRET environment variable.","service":"registry","time":"2015-08-26T21:18:09.826673351Z","version":"v2.1.1"}
{"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"info","msg":"redis not configured","service":"registry","time":"2015-08-26T21:18:09.826787005Z","version":"v2.1.1"}
{"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"info","msg":"listening on [::]:5000","service":"registry","time":"2015-08-26T21:18:09.827034441Z","version":"v2.1.1"}
{"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"info","msg":"Starting upload purge in 2m0s","service":"registry","time":"2015-08-26T21:18:09.827214429Z","version":"v2.1.1"}
{"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"filesystem.List(\"/\")","service":"registry","time":"2015-08-26T21:18:19.827644928Z","trace.duration":122072,"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).List","trace.id":"cec88efd-d04b-48f9-af6f-ac31ab69b9f3","trace.line":123,"version":"v2.1.1"}
{"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"filesystem.List(\"/\")","service":"registry","time":"2015-08-26T21:18:29.82772882Z","trace.duration":197430,"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).List","trace.id":"58963d25-7b0a-47af-b891-35eb36bcd48f","trace.line":123,"version":"v2.1.1"}
{"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"filesystem.List(\"/\")","service":"registry","time":"2015-08-26T21:18:39.827697945Z","trace.duration":200714,"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).List","trace.id":"4b811ea0-73f0-44b5-808c-17fffd0df9ba","trace.line":123,"version":"v2.1.1"}
{"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"filesystem.List(\"/\")","service":"registry","time":"2015-08-26T21:18:49.827682992Z","trace.duration":184451,"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).List","trace.id":"9f80cbbe-8633-47af-b5cf-76010ea9502a","trace.line":123,"version":"v2.1.1"}
{"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"filesystem.List(\"/\")","service":"registry","time":"2015-08-26T21:18:59.827662225Z","trace.duration":168832,"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).List","trace.id":"85c13b19-0d53-415f-9eff-a915e4ee5a68","trace.line":123,"version":"v2.1.1"}
{"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"filesystem.List(\"/\")","service":"registry","time":"2015-08-26T21:19:09.827687271Z","trace.duration":191433,"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).List","trace.id":"b57041f2-4e98-42e2-8d93-acb7112e8d62","trace.line":123,"version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"cca7e90e-23a3-493c-972e-c78e06c44d3e","http.request.method":"GET","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"authorizing request","service":"registry","time":"2015-08-26T21:19:16.542094733Z","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"cca7e90e-23a3-493c-972e-c78e06c44d3e","http.request.method":"GET","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","http.response.contenttype":"application/json; charset=utf-8","http.response.duration":"5.7588ms","http.response.status":200,"http.response.written":2,"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"info","msg":"response completed","service":"registry","time":"2015-08-26T21:19:16.542432021Z","version":"v2.1.1"}
172.17.0.4 - - [26/Aug/2015:21:19:16 +0000] "GET /v2/ HTTP/1.0" 200 2 "" "docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64"
{"http.request.host":"--------------","http.request.id":"b2c7360a-df1a-4f8e-9422-7c562f415253","http.request.method":"HEAD","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"authorizing request","service":"registry","time":"2015-08-26T21:19:16.931548168Z","vars.digest":"sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","vars.name":"ubuntu2","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"b2c7360a-df1a-4f8e-9422-7c562f415253","http.request.method":"HEAD","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"GetBlob","service":"registry","time":"2015-08-26T21:19:16.931883917Z","vars.digest":"sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","vars.name":"ubuntu2","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"b2c7360a-df1a-4f8e-9422-7c562f415253","http.request.method":"HEAD","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"filesystem.GetContent(\"/docker/registry/v2/repositories/ubuntu2/_layers/sha256/a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4/link\")","service":"registry","time":"2015-08-26T21:19:16.932317739Z","trace.duration":155744,"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).GetContent","trace.id":"7beea316-9318-4e37-aef5-53bcd2e74c25","trace.line":55,"vars.digest":"sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","vars.name":"ubuntu2","version":"v2.1.1"}
{"err.code":"BLOB_UNKNOWN","err.detail":"sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","err.message":"blob unknown to registry","http.request.host":"--------------","http.request.id":"b2c7360a-df1a-4f8e-9422-7c562f415253","http.request.method":"HEAD","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","http.response.contenttype":"application/json; charset=utf-8","http.response.duration":"7.070528ms","http.response.status":404,"http.response.written":157,"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"error","msg":"response completed with error","service":"registry","time":"2015-08-26T21:19:16.932804709Z","vars.digest":"sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4","vars.name":"ubuntu2","version":"v2.1.1"}
172.17.0.4 - - [26/Aug/2015:21:19:16 +0000] "HEAD /v2/ubuntu2/blobs/sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4 HTTP/1.0" 404 157 "" "docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64"
{"http.request.host":"--------------","http.request.id":"f9588c85-0550-44d6-9c6b-27b803fccdd5","http.request.method":"POST","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/uploads/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"authorizing request","service":"registry","time":"2015-08-26T21:19:17.317968232Z","vars.name":"ubuntu2","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"f9588c85-0550-44d6-9c6b-27b803fccdd5","http.request.method":"POST","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/uploads/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"(*linkedBlobStore).Writer","service":"registry","time":"2015-08-26T21:19:17.318388199Z","vars.name":"ubuntu2","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"f9588c85-0550-44d6-9c6b-27b803fccdd5","http.request.method":"POST","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/uploads/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"filesystem.PutContent(\"/docker/registry/v2/repositories/ubuntu2/_uploads/6354aefd-8169-4a96-83bb-546b9619b755/startedat\")","service":"registry","time":"2015-08-26T21:19:17.319128149Z","trace.duration":463574,"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":"e82334c8-da6c-4364-9f1a-bb85b6763c71","trace.line":67,"vars.name":"ubuntu2","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"f9588c85-0550-44d6-9c6b-27b803fccdd5","http.request.method":"POST","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/uploads/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"filesystem.Stat(\"/docker/registry/v2/repositories/ubuntu2/_uploads/6354aefd-8169-4a96-83bb-546b9619b755/data\")","service":"registry","time":"2015-08-26T21:19:17.319533344Z","trace.duration":84338,"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":"38542f30-5ce1-42f4-b93f-194280a8b02c","trace.line":111,"vars.name":"ubuntu2","version":"v2.1.1"}
{"http.request.host":"--------------","http.request.id":"f9588c85-0550-44d6-9c6b-27b803fccdd5","http.request.method":"POST","http.request.remoteaddr":"192.168.0.68","http.request.uri":"/v2/ubuntu2/blobs/uploads/","http.request.useragent":"docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64","http.response.duration":"12.438717ms","http.response.status":202,"http.response.written":0,"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"info","msg":"response completed","service":"registry","time":"2015-08-26T21:19:17.324804059Z","version":"v2.1.1"}
172.17.0.4 - - [26/Aug/2015:21:19:17 +0000] "POST /v2/ubuntu2/blobs/uploads/ HTTP/1.0" 202 0 "" "docker/1.8.1 go/go1.4.2 git-commit/d12ea79 kernel/3.13.0-62-generic os/linux arch/amd64"
{"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"filesystem.List(\"/\")","service":"registry","time":"2015-08-26T21:19:19.827776223Z","trace.duration":213153,"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).List","trace.id":"7be00d5a-c6a4-4b4d-892b-3835b62e5157","trace.line":123,"version":"v2.1.1"}
{"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"filesystem.List(\"/\")","service":"registry","time":"2015-08-26T21:19:29.827740443Z","trace.duration":200842,"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).List","trace.id":"5d608efc-fa63-4494-ade8-c23e8f39702a","trace.line":123,"version":"v2.1.1"}
{"instance.id":"68059e32-81a2-4378-8575-3cbc3225b85b","level":"debug","msg":"filesystem.List(\"/\")","service":"registry","time":"2015-08-26T21:19:39.827742609Z","trace.duration":241777,"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).List","trace.id":"6c5968cc-7206-4ad9-be5e-36059cd749ca","trace.line":123,"version":"v2.1.1"}
@dmp42

This comment has been minimized.

Member

dmp42 commented Aug 26, 2015

@stevvooe @RichardScothern any idea there?

@stevvooe

This comment has been minimized.

Contributor

stevvooe commented Aug 27, 2015

@dmp42 It looks like the error BLOB_UNKNOWN is actually working correctly. The client encounters this and then proceeds to create an upload. When the push commences, the daemon gets "blob upload unknown" reported via the cli. This error can happen when working with a blob writer via the http API. We will only see this when encountering a 404 on a blob upload endpoint.

We can see the upload creation operation completing successfully, since it returns a 202. The call to Stat for "/docker/registry/v2/repositories/ubuntu2/_uploads/6354aefd-8169-4a96-83bb-546b9619b755/data" seems to have been successful.

My theory is that something is dropping the information from the upload url on redirect. Normally, I would suspect this is an issue with the load balancer, but the configuration looks clean. This can possibly be caused by a bug in sanitizeLocation under certain setups. @dmcgowan

@caladbolg7 I'd like to eliminate the configuration environment as a possible cause. Let's take a look at a few things:

  1. Let's see the output of the daemon logs during the failed push. Make sure "debug" is enabled with "-D". We are looking for some hint as to what is happening with the upload.
  2. Please send the output of tree /var/lib/registry/docker/registry/v2/repositories/ubuntu2/_uploads after doing an upload. We'll want to see the uploads represented in the filesystem and correlate them with the log traces.

@caladbolg7 There may be an issue with having two levels of nginx and correctly resolving the protocol scheme and host. It is possible that the scheme is being incorrectly set by the inner nginx instance. Based on your configuration, you may not even need the second nginx instance. I don't understand you're full environment, but it seems unnecessary.

@dmp42

This comment has been minimized.

Member

dmp42 commented Aug 27, 2015

cc @docker/distribution-maintainers

@ccrosby7

This comment has been minimized.

ccrosby7 commented Aug 27, 2015

File tree:

   .
   |-docker
   |---registry
   |-----v2
   |-------repositories
   |---------ubuntu2
   |-----------_uploads
   |-------------6354aefd-8169-4a96-83bb-546b9619b755
   |-------------afc0bc4b-3717-4d23-9091-60231a2707a6

docker daemon -D output:

DEBU[0000] Registering GET, /_ping
DEBU[0000] Registering GET, /version
DEBU[0000] Registering GET, /containers/json
DEBU[0000] Registering GET, /containers/{name:.*}/export
DEBU[0000] Registering GET, /containers/{name:.*}/top
DEBU[0000] Registering GET, /containers/{name:.*}/logs
DEBU[0000] Registering GET, /info
DEBU[0000] Registering GET, /images/json
DEBU[0000] Registering GET, /images/search
DEBU[0000] Registering GET, /containers/ps
DEBU[0000] Registering GET, /containers/{name:.*}/json
DEBU[0000] Registering GET, /containers/{name:.*}/stats
DEBU[0000] Registering GET, /images/{name:.*}/get
DEBU[0000] Registering GET, /images/{name:.*}/json
DEBU[0000] Registering GET, /exec/{id:.*}/json
DEBU[0000] Registering GET, /containers/{name:.*}/archive
DEBU[0000] Registering GET, /events
DEBU[0000] Registering GET, /images/get
DEBU[0000] Registering GET, /images/{name:.*}/history
DEBU[0000] Registering GET, /containers/{name:.*}/changes
DEBU[0000] Registering GET, /containers/{name:.*}/attach/ws
DEBU[0000] Registering POST, /auth
DEBU[0000] Registering POST, /images/create
DEBU[0000] Registering POST, /containers/{name:.*}/kill
DEBU[0000] Registering POST, /containers/{name:.*}/start
DEBU[0000] Registering POST, /commit
DEBU[0000] Registering POST, /images/{name:.*}/tag
DEBU[0000] Registering POST, /containers/{name:.*}/unpause
DEBU[0000] Registering POST, /containers/{name:.*}/restart
DEBU[0000] Registering POST, /containers/{name:.*}/wait
DEBU[0000] Registering POST, /containers/{name:.*}/exec
DEBU[0000] Registering POST, /build
DEBU[0000] Registering POST, /images/{name:.*}/push
DEBU[0000] Registering POST, /containers/create
DEBU[0000] Registering POST, /containers/{name:.*}/stop
DEBU[0000] Registering POST, /containers/{name:.*}/resize
DEBU[0000] Registering POST, /exec/{name:.*}/resize
DEBU[0000] Registering POST, /images/load
DEBU[0000] Registering POST, /containers/{name:.*}/pause
DEBU[0000] Registering POST, /containers/{name:.*}/attach
DEBU[0000] Registering POST, /containers/{name:.*}/copy
DEBU[0000] Registering POST, /exec/{name:.*}/start
DEBU[0000] Registering POST, /containers/{name:.*}/rename
DEBU[0000] Registering PUT, /containers/{name:.*}/archive
DEBU[0000] Registering DELETE, /containers/{name:.*}
DEBU[0000] Registering DELETE, /images/{name:.*}
DEBU[0000] Registering OPTIONS,
DEBU[0000] Registering HEAD, /containers/{name:.*}/archive
DEBU[0000] docker group found. gid: 999
INFO[0000] Listening for HTTP on unix (/var/run/docker.sock)
INFO[0000] [graphdriver] using prior storage driver "aufs"
DEBU[0000] Using graph driver aufs
DEBU[0000] Using default logging driver json-file
DEBU[0000] Migrating existing containers
DEBU[0000] Creating images graph
DEBU[0000] Restored 78 elements
DEBU[0000] Reloaded graph with 3 grants expiring at 2017-03-22 19:04:46.713978458 +0000 UTC
DEBU[0000] Creating repository list
INFO[0000] Option DefaultDriver: bridge
INFO[0000] Option DefaultNetwork: bridge
WARN[0000] Running modprobe bridge nf_nat br_netfilter failed with message: modprobe: WARNING: Module br_netfil
ter not found.
, error: exit status 1
INFO[0000] Firewalld running: false
DEBU[0000] /sbin/iptables, [--wait -t nat -D PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]
DEBU[0000] /sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL ! --dst 127.0.0.0/8 -j DOCKER]

DEBU[0000] /sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL -j DOCKER]
DEBU[0000] /sbin/iptables, [--wait -t nat -D PREROUTING]
DEBU[0000] /sbin/iptables, [--wait -t nat -D OUTPUT]
DEBU[0000] /sbin/iptables, [--wait -t nat -F DOCKER]
DEBU[0000] /sbin/iptables, [--wait -t nat -X DOCKER]
DEBU[0000] Failed to Initialize Datastore due to datastore initialization requires a valid configuration. Opera
ting in non-clustered mode
DEBU[0000] /sbin/iptables, [--wait -t nat -C POSTROUTING -s 172.17.42.1/16 ! -o docker0 -j MASQUERADE]
DEBU[0000] /sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j DROP]
DEBU[0000] /sbin/iptables, [--wait -t filter -C FORWARD -i docker0 -o docker0 -j ACCEPT]
DEBU[0000] /sbin/iptables, [--wait -t filter -C FORWARD -i docker0 ! -o docker0 -j ACCEPT]
DEBU[0000] /sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -
j ACCEPT]
DEBU[0000] /sbin/iptables, [--wait -t nat -n -L DOCKER]
DEBU[0000] /sbin/iptables, [--wait -t nat -N DOCKER]
DEBU[0000] /sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]
DEBU[0000] /sbin/iptables, [--wait -t nat -A PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]
DEBU[0000] /sbin/iptables, [--wait -t nat -C OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8]

DEBU[0000] /sbin/iptables, [--wait -t nat -A OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8]

DEBU[0000] /sbin/iptables, [--wait -t filter -n -L DOCKER]
DEBU[0000] /sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER]
WARN[0000] Your kernel does not support swap memory limit.
DEBU[0000] Loaded container 740f91c98aa4ee440401c7e86c11147b271253e852f430ffcf210aafda37bb88
DEBU[0000] Loaded container 744c8840e55a93914b374bb1d520cde5119bf5f77916c66ef2360248d5ed3655
DEBU[0000] Loaded container 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3
DEBU[0000] Loaded container eab4b6ce3d96574d6729f38c56036e41771b22df6e535079c3ce04449759c38a
DEBU[0000] killing old running container 740f91c98aa4ee440401c7e86c11147b271253e852f430ffcf210aafda37bb88
DEBU[0000] killing old running container 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3
DEBU[0000] killing old running container eab4b6ce3d96574d6729f38c56036e41771b22df6e535079c3ce04449759c38a
DEBU[0000] killing old running container 744c8840e55a93914b374bb1d520cde5119bf5f77916c66ef2360248d5ed3655
DEBU[0000] Starting container 744c8840e55a93914b374bb1d520cde5119bf5f77916c66ef2360248d5ed3655
DEBU[0000] Update /etc/hosts of 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3 for alias cf-r
egistry with ip 172.17.0.1
DEBU[0000] Update /etc/hosts of 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3 for alias cf-r
egistry_1 with ip 172.17.0.1
DEBU[0000] Update /etc/hosts of 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3 for alias user
_cf-registry_1 with ip 172.17.0.1
INFO[0001] Daemon has completed initialization
INFO[0001] Docker daemon                                 commit=d12ea79 execdriver=native-0.2 graphdriver=aufs
version=1.8.1
DEBU[0148] Calling GET /containers/json
INFO[0148] GET /v1.19/containers/json?all=1&limit=-1&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Duser%22%2C+%22com.docker.compose.service%3Dpostgres%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&size=0
DEBU[0148] Calling GET /containers/{name:.*}/json
INFO[0148] GET /v1.19/containers/740f91c98aa4ee440401c7e86c11147b271253e852f430ffcf210aafda37bb88/json
DEBU[0148] Calling GET /containers/json
INFO[0148] GET /v1.19/containers/json?all=1&limit=-1&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Duser%22%2C+%22com.docker.compose.service%3Dcf-node%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&size=0
DEBU[0148] Calling GET /containers/{name:.*}/json
INFO[0148] GET /v1.19/containers/eab4b6ce3d96574d6729f38c56036e41771b22df6e535079c3ce04449759c38a/json
DEBU[0148] Calling GET /containers/json
INFO[0148] GET /v1.19/containers/json?all=1&limit=-1&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Duser%22%2C+%22com.docker.compose.service%3Dcf-registry%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&size=0
DEBU[0148] Calling GET /containers/{name:.*}/json
INFO[0148] GET /v1.19/containers/744c8840e55a93914b374bb1d520cde5119bf5f77916c66ef2360248d5ed3655/json
DEBU[0148] Calling GET /containers/json
INFO[0148] GET /v1.19/containers/json?all=1&limit=-1&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Duser%22%2C+%22com.docker.compose.service%3Dcf-nginx%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&size=0
DEBU[0148] Calling GET /containers/{name:.*}/json
INFO[0148] GET /v1.19/containers/7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3/json
DEBU[0148] Calling GET /containers/json
INFO[0148] GET /v1.19/containers/json?all=1&limit=-1&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Duser%22%2C+%22com.docker.compose.service%3Dpostgres%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&size=0
DEBU[0148] Calling GET /images/{name:.*}/json
INFO[0148] GET /v1.19/images/user_postgres/json
DEBU[0148] Calling GET /containers/{name:.*}/json
INFO[0148] GET /v1.19/containers/740f91c98aa4ee440401c7e86c11147b271253e852f430ffcf210aafda37bb88/json
DEBU[0148] Calling GET /containers/json
INFO[0148] GET /v1.19/containers/json?all=1&limit=-1&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Duser%22%2C+%22com.docker.compose.service%3Dcf-node%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&size=0
DEBU[0148] Calling GET /images/{name:.*}/json
INFO[0148] GET /v1.19/images/user_cf-node/json
DEBU[0148] Calling GET /containers/{name:.*}/json
INFO[0148] GET /v1.19/containers/eab4b6ce3d96574d6729f38c56036e41771b22df6e535079c3ce04449759c38a/json
DEBU[0148] Calling GET /containers/json
INFO[0148] GET /v1.19/containers/json?all=1&limit=-1&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Duser%22%2C+%22com.docker.compose.service%3Dcf-registry%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&size=0
DEBU[0148] Calling GET /images/{name:.*}/json
INFO[0148] GET /v1.19/images/user_cf-registry/json
DEBU[0148] Calling GET /containers/{name:.*}/json
INFO[0148] GET /v1.19/containers/744c8840e55a93914b374bb1d520cde5119bf5f77916c66ef2360248d5ed3655/json
DEBU[0148] Calling GET /containers/json
INFO[0148] GET /v1.19/containers/json?all=1&limit=-1&trunc_cmd=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Duser%22%2C+%22com.docker.compose.service%3Dcf-nginx%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&size=0
DEBU[0148] Calling GET /images/{name:.*}/json
INFO[0148] GET /v1.19/images/user_cf-nginx/json
DEBU[0148] Calling GET /containers/{name:.*}/json
INFO[0148] GET /v1.19/containers/7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3/json
DEBU[0148] Calling POST /containers/{name:.*}/start
INFO[0148] POST /v1.19/containers/740f91c98aa4ee440401c7e86c11147b271253e852f430ffcf210aafda37bb88/start
DEBU[0148] Update /etc/hosts of eab4b6ce3d96574d6729f38c56036e41771b22df6e535079c3ce04449759c38a for alias postgres with ip 172.17.0.2
DEBU[0148] Update /etc/hosts of eab4b6ce3d96574d6729f38c56036e41771b22df6e535079c3ce04449759c38a for alias postgres_1 with ip 172.17.0.2
DEBU[0148] Update /etc/hosts of eab4b6ce3d96574d6729f38c56036e41771b22df6e535079c3ce04449759c38a for alias user_postgres_1 with ip 172.17.0.2
DEBU[0148] Calling POST /containers/{name:.*}/start
INFO[0148] POST /v1.19/containers/eab4b6ce3d96574d6729f38c56036e41771b22df6e535079c3ce04449759c38a/start
DEBU[0148] Update /etc/hosts of 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3 for alias cf-node with ip 172.17.0.3
DEBU[0148] Update /etc/hosts of 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3 for alias cf-node_1 with ip 172.17.0.3
DEBU[0148] Update /etc/hosts of 7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3 for alias user_cf-node_1 with ip 172.17.0.3
DEBU[0148] Calling POST /containers/{name:.*}/start
INFO[0148] POST /v1.19/containers/7f3fa397380c7b9e921daed2ee9636db520446873a646cd03eb4c1572c5913e3/start
DEBU[0148] /sbin/iptables, [--wait -t nat -A DOCKER -p tcp -d 0/0 --dport 443 -j DNAT --to-destination 172.17.0.4:443 ! -i docker0]
DEBU[0148] /sbin/iptables, [--wait -t filter -A DOCKER ! -i docker0 -o docker0 -p tcp -d 172.17.0.4 --dport 443 -j ACCEPT]
DEBU[0148] /sbin/iptables, [--wait -t nat -A POSTROUTING -p tcp -s 172.17.0.4 -d 172.17.0.4 --dport 443 -j MASQUERADE]
DEBU[0149] /sbin/iptables, [--wait -t nat -A DOCKER -p tcp -d 0/0 --dport 80 -j DNAT --to-destination 172.17.0.4:80 ! -i docker0]
DEBU[0149] /sbin/iptables, [--wait -t filter -A DOCKER ! -i docker0 -o docker0 -p tcp -d 172.17.0.4 --dport 80 -j ACCEPT]
DEBU[0149] /sbin/iptables, [--wait -t nat -A POSTROUTING -p tcp -s 172.17.0.4 -d 172.17.0.4 --dport 80 -j MASQUERADE]

If there's a better way to be getting the docker daemon logs that I'm missing, please let me know. Long story short, the upper layer of nginx is necessary use of a separate part of the overarching project.

Thanks again for the help.

@stevvooe

This comment has been minimized.

Contributor

stevvooe commented Aug 27, 2015

@caladbolg7 Thanks for the extra information.

At this point, it is pretty safe to say the upload is actually there. Given the bug we've identified in the client library, I am pretty confident that may be the cause.

Although, I am slightly worried that you may still run into problems with the "double nginx" setup. If you are willing to continue troubleshooting, let's confirm the root cause of this particular issue. Do you happen to have the logs during the failure? These logs look like they only contain daemon startup. You'll have to restart the daemon in debug mode then perform the push.

@ccrosby7

This comment has been minimized.

ccrosby7 commented Aug 27, 2015

That's all I got while attempting a push. The upload itself is starting, but only a 32B layer is moving. If I attempt to pull the same image back, it errors as unknown.

@stevvooe

This comment has been minimized.

Contributor

stevvooe commented Aug 28, 2015

@caladbolg7 I don't think the push is actually succeeding at all, based on the registry logs. I think the upload request is getting corrupted and getting that 404. We'll get the patch in and give this a try.

@agaffney

This comment has been minimized.

agaffney commented Sep 10, 2015

I'm seeing something similar, but it only seems to happen intermittently. I have 3 servers running registry:2.1.1, all using the same NFS mount for storage. Seemingly randomly, I'll get an error like:

The push refers to a repository [docker-atl1.turn.com/tops-software/opentsdb] (len: 1)
afdb739b082d: Buffering to Disk
afdb739b082d: Image successfully pushed
afdb739b082d: Image already exists
...
9000446d7e36: Buffering to Disk
9000446d7e36: Image successfully pushed
9accf256f939: Buffering to Disk
9accf256f939: Image successfully pushed
6a7b54515901: Image already exists
47d44cb6f252: Image already exists
Error pushing to registry: Server error: 404 trying to push tops-software/opentsdb:latest manifest

and the corresponding logs from the registry:

time="2015-09-10T00:19:38.169310226Z" level=warning msg="the ResponseWriter does not implement CloseNotifier" http.request.host="localhost:5000" http.request.id=6516b3a2-12c7-43dd-9083-d46020d4597d http.request.method=PUT http.request.remoteaddr="172.17.42.1:50415" http.request.uri="/v2/tops-software/opentsdb/manifests/latest" http.request.useragent="docker/1.7.1 go/go1.4.2 git-commit/786b29d kernel/2.6.32-573.3.1.el6.x86_64 os/linux arch/amd64" instance.id=15c05e4b-1402-4e57-91a3-0414d0969c0c vars.name="tops-software/opentsdb" vars.reference=latest version=v2.1.1 
time="2015-09-10T00:19:38.173998321Z" level=error msg="response completed with error" err.code="BLOB_UNKNOWN" err.detail=sha256:ec46c816489d99bd6a68c0f34e11c10f2d9891addb2fc2ca246d2b5b2f2180cb err.message="blob unknown to registry" http.request.host="localhost:5000" http.request.id=6516b3a2-12c7-43dd-9083-d46020d4597d http.request.method=PUT http.request.remoteaddr="172.17.42.1:50415" http.request.uri="/v2/tops-software/opentsdb/manifests/latest" http.request.useragent="docker/1.7.1 go/go1.4.2 git-commit/786b29d kernel/2.6.32-573.3.1.el6.x86_64 os/linux arch/amd64" http.response.contenttype="application/json; charset=utf-8" http.response.duration=5.803492ms http.response.status=404 http.response.written=157 instance.id=15c05e4b-1402-4e57-91a3-0414d0969c0c vars.name="tops-software/opentsdb" vars.reference=latest version=v2.1.1 
172.17.42.1 - - [10/Sep/2015:00:19:38 +0000] "PUT /v2/tops-software/opentsdb/manifests/latest HTTP/1.0" 404 157 "" "docker/1.7.1 go/go1.4.2 git-commit/786b29d kernel/2.6.32-573.3.1.el6.x86_64 os/linux arch/amd64"

Running the 'docker push' command again will usually succeed. I've seen this happen twice so far, and it's been on a different registry instance each time.

It probably doesn't matter, but these registry instances are sitting behind nginx with a simple proxy_pass directive.

@RichardScothern

This comment has been minimized.

Contributor

RichardScothern commented Sep 10, 2015

Hi @agaffney this is a closed issue and we discourage continued conversations within them. We will probably issue a patch release with this and other bug fixes. If your problem persists you can open a new issue.

@agaffney

This comment has been minimized.

agaffney commented Sep 10, 2015

Sorry, I didn't notice that the issue had been closed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment