summary refs log tree commit diff
diff options
context:
space:
mode:
authorSean Quah <8349537+squahtx@users.noreply.github.com>2022-05-04 13:38:55 +0100
committerGitHub <noreply@github.com>2022-05-04 13:38:55 +0100
commitb2df0716bc0cf31b5f5f90a0599bc1d04a837e27 (patch)
tree9ad31082ead4d5514efb145f13575544391c0fb1
parentInclude bundled aggregations for the latest event in a thread. (#12273) (diff)
downloadsynapse-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>
Diffstat (limited to '')
-rw-r--r--changelog.d/12587.misc1
-rw-r--r--docs/usage/administration/request_log.md2
-rw-r--r--synapse/http/server.py30
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"