diff --git a/sanic/app.py b/sanic/app.py index c804c693..aae379b3 100644 --- a/sanic/app.py +++ b/sanic/app.py @@ -930,7 +930,7 @@ class Sanic: """ pass - async def handle_exception(self, request, exception): + async def handle_exception(self, request, exception, name=""): try: response = self.error_handler.response(request, exception) if isawaitable(response): @@ -947,6 +947,17 @@ class Sanic: response = HTTPResponse( "An error occurred while handling an error", status=500 ) + # Run response middleware + if response is not None: + try: + response = await self._run_response_middleware( + request, response, request_name=name + ) + except Exception: + error_logger.exception( + "Exception occurred in one of response " + "middleware handlers" + ) return response @@ -1011,62 +1022,34 @@ class Sanic: response = handler(request, *args, **kwargs) if isawaitable(response): response = await response - except CancelledError: - # If response handler times out, the server handles the error - # and cancels the handle_request job. - # In this case, the transport is already closed and we cannot - # issue a response. - response = None - cancelled = True - raise - except Exception as e: - # -------------------------------------------- # - # Response Generation Failed - # -------------------------------------------- # - response = await self.handle_exception(request, e) - finally: - # -------------------------------------------- # - # Response Middleware - # -------------------------------------------- # - # Don't run response middleware if response is None + # Run response middleware if response is not None: try: response = await self._run_response_middleware( request, response, request_name=name ) - except CancelledError: - # Response middleware can timeout too, as above. - response = None - cancelled = True - except BaseException: + except Exception: error_logger.exception( "Exception occurred in one of response " "middleware handlers" ) - if cancelled: - raise CancelledError() - - try: - # pass the response to the correct callback + # Stream response if isinstance(response, StreamingHTTPResponse): await response.stream(request) elif isinstance(response, HTTPResponse): await request.respond(response).send(end_stream=True) - else: - raise ServerError(f"Invalid response type {response} (need HTTPResponse)") - except Exception as e: - response = await self.handle_exception(request, e) - - # pass the response to the correct callback - if response is None: - pass - elif isinstance(response, StreamingHTTPResponse): - await response.stream(request) - elif isinstance(response, HTTPResponse): - await request.respond(response).send(end_stream=True) else: raise ServerError( - f"Invalid response type {response} (need HTTPResponse)") + f"Invalid response type {response!r} (need HTTPResponse)" + ) + + except Exception as e: + # -------------------------------------------- # + # Response Generation Failed + # -------------------------------------------- # + response = await self.handle_exception(request, e, name) + await request.respond(response).send(end_stream=True) + # -------------------------------------------------------------------- # # Testing diff --git a/sanic/http.py b/sanic/http.py index 6befc3fa..439ae52a 100644 --- a/sanic/http.py +++ b/sanic/http.py @@ -128,13 +128,13 @@ class Http: logger.error(f"{self.request} body not consumed.") async for _ in self: pass - except Exception as e: - self.exception = e - except BaseException: + except CancelledError: # Exit after trying to finish a response self.keep_alive = False if self.exception is None: self.exception = ServiceUnavailable(f"Cancelled") + except Exception as e: + self.exception = e if self.exception: e, self.exception = self.exception, None # Exception while idle? Probably best to close connection diff --git a/sanic/response.py b/sanic/response.py index c71a5376..fc6c64b1 100644 --- a/sanic/response.py +++ b/sanic/response.py @@ -76,6 +76,7 @@ class StreamingHTTPResponse(BaseHTTPResponse): self.content_type, ).send await self.streaming_fn(self) + await self.send(end_stream=True) class HTTPResponse(BaseHTTPResponse): __slots__ = ("body", "status", "content_type", "headers", "_cookies") diff --git a/sanic/server.py b/sanic/server.py index d11e14e0..b7f9bada 100644 --- a/sanic/server.py +++ b/sanic/server.py @@ -167,24 +167,28 @@ class HttpProtocol(asyncio.Protocol): await self._data_received.wait() def check_timeouts(self): - """Runs itself once a second to enforce any expired timeouts.""" - if not self._task: - return - duration = current_time() - self._time - stage = self._http.stage - if stage is Stage.IDLE and duration > self.keep_alive_timeout: - logger.debug("KeepAlive Timeout. Closing connection.") - elif stage is Stage.REQUEST and duration > self.request_timeout: - self._http.exception = RequestTimeout("Request Timeout") - elif ( - stage in (Stage.REQUEST, Stage.FAILED) - and duration > self.response_timeout - ): - self._http.exception = ServiceUnavailable("Response Timeout") - else: - self.loop.call_later(1.0, self.check_timeouts) - return - self._task.cancel() + """Runs itself periodically to enforce any expired timeouts.""" + try: + if not self._task: + return + duration = current_time() - self._time + stage = self._http.stage + if stage is Stage.IDLE and duration > self.keep_alive_timeout: + logger.debug("KeepAlive Timeout. Closing connection.") + elif stage is Stage.REQUEST and duration > self.request_timeout: + self._http.exception = RequestTimeout("Request Timeout") + elif ( + stage in (Stage.HANDLER, Stage.RESPONSE, Stage.FAILED) + and duration > self.response_timeout + ): + self._http.exception = RequestTimeout("Response Timeout") + else: + interval = min(self.keep_alive_timeout, self.request_timeout, self.response_timeout) / 2 + self.loop.call_later(max(0.1, interval), self.check_timeouts) + return + self._task.cancel() + except: + logger.exception("protocol.check_timeouts") async def send(self, data): """Writes data with backpressure control.""" @@ -232,6 +236,10 @@ class HttpProtocol(asyncio.Protocol): self.resume_writing() if self._task: self._task.cancel() + if self._debug and self._http and self._http.request: + logger.error( + f"Connection lost before response written @ {self._http.request.ip}", + ) except: logger.exception("protocol.connection_lost") diff --git a/tests/test_logging.py b/tests/test_logging.py index 5a54b75a..f7326872 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -109,12 +109,11 @@ def test_log_connection_lost(app, debug, monkeypatch): @app.route("/conn_lost") async def conn_lost(request): response = text("Ok") - response.output = Mock(side_effect=RuntimeError) + request.transport.close() return response - with pytest.raises(ValueError): - # catch ValueError: Exception during request - app.test_client.get("/conn_lost", debug=debug) + req, res = app.test_client.get("/conn_lost", debug=debug) + assert res is None log = stream.getvalue() diff --git a/tests/test_middleware.py b/tests/test_middleware.py index 6fc37001..f03fdc23 100644 --- a/tests/test_middleware.py +++ b/tests/test_middleware.py @@ -54,7 +54,7 @@ def test_middleware_response(app): def test_middleware_response_exception(app): - result = {"status_code": None} + result = {"status_code": "middleware not run"} @app.middleware("response") async def process_response(request, response): diff --git a/tests/test_request_timeout.py b/tests/test_request_timeout.py index c518f087..f4eb8ee9 100644 --- a/tests/test_request_timeout.py +++ b/tests/test_request_timeout.py @@ -79,8 +79,12 @@ class DelayableSanicTestClient(SanicTestClient): request_timeout_default_app = Sanic("test_request_timeout_default") request_no_timeout_app = Sanic("test_request_no_timeout") -request_timeout_default_app.config.REQUEST_TIMEOUT = 0.6 -request_no_timeout_app.config.REQUEST_TIMEOUT = 0.6 + +# Note: The delayed client pauses before making a request, so technically +# it is in keep alive duration. Earlier Sanic versions entered a new connection +# in request mode even if no bytes of request were received. +request_timeout_default_app.config.KEEP_ALIVE_TIMEOUT = 0.6 +request_no_timeout_app.config.KEEP_ALIVE_TIMEOUT = 0.6 @request_timeout_default_app.route("/1") diff --git a/tests/test_response.py b/tests/test_response.py index fdda7684..3bfce480 100644 --- a/tests/test_response.py +++ b/tests/test_response.py @@ -469,6 +469,7 @@ def test_file_stream_response_range( ) request, response = app.test_client.get("/files/{}".format(file_name)) + print(response.body) assert response.status == 206 assert "Content-Range" in response.headers assert response.headers["Content-Range"] == "bytes {}-{}/{}".format(