get internal error on download multi-part file

[Bulat Gaifullin]

I am trying to download file from swift via proxy and receive the internal error:

HTTP/1.1 500 Internal Error
Content-Length: 17
Content-Type: text/plain
X-Openstack-Request-Id: tx4f1516f9c8d44389a6dac-005ab7d3f4
X-Trans-Id: tx4f1516f9c8d44389a6dac-005ab7d3f4
Date: Sun, 25 Mar 2018 16:53:06 GMT

the log contains following lines:

Mar 25 16:53:06 proxy4 swift-proxy: - - 25/Mar/2018/16/53/06 GET /v1/AUTH_42859d61583d48b7aead939fb39cb898/test%3Fprefix%3DSW_DVD9_Win_Svr_STD_Core_and_DataCtr_Core_2016_64Bit_Russian_-3_MLF_X21-30363.ISO.part%26format%3Djson HTTP/1.0 200
 - curl/7.29.0%20DLO%20MultipartGET gAAAAABat8_7Df2T... - 188 - tx14dc6f3012024f44ab27e-005ab7d3f1 X-Auth-Token:%20gAAAAABat8_7Df2TnfRnVz570E3exU62n3g8Fv9ibV6opwQmJTWXMeHBwcLF9S62_15wJ85JmupXtLTg6Sd7s7aEut8oJnpnJ3rae2Ec_iTk0WVz5qbamXPbHcn
ze8BpIegatoobryDzPoKKxA3ObpsU5k9vcXLuqmwD3GcJ67losBfndnw4o18%0AHost:%2010.1.1.203%0AX-User-Id:%20ea291d0d3da448d483483abc2d6aa235%0AX-Project-Id:%2042859d61583d48b7aead939fb39cb898%0AUser-Agent:%20curl/7.29.0%20DLO%20MultipartGET%0AX-Tran
s-Id:%20tx14dc6f3012024f44ab27e-005ab7d3f1 0.0098 DLO - 1521996786.048336983 1521996786.058136940 0
Mar 25 16:53:06 proxy4 catch_errors: Error: An error occurred: #012Traceback (most recent call last):#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/catch_errors.py", line 41, in handle_request#012 resp = self._app
_call(env)#012 File "/usr/lib/python2.7/site-packages/swift/common/wsgi.py", line 1074, in _app_call#012 resp = self.app(env, self._start_response)#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/gatekeeper.py", li
ne 123, in __call__#012 return self.app(env, gatekeeper_response)#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/healthcheck.py", line 52, in __call__#012 return self.app(env, start_response)#012 File "/usr/lib
/python2.7/site-packages/swift/common/middleware/memcache.py", line 109, in __call__#012 return self.app(env, start_response)#012 File "/usr/lib/python2.7/site-packages/swift/common/swob.py", line 1402, in _wsgify_self#012 return f
unc(self, Request(env))(env, start_response)#012 File "/usr/lib/python2.7/site-packages/swift/common/swob.py", line 1402, in _wsgify_self#012 return func(self, Request(env))(env, start_response)#012 File "/usr/lib/python2.7/site-pack
ages/swift/common/middleware/tempurl.py", line 451, in __call__#012 return self.app(env, start_response)#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/ratelimit.py", line 301, in __call__#012 return self.app(en
v, start_response)#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/list_endpoints.py", line 200, in __call__#012 return self.app(env, start_response)#012 File "/usr/lib/python2.7/site-packages/webob/dec.py", line 1
31, in __call__#012 resp = self.call_func(req, *args, **self.kwargs)#012 File "/usr/lib/python2.7/site-packages/webob/dec.py", line 196, in call_func#012 return self.func(req, *args, **kwargs)#012 File "/usr/lib/python2.7/site-pac
kages/keystonemiddleware/auth_token/__init__.py", line 337, in __call__#012 response = req.get_response(self._app)#012 File "/usr/lib/python2.7/site-packages/webob/request.py", line 1316, in send#012 application, catch_exc_info=Fal
se)#012 File "/usr/lib/python2.7/site-packages/webob/request.py", line 1280, in call_application#012 app_iter = application(self.environ, start_response)#012 File "/usr/lib/python2.7/site-packages/swift3/middleware.py", line 95, in _
_call__#012 return resp(env, start_response)#012 File "/usr/lib/python2.7/site-packages/swift3/s3_token_middleware.py", line 235, in __call__#012 return self._app(environ, start_response)#012 File "/usr/lib/python2.7/site-packages
/swift/common/middleware/keystoneauth.py", line 234, in __call__#012 return self.app(environ, keystone_start_response)#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/copy.py", line 272, in __call__#012 return se
lf.app(env, start_response)#012 File "/usr/lib/python2.7/site-packages/swift/common/swob.py", line 1402, in _wsgify_self#012 return func(self, Request(env))(env, start_response)#012 File "/usr/lib/python2.7/site-packages/swift/common
/swob.py", line 1402, in _wsgify_self#012 return func(self, Request(env))(env, start_response)#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/slo.py", line 1424, in __call__#012 return self.handle_multipart_get_
or_head(req, start_response)#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/slo.py", line 1051, in handle_multipart_get_or_head#012 return SloGetContext(self).handle_slo_get_or_head(req, start_response)#012 File "
/usr/lib/python2.7/site-packages/swift/common/middleware/slo.py", line 747, in handle_slo_get_or_head#012 resp_iter = self._app_call(req.environ)#012 File "/usr/lib/python2.7/site-packages/swift/common/wsgi.py", line 1074, in _app_cal
l#012 resp = self.app(env, self._start_response)#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/dlo.py", line 405, in __call__#012 handle_request(req, start_response)#012 File "/usr/lib/python2.7/site-packages/
swift/common/middleware/dlo.py", line 353, in handle_request#012 response = self.get_or_head_response(req, value)#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/dlo.py", line 238, in get_or_head_response#012 req
, version, account, container, obj_prefix)#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/dlo.py", line 159, in _get_container_listing#012 return None, json.loads(''.join(con_resp.app_iter))#012 File "/usr/lib64/p
ython2.7/json/__init__.py", line 338, in loads#012 return _default_decoder.decode(s)#012 File "/usr/lib64/python2.7/json/decoder.py", line 366, in decode#012 obj, end = self.raw_decode(s, idx=_w(s, 0).end())#012 File "/usr/lib64/p
ython2.7/json/decoder.py", line 384, in raw_decode#012 raise ValueError("No JSON object could be decoded")#012ValueError: No JSON object could be decoded (txn: tx14dc6f3012024f44ab27e-005ab7d3f1)
Mar 25 16:53:08 proxy4 container-server: 10.0.1.200 - - [25/Mar/2018:16:53:08 +0000] "GET /md0/977/.misplaced_objects/1521993600" 404 - "GET http://localhost/v1/.misplaced_objects/1521993600?marker=&prefix=&end_marker=&format=json" "tx4f1
516f9c8d44389a6dac-005ab7d3f4" "proxy-server 42629" 0.0021 "-" 31459 0

