Can't push image to Ceph RADOS backend

[Facundo Ciccioli]

Hi there!

We are having issues when pushing an image to a docker registry using Ceph RADOS' Swift compatible API. Specifically, when trying to push we see the following:

$ docker push 10.0.8.87:5000/hello-world
The push refers to repository [10.0.8.87:5000/hello-world]
9c27e219663c: Pushing [==================================================>] 15.36kB
received unexpected HTTP status: 500 Internal Server Error

We can see it retrying 4 times and then the 500 comes out. After the push we can see on the container some objects were created (container was empty right before pushing):

$ openstack object list docker_registry_real -f value
files/docker/registry/v2/repositories/hello-world/_uploads/57b99308-87e7-4304-b747-7513f18b6176/data
files/docker/registry/v2/repositories/hello-world/_uploads/57b99308-87e7-4304-b747-7513f18b6176/hashstates/sha256/0
files/docker/registry/v2/repositories/hello-world/_uploads/57b99308-87e7-4304-b747-7513f18b6176/startedat
files/docker/registry/v2/repositories/hello-world/_uploads/5c3a3c88-4837-437c-a13e-56cd7bb3768e/data
files/docker/registry/v2/repositories/hello-world/_uploads/5c3a3c88-4837-437c-a13e-56cd7bb3768e/hashstates/sha256/0
files/docker/registry/v2/repositories/hello-world/_uploads/5c3a3c88-4837-437c-a13e-56cd7bb3768e/startedat
files/docker/registry/v2/repositories/hello-world/_uploads/6227ea69-f52a-4cf8-9c2b-7cfb5af0a04f/data
files/docker/registry/v2/repositories/hello-world/_uploads/6227ea69-f52a-4cf8-9c2b-7cfb5af0a04f/hashstates/sha256/0
files/docker/registry/v2/repositories/hello-world/_uploads/6227ea69-f52a-4cf8-9c2b-7cfb5af0a04f/startedat
files/docker/registry/v2/repositories/hello-world/_uploads/9f632071-2341-44d4-bde8-da56c78eb500/data
files/docker/registry/v2/repositories/hello-world/_uploads/9f632071-2341-44d4-bde8-da56c78eb500/hashstates/sha256/0
files/docker/registry/v2/repositories/hello-world/_uploads/9f632071-2341-44d4-bde8-da56c78eb500/startedat
files/docker/registry/v2/repositories/hello-world/_uploads/df0e031c-42b8-45d6-9b7b-9f0205df265c/data
files/docker/registry/v2/repositories/hello-world/_uploads/df0e031c-42b8-45d6-9b7b-9f0205df265c/hashstates/sha256/0
files/docker/registry/v2/repositories/hello-world/_uploads/df0e031c-42b8-45d6-9b7b-9f0205df265c/startedat

It seems it's creating the triplet data/hashstate/startedat with each retry. All the data files are empty.

On the registry's output we found this while pushing:

{
  "auth.user.name": "admin",
  "err.code": "unknown",
  "err.detail": "swift: Bad Request",
  "err.message": "unknown error",
  "go.version": "go1.11.2",
  "http.request.host": "10.0.8.87:5000",
  "http.request.id": "ed73da00-baaf-46aa-ad52-bc88768ad283",
  "http.request.method": "PATCH",
  "http.request.remoteaddr": "10.0.8.87:45932",
  "http.request.uri": "/v2/hello-world/blobs/uploads/e6614853-1556-4c15-b082-f684c84bd8dd?_state=aWHS_OxvXcYjZ4umzqXhcVLx9zxY48ZqVnkOEBiBwsN7Ik5hbWUiOiJoZWxsby13b3JsZCIsIlVVSUQiOiJlNjYxNDg1My0xNTU2LTRjMTUtYjA4Mi1mNjg0Yzg0YmQ4ZGQiLCJPZmZzZXQiOjAsIlN0YXJ0ZWRBdCI6IjIwMjAtMDctMjJUMTE6MjY6MjEuNDEzMTExODM0WiJ9",
  "http.request.useragent": "docker/18.09.7 go/go1.10.4 git-commit/2d0083d kernel/4.15.0-76-generic os/linux arch/amd64 UpstreamClient(Docker-Client/18.09.7 \\(linux\\))",
  "http.response.contenttype": "application/json; charset=utf-8",
  "http.response.duration": "114.100917ms",
  "http.response.status": 500,
  "http.response.written": 141,
  "level": "error",
  "msg": "response completed with error",
  "time": "2020-07-22T11:26:21.569256647Z",
  "vars.name": "hello-world",
  "vars.uuid": "e6614853-1556-4c15-b082-f684c84bd8dd"
}

Increasing Ceph's logging verbosity we spoted this as well:

