summary refs log tree commit diff
diff options
context:
space:
mode:
authorSean Quah <8349537+squahtx@users.noreply.github.com>2022-04-28 16:49:50 +0100
committerGitHub <noreply@github.com>2022-04-28 15:49:50 +0000
commit0b684b59e5ef761575830e9bcdfebcb13c6d2132 (patch)
tree248f4b30d2e5037a413364c05088c31b54255dc0
parentAdd linebreak to pipx install quote in README (#12579) (diff)
downloadsynapse-0b684b59e5ef761575830e9bcdfebcb13c6d2132.tar.xz
Fix logging of incorrect status codes for disconnected requests (#12580)
The status code of requests must always be set, regardless of client
disconnection, otherwise they will always be logged as 200!.

Broken for `respond_with_json` in
f48792eec43f893f4f893ffdcbf00f8958b6f6b5.
Broken for `respond_with_json_bytes` in
3e58ce72b42f2ae473c1e76a967548cd6fa7e2e6.
Broken for `respond_with_html_bytes` in
ea26e9a98b0541fc886a1cb826a38352b7599dbe.

Signed-off-by: Sean Quah <seanq@element.io>
-rw-r--r--changelog.d/12580.bugfix1
-rw-r--r--synapse/http/server.py12
-rw-r--r--tests/handlers/test_cas.py14
-rw-r--r--tests/handlers/test_saml.py14
4 files changed, 36 insertions, 5 deletions
diff --git a/changelog.d/12580.bugfix b/changelog.d/12580.bugfix
new file mode 100644

index 0000000000..bedce405e2 --- /dev/null +++ b/changelog.d/12580.bugfix
@@ -0,0 +1 @@ +Fix a long standing bug where status codes would almost always get logged as 200!, irrespective of the actual status code, when clients disconnect before a request has finished processing. diff --git a/synapse/http/server.py b/synapse/http/server.py
index b8a7a0f5df..1cf49830e8 100644 --- a/synapse/http/server.py +++ b/synapse/http/server.py
@@ -683,6 +683,9 @@ def respond_with_json( Returns: twisted.web.server.NOT_DONE_YET if the request is still active. """ + # The response code must always be set, for logging purposes. + request.setResponseCode(code) + # could alternatively use request.notifyFinish() and flip a flag when # the Deferred fires, but since the flag is RIGHT THERE it seems like # a waste. @@ -697,7 +700,6 @@ def respond_with_json( else: encoder = _encode_json_bytes - request.setResponseCode(code) request.setHeader(b"Content-Type", b"application/json") request.setHeader(b"Cache-Control", b"no-cache, no-store, must-revalidate") @@ -728,13 +730,15 @@ def respond_with_json_bytes( Returns: twisted.web.server.NOT_DONE_YET if the request is still active. """ + # The response code must always be set, for logging purposes. + request.setResponseCode(code) + if request._disconnected: logger.warning( "Not sending response to request %s, already disconnected.", request ) return None - request.setResponseCode(code) request.setHeader(b"Content-Type", b"application/json") request.setHeader(b"Content-Length", b"%d" % (len(json_bytes),)) request.setHeader(b"Cache-Control", b"no-cache, no-store, must-revalidate") @@ -840,6 +844,9 @@ def respond_with_html_bytes(request: Request, code: int, html_bytes: bytes) -> N code: The HTTP response code. html_bytes: The HTML bytes to use as the response body. """ + # The response code must always be set, for logging purposes. + request.setResponseCode(code) + # could alternatively use request.notifyFinish() and flip a flag when # the Deferred fires, but since the flag is RIGHT THERE it seems like # a waste. @@ -849,7 +856,6 @@ def respond_with_html_bytes(request: Request, code: int, html_bytes: bytes) -> N ) return None - request.setResponseCode(code) request.setHeader(b"Content-Type", b"text/html; charset=utf-8") request.setHeader(b"Content-Length", b"%d" % (len(html_bytes),)) diff --git a/tests/handlers/test_cas.py b/tests/handlers/test_cas.py
index a54aa29cf1..751025c5da 100644 --- a/tests/handlers/test_cas.py +++ b/tests/handlers/test_cas.py
@@ -201,4 +201,16 @@ class CasHandlerTestCase(HomeserverTestCase): def _mock_request(): """Returns a mock which will stand in as a SynapseRequest""" - return Mock(spec=["getClientIP", "getHeader", "_disconnected"]) + mock = Mock( + spec=[ + "finish", + "getClientIP", + "getHeader", + "setHeader", + "setResponseCode", + "write", + ] + ) + # `_disconnected` musn't be another `Mock`, otherwise it will be truthy. + mock._disconnected = False + return mock diff --git a/tests/handlers/test_saml.py b/tests/handlers/test_saml.py
index 8d4404eda1..e2f0f90ef1 100644 --- a/tests/handlers/test_saml.py +++ b/tests/handlers/test_saml.py
@@ -349,4 +349,16 @@ class SamlHandlerTestCase(HomeserverTestCase): def _mock_request(): """Returns a mock which will stand in as a SynapseRequest""" - return Mock(spec=["getClientIP", "getHeader", "_disconnected"]) + mock = Mock( + spec=[ + "finish", + "getClientIP", + "getHeader", + "setHeader", + "setResponseCode", + "write", + ] + ) + # `_disconnected` musn't be another `Mock`, otherwise it will be truthy. + mock._disconnected = False + return mock