synapse icon indicating copy to clipboard operation
synapse copied to clipboard

Enable cancellation for `POST /_matrix/client/v3/keys/query`

Open squahtx opened this issue 2 years ago • 2 comments

POST /_matrix/client/v3/keys/query can take a long time.

When clients retry the request, the new request gets queued behind the previous one by E2eKeysHandler._query_devices_linearizer, so retrying a request that timed out only makes response times worse.

...
2022-05-26 14:34:57,053 - synapse.access.http.11104 - 450 - INFO - POST-2875183 - xxx.xxx.xxx.xxx - 11104 - {@xxxxxxxxx:matrix.org} Processed request: 447.546sec/-267.564sec (0.213sec, 0.015sec) (0.015sec/0.052sec/34) 0B 200! "POST /_matrix/client/v3/keys/query HTTP/1.1" "xxxxxxxxx" [0 dbevts]
2022-05-26 14:35:04,581 - synapse.access.http.11104 - 450 - INFO - POST-2875478 - xxx.xxx.xxx.xxx - 11104 - {@xxxxxxxxx:matrix.org} Processed request: 435.215sec/-255.214sec (0.224sec, 0.029sec) (0.023sec/0.064sec/40) 0B 200! "POST /_matrix/client/v3/keys/query HTTP/1.1" "xxxxxxxxx" [0 dbevts]
2022-05-26 14:35:04,591 - synapse.access.http.11104 - 450 - INFO - POST-2874965 - xxx.xxx.xxx.xxx - 11104 - {@xxxxxxxxx:matrix.org} Processed request: 467.875sec/-287.874sec (0.213sec, 0.012sec) (0.044sec/0.106sec/46) 0B 200! "POST /_matrix/client/v3/keys/query HTTP/1.1" "xxxxxxxxx" [0 dbevts]
2022-05-26 14:35:05,443 - synapse.access.http.11104 - 450 - INFO - POST-2875779 - xxx.xxx.xxx.xxx - 11104 - {@xxxxxxxxx:matrix.org} Processed request: 414.790sec/-234.788sec (0.207sec, 0.013sec) (0.017sec/0.062sec/35) 0B 200! "POST /_matrix/client/v3/keys/query HTTP/1.1" "xxxxxxxxx" [0 dbevts]
2022-05-26 14:35:12,246 - synapse.access.http.11104 - 450 - INFO - POST-2875953 - xxx.xxx.xxx.xxx - 11104 - {@xxxxxxxxx:matrix.org} Processed request: 409.941sec/-229.943sec (0.234sec, 0.016sec) (0.010sec/0.054sec/18) 0B 200! "POST /_matrix/client/v3/keys/query HTTP/1.1" "xxxxxxxxx" [0 dbevts]
2022-05-26 14:35:34,240 - synapse.access.http.11104 - 450 - INFO - POST-2875839 - xxx.xxx.xxx.xxx - 11104 - {@xxxxxxxxx:matrix.org} Processed request: 439.033sec/-259.028sec (0.253sec, 0.012sec) (0.017sec/0.042sec/35) 0B 200! "POST /_matrix/client/v3/keys/query HTTP/1.1" "xxxxxxxxx" [0 dbevts]
2022-05-26 14:35:42,721 - synapse.access.http.11104 - 450 - INFO - POST-2875818 - xxx.xxx.xxx.xxx - 11104 - {@xxxxxxxxx:matrix.org} Processed request: 448.897sec/-268.734sec (0.238sec, 0.015sec) (0.019sec/0.052sec/30) 0B 200! "POST /_matrix/client/v3/keys/query HTTP/1.1" "xxxxxxxxx" [0 dbevts]
2022-05-26 14:36:04,578 - synapse.access.http.11104 - 450 - INFO - POST-2876136 - xxx.xxx.xxx.xxx - 11104 - {@xxxxxxxxx:matrix.org} Processed request: 452.018sec/-272.030sec (0.187sec, 0.015sec) (0.013sec/0.046sec/26) 0B 200! "POST /_matrix/client/v3/keys/query HTTP/1.1" "xxxxxxxxx" [0 dbevts]
2022-05-26 14:36:04,957 - synapse.access.http.11104 - 450 - INFO - POST-2876300 - xxx.xxx.xxx.xxx - 11104 - {@xxxxxxxxx:matrix.org} Processed request: 442.008sec/-262.071sec (0.201sec, 0.012sec) (0.013sec/0.045sec/31) 0B 200! "POST /_matrix/client/v3/keys/query HTTP/1.1" "xxxxxxxxx" [0 dbevts]
2022-05-26 14:36:11,865 - synapse.access.http.11104 - 450 - INFO - POST-2877424 - xxx.xxx.xxx.xxx - 11104 - {@xxxxxxxxx:matrix.org} Processed request: 385.515sec/-205.517sec (0.182sec, 0.014sec) (0.108sec/0.087sec/26) 0B 200! "POST /_matrix/client/v3/keys/query HTTP/1.1" "xxxxxxxxx" [0 dbevts]
...

To prevent the linearizer queue from building up too much, we can enable cancellation for the endpoint.

  • [ ] Audit the call tree of the endpoint. There's a previous audit of /rooms/$room_id/members at https://github.com/matrix-org/synapse/issues/3528#issuecomment-1083481216, which may or may not have some overlap.
  • [ ] (Optional) Relax the validation on @cancellable and attach it to the methods you've audited
  • [ ] Add the @cancellable flag to the endpoint
  • [ ] Add a test (using the machinery of #12674)

squahtx avatar May 26 '22 17:05 squahtx

Hi, I'd like to work on this issue.

ritikBhandari avatar May 31 '22 06:05 ritikBhandari

Per #13518: this manifests in thousands of requests to /_synapse/replication/user_device_resync on the main process, which are handled by ReplicationUserDevicesResyncRestServlet.

richvdh avatar Aug 12 '22 14:08 richvdh

  • [x] Relax the validation on @cancellable #13662
  • [ ] Audit the call tree of the endpoint. Add the @cancellable flag to the endpoint (to be PR'd); Add a test — https://github.com/matrix-org/synapse/pull/13680

reivilibre avatar Aug 30 '22 15:08 reivilibre