Presence worker gets stuck on 1.33.0rc1

[tulir]

Description

A line like this is spammed in the logs and the worker handling presence pins the CPU and gets stuck:

2021-04-28 12:05:20,199 - synapse.replication.tcp.resource - 187 - INFO - replication_notifier-103- Streaming: presence_federation -> 5

If presence is on the master process, then the master process gets stuck.

The issue goes away after disabling presence.

Steps to reproduce

• Have presence and workers enabled
• Update to 1.33.0rc1
• Optionally, move the presence stream to a worker

Version information

• Version: 1.33.0rc1
• Install method: Docker

[deepbluev7]

Happens to me too shortly after updating. I installed from source. After I restarted it twice I can't reproduce it anymore though?

[erikjohnston]

FTR disabling presence is a temporary fix, if you don't want to downgrade.

[deepbluev7]

Logs from the start of the spam:

2021-04-28 11:40:39,306 - synapse.access.http.9893 - 387 - INFO - POST-111 - 127.0.0.1 - 9893 - {None} Processed request: 0.005sec/-0.000sec (0.002sec, 0.000sec) (0.001sec/0.002sec/5) 4B 200 "POST /_synapse/replication/fed_send_edu/m.presence/nCmfebTyOS HTTP/1.1" "Synapse/1.33.0rc1" [0 dbevts]
2021-04-28 11:40:39,307 - synapse.replication.tcp.resource - 187 - INFO - replication_notifier-59 - Streaming: presence -> 110906303
2021-04-28 11:40:39,328 - synapse.replication.tcp.resource - 187 - INFO - replication_notifier-60 - Streaming: presence_federation -> 1
2021-04-28 11:40:39,329 - synapse.replication.tcp.resource - 187 - INFO - replication_notifier-61 - Streaming: presence_federation -> 2
2021-04-28 11:40:39,331 - synapse.replication.tcp.resource - 187 - INFO - replication_notifier-62 - Streaming: presence_federation -> 3
2021-04-28 11:40:39,334 - synapse.replication.tcp.resource - 187 - INFO - replication_notifier-63 - Streaming: presence_federation -> 4
2021-04-28 11:40:39,351 - synapse.replication.tcp.resource - 187 - INFO - replication_notifier-64 - Streaming: presence_federation -> 4
2021-04-28 11:40:39,366 - synapse.replication.tcp.resource - 187 - INFO - replication_notifier-64 - Streaming: presence_federation -> 4
2021-04-28 11:40:39,382 - synapse.replication.tcp.resource - 187 - INFO - replication_notifier-64 - Streaming: presence_federation -> 4

[erikjohnston]

Can someone try this with DEBUG logging on, at least for synapse.replication.tcp.resource please? I'm interested in log lines like: Getting stream: presence_federation: 2 -> 3

[erikjohnston]

#9900 should hopefully fix this.