Description
-
I'm submitting a ...
[X ] bug report
[ ] feature request
[ ] question about the decisions made in the repository -
What is the current behavior?
As described in this answer, when CherryPy raises a TimeoutError, it's doing so because the request took longer than the timeout to complete, but it was still allowed to complete.
The docs say:
response.timeout: the number of seconds to allow responses to run
- If the current behavior is a bug, please provide the steps to reproduce and if possible a screenshots and logs of the problem.
Consider this script:
__requires__ = ['cherrypy']
import time
import os
import cherrypy
class Server:
@cherrypy.expose
def index(self):
time.sleep(5)
return 'done!'
@classmethod
def run(cls):
config = {
'global': {
'server.socket_port': int(os.environ.get('PORT', 8080)),
'engine.timeout_monitor.frequency': 1,
'response.timeout': 2,
},
}
cherrypy.quickstart(cls(), config=config)
__name__ == '__main__' and Server.run()
Run it with rwt:
$ PORT=8081 rwt -- test-timeout.py
Collecting cherrypy
Using cached CherryPy-11.0.0-py2.py3-none-any.whl
Collecting six (from cherrypy)
Using cached six-1.10.0-py2.py3-none-any.whl
Collecting cheroot>=5.2.0 (from cherrypy)
Using cached cheroot-5.8.3-py2.py3-none-any.whl
Collecting portend>=2.1.1 (from cherrypy)
Using cached portend-2.1.2-py2.py3-none-any.whl
Collecting tempora>=1.8 (from portend>=2.1.1->cherrypy)
Using cached tempora-1.9-py2.py3-none-any.whl
Collecting pytz (from tempora>=1.8->portend>=2.1.1->cherrypy)
Using cached pytz-2017.2-py2.py3-none-any.whl
Installing collected packages: six, cheroot, pytz, tempora, portend, cherrypy
Successfully installed cheroot-5.8.3 cherrypy-11.0.0 portend-2.1.2 pytz-2017.2 six-1.10.0 tempora-1.9
[18/Aug/2017:13:22:38] ENGINE Listening for SIGTERM.
[18/Aug/2017:13:22:38] ENGINE Listening for SIGHUP.
[18/Aug/2017:13:22:38] ENGINE Listening for SIGUSR1.
[18/Aug/2017:13:22:38] ENGINE Bus STARTING
[18/Aug/2017:13:22:38] ENGINE Started monitor thread 'Autoreloader'.
[18/Aug/2017:13:22:38] ENGINE Started monitor thread '_TimeoutMonitor'.
[18/Aug/2017:13:22:38] ENGINE Serving on http://127.0.0.1:8081
[18/Aug/2017:13:22:38] ENGINE Bus STARTED
Then time a request with curl:
$ time curl http://localhost:8081/
Unrecoverable error in the server.
Traceback (most recent call last):
File "/var/folders/c6/v7hnmq453xb6p2dbz1gqc6rr0000gn/T/rwt-abvklbkv/cherrypy/_cpwsgi.py", line 190, in trap
return func(*args, **kwargs)
File "/var/folders/c6/v7hnmq453xb6p2dbz1gqc6rr0000gn/T/rwt-abvklbkv/cherrypy/_cpwsgi.py", line 106, in __call__
return self.nextapp(environ, start_response)
File "/var/folders/c6/v7hnmq453xb6p2dbz1gqc6rr0000gn/T/rwt-abvklbkv/cherrypy/_cpwsgi.py", line 439, in tail
return self.response_class(environ, start_response, self.cpapp)
File "/var/folders/c6/v7hnmq453xb6p2dbz1gqc6rr0000gn/T/rwt-abvklbkv/cherrypy/_cpwsgi.py", line 245, in __init__
self.run()
File "/var/folders/c6/v7hnmq453xb6p2dbz1gqc6rr0000gn/T/rwt-abvklbkv/cherrypy/_cpwsgi.py", line 348, in run
request.run(meth, path, qs, rproto, headers, rfile)
File "/var/folders/c6/v7hnmq453xb6p2dbz1gqc6rr0000gn/T/rwt-abvklbkv/cherrypy/_cprequest.py", line 617, in run
raise cherrypy.TimeoutError()
cherrypy._cperror.TimeoutError
curl http://localhost:8081/ 0.01s user 0.01s system 0% cpu 5.028 total
The request takes the full 5 seconds to complete even though the timeout was set to 2 seconds. Additionally, the test will complete without timing out (in most cases) if the timeout_monitor frequency isn't increased.
- What is the expected behavior?
If we were to believe the docs, the request would not be allowed to run longer than the timeout period, but it clearly is allowed to run to completion. Yet, even though it's allowed to run to completion, an error is returned, losing the value of the computation even if the client was still connected to receive it. According to the referenced SO answer, it's difficult if not impossible to interrupt a thread safely. Since the request has to be allowed to run to completion, the "timeout" functionality is not behaving as a timeout but is instead behaving as "make fail if slow". Such behavior should be optional and disabled by default if it's supplied at all.
- What is the motivation / use case for changing the behavior?
The current implementation is misleading and causes harm.
Consider the condition where a user has just invoked a long-running request. They've left it to run to see if it will complete and are eager to see what the result is. The request runs for 10 minutes and finally completes, but when it does, the result is discarded and replaced with a timeout traceback.
Better would be for CherryPy docs to indicate that it cannot safely time out long-running requests and that requests that take too long should be managed out of process.
- Please tell us about your environment:
- Python version: 3.6.2
- OS: macOS 10.12.2
- Browser: curl