ChunkReadTimeout exception in file_iter in swift proxy server not handled

[Renuka Apte]

If the ChunkReadTimeout exception is raised in file_iter, nothing seems to handle it and return an appropriate Http error.
As a result, glance (and nova-compute) sit around waiting for image streaming to be completed.

I looked at the upstream code in github, and this still seems to be an issue.

proxy-server ERROR with Object server 192.168.1.197:6000/xvdg re: Trying to read during GET of /v1/AUTH_Administrator/glance/3: ChunkReadTimeout (10s) (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server 192.168.1.194 192.168.1.194 15/Nov/2011/22/08/37 GET /v1/AUTH_Administrator/glance/3 HTTP/1.0 200 - - 999888777666 - 264765440 - txd559806a48ab466f9a7b8aa35d985310 - 182.7217
proxy-server STDOUT: Traceback (most recent call last): (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: File "/usr/lib/python2.6/site-packages/eventlet/greenpool.py", line 80, in _spawn_n_impl (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: func(*args, **kwargs) (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: File "/usr/lib/python2.6/site-packages/eventlet/wsgi.py", line 508, in process_request (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: proto = self.protocol(socket, address, self) (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: File "/usr/lib/python2.6/SocketServer.py", line 615, in __init__ (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: self.handle() (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: File "/usr/lib/python2.6/BaseHTTPServer.py", line 329, in handle (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: self.handle_one_request() (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: File "/usr/lib/python2.6/site-packages/eventlet/wsgi.py", line 232, in handle_one_request (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: self.handle_one_response() (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: File "/usr/lib/python2.6/site-packages/eventlet/wsgi.py", line 347, in handle_one_response (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: for data in result: (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: File "/usr/lib/python2.6/site-packages/swift/proxy/server.py", line 679, in file_iter (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: chunk = source.read(self.app.object_chunk_size) (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: File "/usr/lib/python2.6/httplib.py", line 538, in read (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: s = self.fp.read(amt) (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: File "/usr/lib/python2.6/socket.py", line 353, in read (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: data = self._sock.recv(left) (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: File "/usr/lib/python2.6/site-packages/eventlet/greenio.py", line 238, in recv (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: timeout_exc=socket.timeout("timed out")) (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: File "/usr/lib/python2.6/site-packages/eventlet/hubs/__init__.py", line 121, in trampoline (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: return hub.switch() (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: File "/usr/lib/python2.6/site-packages/eventlet/hubs/hub.py", line 177, in switch (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: return self.greenlet.switch() (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)
proxy-server STDOUT: ChunkReadTimeout: 10 seconds (txn: txd559806a48ab466f9a7b8aa35d985310) (client_ip: 192.168.1.194)

[Renuka Apte (renukaapte)]

The timeout is not caught by the "except (Exception, TimeoutError):"
It can be caught simply by except:

The only way I could propagate the exception ahead, i.e. so the calling function could catch it, is by explicitly raising a different exception.

Not sure what the correct way to do this is.

[Chris Hoge (hoge)]

Has this bug been addressed at all? In my deployment I have about a 20% failure rate of image deployment because of glance/swift. Nova spins in the build process.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/11126

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/11126
Committed: http://github.com/openstack/swift/commit/edd38035be4f64d547938f44fb2d96a72eeb672a
Submitter: Jenkins
Branch: master

commit edd38035be4f64d547938f44fb2d96a72eeb672a
Author: MORITA Kazutaka <email address hidden>
Date: Fri Aug 10 14:00:09 2012 +0900

    handle exception correctly in _make_app_iter_reader

    _make_app_iter_reader uses a queue to pass read data to
    _make_app_iter, and uses an empty string as a terminator. The problem
    is that it pushes the same terminator even if it fails to reads the
    data. If an exception happens before pushing all data to the queue,
    _make_app_iter exits without yielding all data. In that case,
    proxy-server stops in the middle of sending data, and a client waits
    for all data to come infinitely.

    This patch uses a boolean value for the terminator instead of an empty
    string to distinguish the results, and raises an exception in the
    error cases. Fixes bug 890888.

    Change-Id: Ie4d48025843aa1bb600446da6f4fc49f82a440bf