Skip to content
This repository has been archived by the owner on Apr 26, 2024. It is now read-only.

Fix logging of incorrect status codes for disconnected requests #12580

Merged
merged 5 commits into from
Apr 28, 2022
Merged
Show file tree
Hide file tree
Changes from 3 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions changelog.d/12580.bugfix
Original file line number Diff line number Diff line change
@@ -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.
12 changes: 9 additions & 3 deletions synapse/http/server.py
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand All @@ -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")

Expand Down Expand Up @@ -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")
Expand Down Expand Up @@ -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.
Expand All @@ -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),))

Expand Down
14 changes: 13 additions & 1 deletion tests/handlers/test_cas.py
Original file line number Diff line number Diff line change
Expand Up @@ -201,4 +201,16 @@ def test_required_attributes(self) -> None:

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
Comment on lines +204 to +216
Copy link
Contributor Author

@squahtx squahtx Apr 28, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

test_required_attributes, above, results in a call to respond_with_html_bytes.
Previously, _disconnected would be a mock, which was truthy, so nothing would be written to the mock request.
After the changes in this PR, setResponseCode now gets called.

I've set _disconnected to False, since I don't think that was intended, and added the rest of the methods that now get called.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That seems reasonable. 👍