[Tim Burke (1-tim-z)]

The container controller should always set the query param format=json [1], which will (should?) override any Accept headers -- and we see that in that first line from your proxy-server log:

  /v1/AUTH_42859d61583d48b7aead939fb39cb898/test?prefix=SW_DVD9_Win_Svr_STD_Core_and_DataCtr_Core_2016_64Bit_Russian_-3_MLF_X21-30363.ISO.part&format=json

Is the client sending any Accept headers of its own? What's your proxy-server pipeline look like? In particular, I wonder whether staticweb is enabled, and if so, whether there might be an ordering problem between dlo and staticweb.

What response do you get if you do a GET directly to the container server? You can get the nodes you'll want to check with something like

  swift-get-nodes /etc/swift/container.ring.gz AUTH_42859d61583d48b7aead939fb39cb898/test

On my dev box, the output includes something like

  curl -g -I -XHEAD "http://127.0.0.1:6041/sdb4/14/AUTH_42859d61583d48b7aead939fb39cb898/test"

You'll want to take the URL and add the query params from your request log and any Accept header from your client to make a command line like

  curl -i http://127.0.0.1:6041/sdb4/14/AUTH_42859d61583d48b7aead939fb39cb898/test?prefix=SW_DVD9_Win_Svr_STD_Core_and_DataCtr_Core_2016_64Bit_Russian_-3_MLF_X21-30363.ISO.part&format=json -H "Accept: text/plain"

Does *that* respond with JSON, or something else?

[1] https://github.com/openstack/swift/blob/2.17.0/swift/proxy/controllers/container.py#L102-L104

[Bulat Gaifullin (bulat.gaifullin)]

In my opinion, the problem in code, we make requests and expects that response will be in json format, but we do not inform server that we expect response as json.
I have prepared patch, to fix this: https://review.openstack.org/#/c/556277/1

[Bulat Gaifullin (bulat.gaifullin)]

swift-get-nodes /etc/swift/container.ring.gz AUTH_42859d61583d48b7aead939fb39cb898/test

Account AUTH_42859d61583d48b7aead939fb39cb898
Container test
Object None

Partition 732
Hash b7061894c2e3e95019922044ae5ba1e7

Server:Port Device 10.0.1.200:6201 md0
Server:Port Device 10.0.1.202:6201 md0
Server:Port Device 10.0.1.201:6201 md0
Server:Port Device 10.0.1.203:6201 md0

curl -g -I -XHEAD "http://10.0.1.200:6201/md0/732/AUTH_42859d61583d48b7aead939fb39cb898/test"
curl -g -I -XHEAD "http://10.0.1.202:6201/md0/732/AUTH_42859d61583d48b7aead939fb39cb898/test"
curl -g -I -XHEAD "http://10.0.1.201:6201/md0/732/AUTH_42859d61583d48b7aead939fb39cb898/test"
curl -g -I -XHEAD "http://10.0.1.203:6201/md0/732/AUTH_42859d61583d48b7aead939fb39cb898/test"

Use your own device location of servers:
such as "export DEVICE=/srv/node"
ssh 10.0.1.200 "ls -lah ${DEVICE:-/srv/node*}/md0/containers/732/1e7/b7061894c2e3e95019922044ae5ba1e7"
ssh 10.0.1.202 "ls -lah ${DEVICE:-/srv/node*}/md0/containers/732/1e7/b7061894c2e3e95019922044ae5ba1e7"
ssh 10.0.1.201 "ls -lah ${DEVICE:-/srv/node*}/md0/containers/732/1e7/b7061894c2e3e95019922044ae5ba1e7"
ssh 10.0.1.203 "ls -lah ${DEVICE:-/srv/node*}/md0/containers/732/1e7/b7061894c2e3e95019922044ae5ba1e7"

note: `/srv/node*` is used as default value of `devices`, the real value is set in the config file on each storage node.

curl -g -I -XHEAD "http://10.0.1.200:6201/md0/732/AUTH_42859d61583d48b7aead939fb39cb898/test"
HTTP/1.1 204 No Content
X-Backend-Timestamp: 1516147706.22688
X-Container-Object-Count: 111
X-Put-Timestamp: 1516147706.21897
X-Backend-Put-Timestamp: 1516147706.21897
Last-Modified: Wed, 17 Jan 2018 00:08:27 GMT
X-Backend-Delete-Timestamp: 0000000000.00000
X-Container-Bytes-Used: 169852754740
X-Timestamp: 1516147706.22688
X-Backend-Storage-Policy-Index: 0
Content-Type: text/plain; charset=utf-8
X-Backend-Status-Changed-At: 1516147706.21897
Content-Length: 0
Date: Tue, 27 Mar 2018 07:32:29 GMT

the command outputs:

curl -i "http://10.0.1.200:6201/md0/732/AUTH_42859d61583d48b7aead939fb39cb898/test?prefix=SW_DVD9_Win_Svr_STD_Core_and_DataCtr_Core_2016_64Bit_Russian_-3_MLF_X21-30363.ISO.part&format=json" -H "Accept: text/plain" -H "Accept: text/plain"
HTTP/1.1 200 OK
Content-Length: 526
X-Backend-Timestamp: 1516147706.22688
X-Container-Object-Count: 111
X-Put-Timestamp: 1516147706.21897
X-Backend-Put-Timestamp: 1516147706.21897
Last-Modified: Wed, 17 Jan 2018 00:08:27 GMT
X-Backend-Delete-Timestamp: 0000000000.00000
X-Container-Bytes-Used: 169852754740
X-Timestamp: 1516147706.22688
X-Backend-Storage-Policy-Index: 0
Content-Type: application/json; charset=utf-8
X-Backend-Status-Changed-At: 1516147706.21897
Date: Tue, 27 Mar 2018 07:32:35 GMT

