High CPU (100%) and request starvation caused by worker_lock busy loop during E2E key upload

[Neboer]

Description

Hi, I'm writing here on behalf of team NerChat!, a Matrix server in mainland China. We've just encounter a bug in Synapse and it caused our server down for a few hours.

Under load, the Synapse homeserver becomes unresponsive with CPU usage reaching ~100%. During this state, the server is unable to handle new incoming requests.

Observed Behavior:

• CPU usage reaches ~100% (single core saturated)
• Server stops responding to new requests (stuck and hanging)
• No crash or exception is observed

A profiling session using py-spy shows that the majority of CPU time is spent in a busy loop inside the worker lock acquisition path, triggered by E2E key upload requests.

on_POST (synapse/rest/client/keys.py)
  → upload_keys_for_user (synapse/handlers/e2e_keys.py)
    → _upload_one_time_keys_for_user
      → worker_lock.__aenter__ (synapse/handlers/worker_lock.py)
        → _get_next_retry_interval   <-- major CPU hotspot

Steps to reproduce

We don't know, maybe the bug is related with user uploading keys .

Homeserver

chat.neboer.site

Synapse Version

1.149.1

Installation Method

Docker (matrixdotorg/synapse)

Database

Single PostgreSQL

Workers

Single process

Platform

ArchLinux with 6.18.9-arch1-2 kernel version, containerd nerdctl v2.2.1.
https://hub.docker.com/r/matrixdotorg/synapse

Configuration

No response

Relevant log output

maybe relevant.

synapse.api.errors.SynapseError: 400: One time key signed_curve25519:AAAAAAAAAEI already exists. Old key: {"key":"AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA","signatures":{"@example_user:chat.neboer.site":{"ed25519:EXIAPMVCRO":"BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB"}}}; new key: {'key': 'CCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCC', 'signatures': {'@example_user:chat.neboer.site': {'ed25519:EXIAPMVCRO': 'DDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDD'}}}
2026-03-20 08:02:30,800 - synapse.rest.client.keys - 255 - ERROR - POST-20452 - KEYS_UPLOAD_BEGIN req_id=None user_id=@example_user:chat.neboer.site device_id=EXIAPMVCRO ip=1.2.3.4 xff='1.2.3.4' ua='Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/145.0.0.0 Safari/537.36 Edg/145.0.0.0' one_time_keys=1 fallback_keys=0 has_device_keys=False body={'fallback_keys': {}, 'one_time_keys': {'signed_curve25519:AAAAAAAAAEI': {'key': 'EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE', 'signatures': {'@example_user:chat.neboer.site': {'ed25519:EXIAPMVCRO': 'FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF'}}}}}
2026-03-20 08:02:30,809 - synapse.rest.client.keys - 303 - ERROR - POST-20452 - KEYS_UPLOAD_FAIL req_id=None user_id=@example_user:chat.neboer.site device_id=EXIAPMVCRO elapsed_ms=9
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/synapse/rest/client/keys.py", line 296, in on_POST
    result = await self.e2e_keys_handler.upload_keys_for_user(
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    ...<3 lines>...
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/synapse/logging/opentracing.py", line 949, in _wrapper
    return await func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/synapse/handlers/e2e_keys.py", line 876, in upload_keys_for_user
    await self._upload_one_time_keys_for_user(
        user_id, device_id, time_now, one_time_keys
    )
  File "/usr/local/lib/python3.13/site-packages/synapse/handlers/e2e_keys.py", line 992, in _upload_one_time_keys_for_user
    raise SynapseError(
    ...<6 lines>...
    )
synapse.api.errors.SynapseError: 400: One time key signed_curve25519:AAAAAAAAAEI already exists. Old key: {"key":"AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA","signatures":{"@example_user:chat.neboer.site":{"ed25519:EXIAPMVCRO":"BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB"}}}; new key: {'key': 'EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE', 'signatures': {'@example_user:chat.neboer.site': {'ed25519:EXIAPMVCRO': 'FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF'}}}

Anything else that would be useful to know?

We've patched the files list above and fix the bug, our homeserver works fine now. Maybe these patched files can provide more information.

worker_lock.py
e2e_keys.py
keys.py

[erfnzdeh]

Confirming the same bug on Synapse 1.151.0 (verified still present in v1.152.0 and develop HEAD). Hit us as three separate outages on a ~5 000-user homeserver on Apr 27 / Apr 29 / Apr 30 2026 before we narrowed it down. Same _get_next_retry_interval busy loop, same /keys/upload trigger.

Captured by an accept-queue watchdog we wrote that py-spy-dumps then restarts wedged workers. Identical stack to the OP:

Thread 542571 (active+gil): "MainThread"
    _get_next_retry_interval  (synapse/handlers/worker_lock.py:279)
    __aenter__                (synapse/handlers/worker_lock.py:248)
    _upload_one_time_keys_for_user (synapse/handlers/e2e_keys.py:952)
    upload_keys_for_user      (synapse/handlers/e2e_keys.py:876)
    on_POST                   (synapse/rest/client/keys.py:265)
    …
    release_lock              (synapse/handlers/worker_lock.py:220)
    _wake_all_locks           (synapse/handlers/worker_lock.py:187)

The unbounded self._retry_interval = max(5, next * 2) doubles each iteration. After enough retries the integer crosses several visible thresholds, which we watched manifest in order:

N retries	_retry_interval size	Symptom
7	~10 min	the existing harmless warning fires (#18124)
~14 000	4 214-digit int	hits Python 3.11+ default int→str 4300-digit limit → ValueError → recursive log-formatter loop (this is #19315)
~400 000	124 KB int string	individual log lines literally 117 KB
millions	runaway big-int math	reactor never returns to epoll_wait; accept queue saturates at backlog (50); nginx 502s (this issue)

Trigger in our case was one user with E2E enabled across many devices spamming /keys/upload while the per-user worker_lock was held by a slow concurrent request from one of their other devices. nginx hashes by access-token-derived user, so the same user's requests always landed on the same client_reader instance — wedged that one specific worker, the other was untouched.

#19394 fixes this. We deployed an equivalent (narrower) cap locally; runaway gone, no regression. Would be great to see #19394 merged — it's been open since January.

Happy to share more context (full py-spy dump, watchdog script) if useful.

[MadLittleMods]

Fixed by #19394

See #19394 (comment) for an explanation