2020-07-23 13:43:33.366 7f96ef8e6700 10 read_permissions on docker_registry_real[c151b349-f8dc-494d-be91-fe31125566a2.45815.2]:segments/2f6/46f636b65722f72656769737472792f76322f7265706f7369746f726965732f68656c6c6f2d776f726c642f5f75706c6f6164732f30653331616534342d343730352d346461642d623332392d636466383137343765376338
2f6461746172fa06ab735ae981d020d86ef937e85f941470103532a9350c693b6d16288da2da39a3ee5e6b4b0d3255bfef95601890afd80709/0000000000000001 only_bucket=0 ret=-36
2020-07-23 13:43:33.366 7f96ef8e6700 20 op->ERRORHANDLER: err_no=-36 new_err_no=-36

And using tcpdump we managed to temporarily reproduce the issue (since the token expires):

$ curl -v --request HEAD http://10.0.8.185/swift/v1/docker_registry_real/segments/2f6/46f636b65722f72656769737472792f76322f7265706f7369746f726965732f68656c6c6f2d776f726c642f5f75706c6f6164732f30653331616534342d343730352d346461642d623332392d6364663831373437653763382f6461746172fa06ab735ae981d020d86ef937e85f941470103532a9350c693b6d16288da2da39a3ee5e6b4b0d3255bfef95601890afd80709/0000000000000001 -H 'X-Auth-Token: gAAAAABfGZBx6ZTyYRHNNW07bWZpR5ok1hs-jYDbBjgwLxTj29Vd4CrZZDl9OJ4sVCeeQT2qDlCoSzEAa1k4SAHXRKKGJPgbhkT6RVMtMB_LKyA5r4wgHlS4Mj8Px2OtLUm3kWtCOa0S82t9Q5qG-91f5l1aRAOhJu7SHlsB98BfuCAtW7AhDvs'
Warning: Setting custom HTTP method to HEAD with -X/--request may not work the
Warning: way you want. Consider using -I/--head instead.
* Trying 10.0.8.185...
* TCP_NODELAY set
* Connected to 10.0.8.185 (10.0.8.185) port 80 (#0)
> HEAD /swift/v1/docker_registry_real/segments/2f6/46f636b65722f72656769737472792f76322f7265706f7369746f726965732f68656c6c6f2d776f726c642f5f75706c6f6164732f30653331616534342d343730352d346461642d623332392d6364663831373437653763382f6461746172fa06ab735ae981d020d86ef937e85f941470103532a9350c693b6d16288da2da39a3ee5e6b4b0d3255bfef95601890afd80709/0000000000000001 HTTP/1.1
> Host: 10.0.8.185
> User-Agent: curl/7.58.0
> Accept: */*
> X-Auth-Token: (edited)
>
< HTTP/1.1 400 Bad Request
< Content-Length: 22
< X-Trans-Id: tx0000000000000000003cf-005f199814-2f76e-default
< X-Openstack-Request-Id: tx0000000000000000003cf-005f199814-2f76e-default
< Accept-Ranges: bytes
< Content-Type: text/plain; charset=utf-8
< Date: Thu, 23 Jul 2020 14:00:52 GMT
<
* transfer closed with 22 bytes remaining to read
* stopped the pause stream!
* Closing connection 0
curl: (18) transfer closed with 22 bytes remaining to read

Environment is openstack train running on lxd. Versions are (app, version, revision):

ceilometer 13.1.0 273
ceilometer-agent 13.1.0 263
ceph-mon 13.2.9 48
ceph-osd 13.2.9 303
ceph-radosgw 13.2.9 288
cinder 15.1.0 303
cinder-ceph 15.1.0 256
designate 9.0.0 44
designate-bind 9.11.3+dfsg 29
docker-registry 155
glance 19.0.2 297
gnocchi 4.3.4 40
heat 13.0.1 276
keystone 16.0.1 315
memcached 29
mysql 5.7.20 290
neutron-api 15.0.2 286
neutron-gateway 15.0.2 282
neutron-openvswitch 15.0.2 276
nova-cloud-controller 20.2.0 345
nova-compute 20.2.0 317
openstack-dashboard 16.1.0 304
placement 2.0.0 11
rabbitmq-server 3.6.10 103

Please let me know if you want me to perform some additional test or provide more information.

Thanks!

[Facundo Ciccioli (fandanbango)]

I forgot to mention we found this bug that might be related: https://bugzilla.redhat.com/show_bug.cgi?id=1604979.

[Facundo Ciccioli (fandanbango)]

subscribed ~field-high

[Chris Sanders (chris.sanders)]

After further review, this is a limitation on the registry [0] it's not an incorrect configuration of the charm. I'm removing field-high as this is a limitation of the upstream project not a broken feature of the charm.

[0]: https://github.com/docker/distribution/issues/2189