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

Conversation

squahtx
Copy link
Contributor

@squahtx squahtx commented Apr 28, 2022

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 f48792e.
Broken for respond_with_json_bytes in 3e58ce7.
Broken for respond_with_html_bytes in ea26e9a.

Signed-off-by: Sean Quah seanq@element.io

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
f48792e.
Broken for `respond_with_json_bytes` in
3e58ce7.
Broken for `respond_with_html_bytes` in
ea26e9a.

Signed-off-by: Sean Quah <seanq@element.io>
@squahtx squahtx requested a review from a team as a code owner April 28, 2022 12:42
@clokep
Copy link
Contributor

clokep commented Apr 28, 2022

I think it is fine, but what got logged without setting this? (Or did an error occur?)

@squahtx
Copy link
Contributor Author

squahtx commented Apr 28, 2022

I think it is fine, but what got logged without setting this? (Or did an error occur?)

Nothing too unusual, just the regular logging you'd expect, eg.

Processed request: 232.476sec/-52.473sec (34.953sec, 3.824sec) (25.887sec/45.630sec/36382) 0B 200! "POST /_matrix/client/r0/keys/query HTTP/1.1" "Dart/2.16 (dart:io)" [0 dbevts]

It always came out as "200!" because twisted sets the status code to 200 by default.

There are some 500!s in the matrix.org logs, which I think happen when clients disconnect after the call to respond_*, during serialization of the JSON response.

@clokep
Copy link
Contributor

clokep commented Apr 28, 2022

Arg, you said they were always logged as 200 in the description. Sorry about that! Glad they were still properly logging the ! at least.

@squahtx
Copy link
Contributor Author

squahtx commented Apr 28, 2022

Sorry for the confusion, I shall update the description.

I seem to have broken some tests unfortunately.

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

Choose a reason for hiding this comment

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

That seems reasonable. 👍

@squahtx squahtx requested a review from clokep April 28, 2022 14:57
@squahtx
Copy link
Contributor Author

squahtx commented Apr 28, 2022

Re-requesting review since there was another test that was broken in the same way. The additional changes are the same fix, applied to another test.

@squahtx
Copy link
Contributor Author

squahtx commented Apr 28, 2022

Thanks for the fast review!

@squahtx squahtx enabled auto-merge (squash) April 28, 2022 15:26
@squahtx squahtx merged commit 0b684b5 into develop Apr 28, 2022
@squahtx squahtx deleted the squah/fix_disconnected_request_status_codes branch April 28, 2022 15:49
DMRobertson pushed a commit that referenced this pull request May 10, 2022
Synapse 1.59.0rc1 (2022-05-10)
==============================

This release makes several changes that server administrators should be aware of:

