diff options
| author | Sean Quah <8349537+squahtx@users.noreply.github.com> | 2022-05-04 13:38:55 +0100 |
|---|---|---|
| committer | GitHub <noreply@github.com> | 2022-05-04 13:38:55 +0100 |
| commit | b2df0716bc0cf31b5f5f90a0599bc1d04a837e27 (patch) | |
| tree | 9ad31082ead4d5514efb145f13575544391c0fb1 | |
| parent | Include bundled aggregations for the latest event in a thread. (#12273) (diff) | |
| download | synapse-b2df0716bc0cf31b5f5f90a0599bc1d04a837e27.tar.xz | |
Improve logging for cancelled requests (#12587)
Don't log stack traces for cancelled requests and use a custom HTTP status code of 499. Signed-off-by: Sean Quah <seanq@element.io>
| -rw-r--r-- | changelog.d/12587.misc | 1 | ||||
| -rw-r--r-- | docs/usage/administration/request_log.md | 2 | ||||
| -rw-r--r-- | synapse/http/server.py | 30 |
3 files changed, 32 insertions, 1 deletions
diff --git a/changelog.d/12587.misc b/changelog.d/12587.misc new file mode 100644 index 0000000000..d26e332305 --- /dev/null +++ b/changelog.d/12587.misc @@ -0,0 +1 @@ +Add `@cancellable` decorator, for use on endpoint methods that can be cancelled when clients disconnect. diff --git a/docs/usage/administration/request_log.md b/docs/usage/administration/request_log.md index 316304c734..adb5f4f5f3 100644 --- a/docs/usage/administration/request_log.md +++ b/docs/usage/administration/request_log.md @@ -28,7 +28,7 @@ See the following for how to decode the dense data available from the default lo | NNNN | Total time waiting for response to DB queries across all parallel DB work from this request | | OOOO | Count of DB transactions performed | | PPPP | Response body size | -| QQQQ | Response status code (prefixed with ! if the socket was closed before the response was generated) | +| QQQQ | Response status code<br/>Suffixed with `!` if the socket was closed before the response was generated.<br/>A `499!` status code indicates that Synapse also cancelled request processing after the socket was closed.<br/> | | RRRR | Request | | SSSS | User-agent | | TTTT | Events fetched from DB to service this request (note that this does not include events fetched from the cache) | diff --git a/synapse/http/server.py b/synapse/http/server.py index 1cf49830e8..657bffcddd 100644 --- a/synapse/http/server.py +++ b/synapse/http/server.py @@ -43,6 +43,7 @@ from typing_extensions import Protocol from zope.interface import implementer from twisted.internet import defer, interfaces +from twisted.internet.defer import CancelledError from twisted.python import failure from twisted.web import resource from twisted.web.server import NOT_DONE_YET, Request @@ -82,6 +83,14 @@ HTML_ERROR_TEMPLATE = """<!DOCTYPE html> </html> """ +# A fictional HTTP status code for requests where the client has disconnected and we +# successfully cancelled the request. Used only for logging purposes. Clients will never +# observe this code unless cancellations leak across requests or we raise a +# `CancelledError` ourselves. +# Analogous to nginx's 499 status code: +# https://github.com/nginx/nginx/blob/release-1.21.6/src/http/ngx_http_request.h#L128-L134 +HTTP_STATUS_REQUEST_CANCELLED = 499 + def return_json_error(f: failure.Failure, request: SynapseRequest) -> None: """Sends a JSON error response to clients.""" @@ -93,6 +102,17 @@ def return_json_error(f: failure.Failure, request: SynapseRequest) -> None: error_dict = exc.error_dict() logger.info("%s SynapseError: %s - %s", request, error_code, exc.msg) + elif f.check(CancelledError): + error_code = HTTP_STATUS_REQUEST_CANCELLED + error_dict = {"error": "Request cancelled", "errcode": Codes.UNKNOWN} + + if not request._disconnected: + logger.error( + "Got cancellation before client disconnection from %r: %r", + request.request_metrics.name, + request, + exc_info=(f.type, f.value, f.getTracebackObject()), # type: ignore[arg-type] + ) else: error_code = 500 error_dict = {"error": "Internal server error", "errcode": Codes.UNKNOWN} @@ -155,6 +175,16 @@ def return_html_error( request, exc_info=(f.type, f.value, f.getTracebackObject()), # type: ignore[arg-type] ) + elif f.check(CancelledError): + code = HTTP_STATUS_REQUEST_CANCELLED + msg = "Request cancelled" + + if not request._disconnected: + logger.error( + "Got cancellation before client disconnection when handling request %r", + request, + exc_info=(f.type, f.value, f.getTracebackObject()), # type: ignore[arg-type] + ) else: code = HTTPStatus.INTERNAL_SERVER_ERROR msg = "Internal server error" |