High CPU and DB usage upon start on Synapse v1.138.0

[anoadragon453]

Upon upgrading the element.io homeserver, we found high CPU, memory and DB pressure.

We were seeing many calls to the _fetch_event_list and cancel_delayed_state_events database queries, and the *getEvent* cache growing quickly, ballooning memory.

My theory is that #18858 is the cause. The fix allows the surrounding for loop to iterate (whereas before it would exit early with an Exception). get_event calls _fetch_event_list, and we are tight-looping over fetching a single state event at a time. We then call cancel_delayed_state_events on each state event individually.

It would be more efficient to pull out a batch of (say 500) events at a time and cancel them all with a single query as well.

---

Since this loop operates on state deltas from self._store.get_delayed_events_stream_pos() to self._store.get_room_max_stream_ordering(), one can assume that the intensive operations will run for a bounded time and then settle. Though due to the earlier code aborting early, it's likely that the delayed_events_stream_pos is currently very far behind for most deployments.

Understandably, element.io found this too intensive and rolled Synapse back before it completed.

[anoadragon453]

This code needs to call get_event for each event purely to get the sender of each event (as this isn't stored on the current_state_deltas table).

A short-term fix would be to batch up the event fetches into one. A longer-term one would be adding a sender column to current_state_deltas such that the get_event call isn't necessary.

[anoadragon453]

From what I can see from element.io's database, there is only a single row in delayed_events. This means that calls to cancel_delayed_state_events should be very quick.

The delayed_events_stream_pos is about 7mil behind the latest event stream however, meaning we'd be calling get_event 7mil times (for a single delayed event that will likely never be cancelled). We should probably just bail out early and reset the delayed_events_stream_pos in the case of zero delayed events. And we can clear that one delayed event before updating the homeserver.

[anoadragon453]

This feature is controlled by the max_event_delay_duration config option, which defaults to null, meaning delayed events can't be sent.

However, the background job in question will run regardless of that configuration option. And the old code would process events regardless of any delayed events even being in the DB.

So homeservers can't just disable the feature to avoid this performance issue.

However, this only seems to affect homeservers who have had their delayed_events_stream_pos stuck for a while (well behind the max events stream position), and then unstuck by #18858. This was the case for element.io, but not the case for matrix.org.

I don't know how common that is really, but we're hoping to gather some data from EMS in order to find out.

[anoadragon453]

EMS confirmed internally that homeservers other than element.io had their CPU pinned upon upgrading to v1.138.0.