[{"hash": "50c3bc20c789a917cc0c28e2c8e8f715", "last_modified": "2018-01-17T00:18:18.343570", "bytes": 4096000000, "name": "SW_DVD9_Win_Svr_STD_Core_and_DataCtr_Core_2016_64Bit_Russian_-3_MLF_X21-30363.ISO.part/000000", "content_type": "application/octet-stream"}, {"hash": "3a35f27e249f2cb4750524baa3703439", "last_modified": "2018-01-17T00:18:18.536620", "bytes": 1775667200, "name": "SW_DVD9_Win_Svr_STD_Core_and_DataCt...

[Bulat Gaifullin (bulat.gaifullin)]

any updates on this?

[Bulat Gaifullin (bulat.gaifullin)]

Can anybody review the patch, the problem is actual for our installation.
if there is issue in configuration, how to fix it without modification of code?

[Anton (a.porabkovich)]

python-swiftclient 3.6.0
swift 2.19.0

swift list backup --lh |grep advideo.tar.gz
   0 2018-10-15 02:28:55 application/x-tar 2018-10-15/accounts/advideo.tar.gz
610M 2018-10-15 02:28:45 application/x-tar 2018-10-15/accounts/advideo.tar.gz.part/000000
493M 2018-10-15 02:28:45 application/x-tar 2018-10-15/accounts/advideo.tar.gz.part/000001

$ swift --debug download backup 2018-10-15/accounts/advideo.tar.gz
DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): storage
DEBUG:urllib3.connectionpool:https://storage:443 "GET /v1/AUTH_63cfac2c75ee419bbbd8c638d8b0dae0/backup/2018-10-15/accounts/advideo.tar.gz HTTP/1.1" 500 17
INFO:swiftclient:REQ: curl -i https://storage/v1/AUTH_63cfac2c75ee419bbbd8c638d8b0dae0/backup/2018-10-15/accounts/advideo.tar.gz -X GET -H "X-Auth-Token: gAAAAABbxEZzwvgW_mDLmJgLVZ-obzavwHQc9vU6QFS7IOXySyBSBbMk_Fk-YO3UrY3dw5Zv9wv4P4iHH5di1-jEzrkT7NzWJu9o9d3qg_jRwb6lWvMG6vB-_XQ1w1pdYxys0nTgmY81BXrb5JMdGwgtZAW5LbGsY2pvsDNjtUympX8ybSteYFE"
INFO:swiftclient:RESP STATUS: 500 Internal Error
INFO:swiftclient:RESP HEADERS: {u'Date': u'Mon, 15 Oct 2018 07:49:07 GMT', u'Content-Length': u'17', u'Content-Type': u'text/plain', u'X-Openstack-Request-Id': u'tx92c2c6c75c1d4bcf92cdd-005bc44673', u'X-Trans-Id': u'tx92c2c6c75c1d4bcf92cdd-005bc44673'}
INFO:swiftclient:RESP BODY: An error occurred

I try to receive the list of files or to load the file and receive the internal error:

proxy_catch_errors: Error: An error occurred:
#012Traceback (most recent call last):
#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/catch_errors.py", line 75, in handle_request
#012 resp = self._app_call(env)
#012 File "/usr/lib/python2.7/site-packages/swift/common/wsgi.py", line 1196, in _app_call
#012 resp = self.app(env, self._start_response)
#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/gatekeeper.py", line 122, in __call__
#012 return self.app(env, gatekeeper_response)
#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/healthcheck.py", line 52, in __call__
#012 return self.app(env, start_response)
#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/memcache.py", line 109, in __call__
#012 return self.app(env, start_response)
#012 File "/usr/lib/python2.7/site-packages/swift/common/swob.py", line 1488, in _wsgify_self
#012 return func(self, Request(env))(env, start_response)
#012 File "/usr/lib/python2.7/site-packages/swift/common/swob.py", line 1488, in _wsgify_self
#012 return func(self, Request(env))(env, start_response)
#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/tempurl.py", line 502, in __call__
#012 return self.app(env, start_response)
#012 File "/usr/lib/python2.7/site-packages/swift/common/middleware/ratelimit.py", line 311, in __call__
#012 return self.app(env, start_response)
#012 File "/usr/lib/python2.7/site-packages/webob/dec.py", line 129, in __call__
#012 resp = self.call_func(req, *args, **kw)
#012 File "/usr/lib/python2.7/site-packages/webob/dec.py", line 193, in call_func
#012 return self.func(req, *args, **kwargs)
#012 File "...