- Device name lookup over federation is now disabled by default. ([\#12616](#12616))
- The `synapse.app.appservice` and `synapse.app.user_dir` worker application types are now deprecated. ([\#12452](#12452), [\#12654](#12654))

See [the upgrade notes](https://github.com/matrix-org/synapse/blob/develop/docs/upgrade.md#upgrading-to-v1590) for more details.

Additionally, this release removes the non-standard `m.login.jwt` login type from Synapse. It can be replaced with `org.matrix.login.jwt` for identical behaviour. This is only used if `jwt_config.enabled` is set to `true` in the configuration. ([\#12597](#12597))

Features
--------

- Support [MSC3266](matrix-org/matrix-spec-proposals#3266) room summaries over federation. ([\#11507](#11507))
- Implement [changes](matrix-org/matrix-spec-proposals@4a77139) to [MSC2285 (hidden read receipts)](matrix-org/matrix-spec-proposals#2285). Contributed by @SimonBrandner. ([\#12168](#12168), [\#12635](#12635), [\#12636](#12636), [\#12670](#12670))
- Extend the [module API](https://github.com/matrix-org/synapse/blob/release-v1.59/synapse/module_api/__init__.py) to allow modules to change actions for existing push rules of local users. ([\#12406](#12406))
- Add the `notify_appservices_from_worker` configuration option (superseding `notify_appservices`) to allow a generic worker to be designated as the worker to send traffic to Application Services. ([\#12452](#12452))
- Add the `update_user_directory_from_worker` configuration option (superseding `update_user_directory`) to allow a generic worker to be designated as the worker to update the user directory. ([\#12654](#12654))
- Add new `enable_registration_token_3pid_bypass` configuration option to allow registrations via token as an alternative to verifying a 3pid. ([\#12526](#12526))
- Implement [MSC3786](matrix-org/matrix-spec-proposals#3786): Add a default push rule to ignore `m.room.server_acl` events. ([\#12601](#12601))
- Add new `mau_appservice_trial_days` configuration option to specify a different trial period for users registered via an appservice. ([\#12619](#12619))

Bugfixes
--------

- Fix a bug introduced in Synapse 1.48.0 where the latest thread reply provided failed to include the proper bundled aggregations. ([\#12273](#12273))
- Fix a bug introduced in Synapse 1.22.0 where attempting to send a large amount of read receipts to an application service all at once would result in duplicate content and abnormally high memory usage. Contributed by Brad & Nick @ Beeper. ([\#12544](#12544))
- Fix a bug introduced in Synapse 1.57.0 which could cause `Failed to calculate hosts in room` errors to be logged for outbound federation. ([\#12570](#12570))
- 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. ([\#12580](#12580))
- Fix race when persisting an event and deleting a room that could lead to outbound federation breaking. ([\#12594](#12594))
- Fix a bug introduced in Synapse 1.53.0 where bundled aggregations for annotations/edits were incorrectly calculated. ([\#12633](#12633))
- Fix a long-standing bug where rooms containing power levels with string values could not be upgraded. ([\#12657](#12657))
- Prevent memory leak from reoccurring when presence is disabled. ([\#12656](#12656))

Updates to the Docker image
---------------------------

- Explicitly opt-in to using [BuildKit-specific features](https://github.com/moby/buildkit/blob/master/frontend/dockerfile/docs/syntax.md) in the Dockerfile. This fixes issues with building images in some GitLab CI environments. ([\#12541](#12541))
- Update the "Build docker images" GitHub Actions workflow to use `docker/metadata-action` to generate docker image tags, instead of a custom shell script. Contributed by @henryclw. ([\#12573](#12573))

Improved Documentation
----------------------

- Update SQL statements and replace use of old table `user_stats_historical` in docs for Synapse Admins. ([\#12536](#12536))
- Add missing linebreak to `pipx` install instructions. ([\#12579](#12579))
- Add information about the TCP replication module to docs. ([\#12621](#12621))
- Fixes to the formatting of `README.rst`. ([\#12627](#12627))
- Fix docs on how to run specific Complement tests using the `complement.sh` test runner. ([\#12664](#12664))

Deprecations and Removals
-------------------------

- Remove unstable identifiers from [MSC3069](matrix-org/matrix-spec-proposals#3069). ([\#12596](#12596))
- Remove the unspecified `m.login.jwt` login type and the unstable `uk.half-shot.msc2778.login.application_service` from
  [MSC2778](matrix-org/matrix-spec-proposals#2778). ([\#12597](#12597))
- Synapse now requires at least Python 3.7.1 (up from 3.7.0), for compatibility with the latest Twisted trunk. ([\#12613](#12613))

Internal Changes
----------------

- Use supervisord to supervise Postgres and Caddy in the Complement image to reduce restart time. ([\#12480](#12480))
- Immediately retry any requests that have backed off when a server comes back online. ([\#12500](#12500))
- Use `make_awaitable` instead of `defer.succeed` for return values of mocks in tests. ([\#12505](#12505))
- Consistently check if an object is a `frozendict`. ([\#12564](#12564))
- Protect module callbacks with read semantics against cancellation. ([\#12568](#12568))
- Improve comments and error messages around access tokens. ([\#12577](#12577))
- Improve docstrings for the receipts store. ([\#12581](#12581))
- Use constants for read-receipts in tests. ([\#12582](#12582))
- Log status code of cancelled requests as 499 and avoid logging stack traces for them. ([\#12587](#12587), [\#12663](#12663))
- Remove special-case for `twisted` logger from default log config. ([\#12589](#12589))
- Use `getClientAddress` instead of the deprecated `getClientIP`. ([\#12599](#12599))
- Add link to documentation in Grafana Dashboard. ([\#12602](#12602))
- Reduce log spam when running multiple event persisters. ([\#12610](#12610))
- Add extra debug logging to federation sender. ([\#12614](#12614))
- Prevent remote homeservers from requesting local user device names by default. ([\#12616](#12616))
- Add a consistency check on events which we read from the database. ([\#12620](#12620))
- Remove use of the `constantly` library and switch to enums for `EventRedactBehaviour`. Contributed by @andrewdoh. ([\#12624](#12624))
- Remove unused code related to receipts. ([\#12632](#12632))
- Minor improvements to the scripts for running Synapse in worker mode under Complement. ([\#12637](#12637))
- Move `pympler` back in to the `all` extras. ([\#12652](#12652))
- Fix spelling of `M_UNRECOGNIZED` in comments. ([\#12665](#12665))
- Release script: confirm the commit to be tagged before tagging. ([\#12556](#12556))
- Fix a typo in the announcement text generated by the Synapse release development script. ([\#12612](#12612))

- Fix scripts-dev to pass typechecking. ([\#12356](#12356))
- Add some type hints to datastore. ([\#12485](#12485))
- Remove unused `# type: ignore`s. ([\#12531](#12531))
- Allow unused `# type: ignore` comments in bleeding edge CI jobs. ([\#12576](#12576))
- Remove redundant lines of config from `mypy.ini`. ([\#12608](#12608))
- Update to mypy 0.950. ([\#12650](#12650))
- Use `Concatenate` to better annotate `_do_execute`. ([\#12666](#12666))
- Use `ParamSpec` to refine type hints. ([\#12667](#12667))
- Fix mypy against latest pillow stubs. ([\#12671](#12671))
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants