Optimize how we calculate likely_domains during backfill

[MadLittleMods]

Optimize how we calculate likely_domains during backfill because I've seen this take 17s in production just to get_current_state which is used to get_domains_from_state (see case 2. Loading tons of events in the /messages investigation issue).

There are 3 ways we currently calculate hosts that are in the room:

1. get_current_state -> get_domains_from_state
   • Used in backfill to calculate likely_domains and /timestamp_to_event because it was cargo-culted from backfill
   • This one is being eliminated in favor of get_current_hosts_in_room in this PR 🕳
2. get_current_hosts_in_room
   • Used for other federation things like sending read receipts and typing indicators
3. get_hosts_in_room_at_events
   • Used when pushing out events over federation to other servers in the _process_event_queue_loop

Fix #13626

Part of #13356

Mentioned in internal doc

Query performance

Before

The query from get_current_state sucks just because we have to get all 80k events. And we see almost the exact same performance locally trying to get all of these events (16s vs 17s):

synapse=# SELECT type, state_key, event_id FROM current_state_events WHERE room_id = '!OGEhHVWSdvArJzumhm:matrix.org';
Time: 16035.612 ms (00:16.036)

synapse=# SELECT type, state_key, event_id FROM current_state_events WHERE room_id = '!OGEhHVWSdvArJzumhm:matrix.org';
Time: 4243.237 ms (00:04.243)

But what about get_current_hosts_in_room: When there is 8M rows in the current_state_events table, the previous query in get_current_hosts_in_room took 13s from complete freshness (when the events were first added). But takes 930ms after a Postgres restart or 390ms if running back to back to back.

$ psql synapse
synapse=# \timing on
synapse=# SELECT COUNT(DISTINCT substring(state_key FROM '@[^:]*:(.*)$'))
FROM current_state_events
WHERE
    type = 'm.room.member'
    AND membership = 'join'
    AND room_id = '!OGEhHVWSdvArJzumhm:matrix.org';
 count
-------
  4130
(1 row)

Time: 13181.598 ms (00:13.182)

synapse=# SELECT COUNT(*) from current_state_events where room_id = '!OGEhHVWSdvArJzumhm:matrix.org';
 count
-------
 80814

synapse=# SELECT COUNT(*) from current_state_events;
  count
---------
 8162847

synapse=# SELECT pg_size_pretty( pg_total_relation_size('current_state_events') );
 pg_size_pretty
----------------
 4702 MB

After

I'm not sure how long it takes from complete freshness as I only really get that opportunity once (maybe restarting computer but that's cumbersome) and it's not really relevant to normal operating times. Maybe you get closer to the fresh times the more access variability there is so that Postgres caches aren't as exact. Update: The longest I've seen this run for is 6.4s and 4.5s after a computer restart.

After a Postgres restart, it takes 330ms and running back to back takes 260ms.

$ psql synapse
synapse=# \timing on
Timing is on.
synapse=# SELECT
    substring(c.state_key FROM '@[^:]*:(.*)$') as host
FROM current_state_events c
/* Get the depth of the event from the events table */
INNER JOIN events AS e USING (event_id)
WHERE
    c.type = 'm.room.member'
    AND c.membership = 'join'
    AND c.room_id = '!OGEhHVWSdvArJzumhm:matrix.org'
GROUP BY host
ORDER BY min(e.depth) ASC;
Time: 333.800 ms

Going further

To improve things further we could add a limit parameter to get_current_hosts_in_room. Realistically, we don't need 4k domains to choose from because there is no way we're going to query that many before we a) probably get an answer or b) we give up. Tracked by #13659

Another thing we can do is optimize the query to use a index skip scan:

• https://wiki.postgresql.org/wiki/Loose_indexscan
• Index Skip Scan, https://commitfest.postgresql.org/37/1741/
• https://www.timescale.com/blog/how-we-made-distinct-queries-up-to-8000x-faster-on-postgresql/
• (new link as of 2023-06-01): https://stackoverflow.com/questions/25536422/optimize-group-by-query-to-retrieve-latest-row-per-user/25536748

Dev notes

Created a utility script to dump the state events from a
GET https://matrix-client.matrix.org/_matrix/client/r0/rooms/!OGEhHVWSdvArJzumhm:matrix.org/state response for testing in your local dev database, https://github.com/MadLittleMods/matrix-synapse-state-dumper

It can also add in filler events in between in the database so it isn't such an easy sequential read for Postgres.

It's rough and just barely does what I needed to get some testing for this PR. Not very general.

---

brew services restart postgresql@13

$ psql synapse
> \timing on
> ...
> \q

---

Get count of rows when using group by:

SELECT COUNT(*) OVER () AS TotalRecords
FROM current_state_events c
/* Get the depth of the event from the events table */
INNER JOIN events AS e USING (event_id)
WHERE
    c.type = 'm.room.member'
    AND c.membership = 'join'
    AND c.room_id = '!OGEhHVWSdvArJzumhm:matrix.org'
GROUP BY substring(c.state_key FROM '@[^:]*:(.*)$')
ORDER BY min(e.depth);

---

BackfillBenchmarkTestCase test_benchmark_likely_domains

class BackfillBenchmarkTestCase(unittest.HomeserverTestCase):
    def prepare(self, reactor, clock, hs):
        self._storage_controllers = hs.get_storage_controllers()

    def test_benchmark_likely_domains(self):
        import time
        import logging

        logger = logging.getLogger(__name__)

        from synapse.handlers.federation import get_domains_from_state

        async def calculate_likely_domains():
            # Find other homeservers from the given state in the room
            curr_state = await self._storage_controllers.state.get_current_state(
                "!OGEhHVWSdvArJzumhm:matrix.org"
            )
            curr_domains = get_domains_from_state(curr_state)
            likely_domains = [
                domain for domain, depth in curr_domains if domain != self.server_name
            ]
            return likely_domains

        def time_calculate_likely_domains(test_prefix: str):
            benchmark_start_time = time.time()
            likely_domains = self.get_success(calculate_likely_domains())
            benchmark_end_time = time.time()
            logger.info(
                "Benchmark time (%s): %s",
                "{test_prefix: <13}".format(test_prefix=test_prefix),
                (benchmark_end_time - benchmark_start_time),
            )
            self.assertGreater(len(likely_domains), 4000)

        time_calculate_likely_domains("1")
        time_calculate_likely_domains("2")
        time_calculate_likely_domains("3")

Pull Request Checklist

• Pull request is based on the develop branch
• Pull request includes a changelog file. The entry should:
  • Be a short description of your change which makes sense to users. "Fixed a bug that prevented receiving messages from other servers." instead of "Moved X method from EventStore to EventWorkerStore.".
  • Use markdown where necessary, mostly for code blocks.
  • End with either a period (.) or an exclamation mark (!).
  • Start with a capital letter.
  • Feel free to credit yourself, by adding a sentence "Contributed by @github_username." or "Contributed by [Your Name]." to the end of the entry.
• Pull request includes a sign off
• Code style is correct
  (run the linters)

[MadLittleMods]

Eliminating this option to get domains for a room in favor of get_current_hosts_in_room.

In a room like #matrixhq, getting all 80k state events in the room, then whittling it down in the app is not faster than a quick targeted database query or maybe even luckily hitting the cache.

[MadLittleMods]

Updating the query to order by depth to match what get_domains_from_state did before (drop-in replacement).

The heuristic of sorting by servers who have been there the longest is good because they're most likely to have anything we ask about.

[reivilibre]

Interesting optimisation!

Would be worth checking how much we're going to negatively impact callers that don't care about the depth ordering ­— introducing a join (not even with all the columns covered by an index) in a section of the code that says 'Avoiding a join is a Very Good Thing' makes me worry a bit :).

[reivilibre]

Is adding this join here going to bite us in the bum for callers that don't actually care about the depth ordering?

As an aside, adding an index on events(event_id, depth) could be considered to speed up this if it turns out to be a problem, but on the other hand we're not keen on adding more indices to the events tables because it's frequently written.

[MadLittleMods]

Time-wise, I think by the nature of the extra complexity, it will take more time but it's not something I optimized for here. If we don't like this trade-off, we could remove the cache-shortcut lookup in get_current_hosts_in_room around it (it's kinda doing the same thing anyway looking in current_state_events).

Is there another concern about the order itself?

[MadLittleMods]

fwiw, here are some first-run timings. Not sure how much the first one affects the second one 🤷. Doubling the time isn't very good though so I'm up for removing the cache-shortcut lookup (just poke me further). Or we just sort by oldest current_state_events rows (not necessarily depth order but might be pretty close in practice) and not worry about the slight difference it makes to backfill (this one maybe sounds more interesting to me).

$ psql synapse
synapse=# \timing on

synapse=# SELECT c.state_key FROM current_state_events as c
/* Get the depth of the event from the events table */
INNER JOIN events AS e USING (event_id)
WHERE c.type = 'm.room.member' AND c.room_id = '!OGEhHVWSdvArJzumhm:matrix.org' AND membership = 'join'
/* Sorted by lowest depth first */
ORDER BY e.depth ASC;

Time: 4374.227 ms (00:04.374)


synapse=# SELECT c.state_key FROM current_state_events as c
WHERE c.type = 'm.room.member' AND c.room_id = '!OGEhHVWSdvArJzumhm:matrix.org' AND membership = 'join';

Time: 1947.409 ms (00:01.947)

[reivilibre]

Only doubling isn't as bad as I was expecting, so maybe it's fine. Possibly worth checking a graph for how much time is spent on get_users_in_rooms and thinking if it would burn us if that time were doubled.

[MadLittleMods]

Only doubling isn't as bad as I was expecting, so maybe it's fine. Possibly worth checking a graph for how much time is spent on get_users_in_rooms and thinking if it would burn us if that time were doubled.

Do we have a graph for this? I don't see special metrics annotated in it but 👍 it would be good to look at if we had it. Depending on confidence, we can merge a PR to measure it.

---

I've looked at the usages and there are some areas where it doesn't feel great to increase the time (calculating if an appservice is interested in an event (this could probably be smarter though anyway to use the user namespace regex directly on the members of the room like we do to get the domains), calculating join_authorised_via_users_server in a /make_join (idk how important this is), newly joined rooms in /sync, presence). Overall seems kinda fine ⏩

I can create separate PRs to fix up the following areas first, then we can merge this after those places are changed.

There are a few areas where it feels like we shouldn't be using get_users_in_room and can just use a direct lookup for the single user:

• synapse/synapse/handlers/events.py

  Lines 176 to 177 in a25a370

  	users = await self.store.get_users_in_room(event.room_id)
  	is_peeking = user.to_string() not in users

• synapse/synapse/handlers/room.py

  Lines 1287 to 1288 in a25a370

  	users = await self.store.get_users_in_room(room_id)
  	is_peeking = user.to_string() not in users

• synapse/synapse/handlers/message.py

  Lines 764 to 765 in a25a370

  	user_ids = await self.store.get_users_in_room(room_id)
  	return self.config.servernotices.server_notices_mxid in user_ids

• synapse/synapse/handlers/room_member.py

  Lines 1623 to 1624 in a25a370

  	user_ids = await self.store.get_users_in_room(room_id)
  	return self._server_notices_mxid in user_ids

• synapse/synapse/server_notices/server_notices_manager.py

  Lines 114 to 115 in a25a370

  	user_ids = await self._store.get_users_in_room(room.room_id)
  	if len(user_ids) <= 2 and self.server_notices_mxid in user_ids:

There are a few places where we should use get_current_hosts_in_room instead:

• synapse/synapse/handlers/directory.py

  Lines 86 to 87 in a25a370

  	users = await self.store.get_users_in_room(room_id)
  	servers = {get_domain_from_id(u) for u in users}

• synapse/synapse/handlers/directory.py

  Lines 290 to 291 in a25a370

  	users = await self.store.get_users_in_room(room_id)
  	extra_servers = {get_domain_from_id(u) for u in users}

• synapse/synapse/handlers/presence.py

  Lines 2054 to 2055 in a25a370

  	user_ids = await store.get_users_in_room(room_id)
  	hosts = {get_domain_from_id(user_id) for user_id in user_ids}

• synapse/synapse/handlers/typing.py

  Lines 365 to 366 in a25a370

  	users = await self.store.get_users_in_room(room_id)
  	domains = {get_domain_from_id(u) for u in users}

• synapse/synapse/handlers/device.py

  Lines 697 to 698 in a25a370

  	joined_user_ids = await self.store.get_users_in_room(room_id)
  	hosts = {get_domain_from_id(u) for u in joined_user_ids}

[MadLittleMods]

Here is some follow-up. I think this PR was rolled out on matrix.org (or maybe just the RC was which wouldn't include this?)

The average looks about the same. It seems a bit more peakier on total txn time.

[MadLittleMods]

Another follow-up, this time I think the changes are actually deployed to matrix.org as indicated by that change in the UP graph at the top (and /versions shows a hash that includes it)

It looks like it does take significantly more time on average (~100ms vs ~10ms before) but we're doing the query a whole lot more less probably because we fixed up those mis-uses.

https://grafana.matrix.org/d/000000012/synapse?orgId=1&from=1662362659334&to=1662535459334&viewPanel=180

[MadLittleMods]

This probably has a bigger penalty for other usage patterns, see #13942

[MadLittleMods]

Probably fixed #13942 via #13958 (another get_users_in_room mis-use)

Fixed up another mis-use in #13960

And found another mis-use that's tracked by #13967. Since this involves more than just switching it out, I'm not going to tackle. Feel free to pick it up!

[MadLittleMods]

This ended up as two functions get_current_hosts_in_room and get_current_hosts_in_room_ordered so that we don't have to take the performance hit of the extra join in get_users_in_room, see #13972

[reivilibre]

Only doubling isn't as bad as I was expecting, so maybe it's fine. Possibly worth checking a graph for how much time is spent on get_users_in_rooms and thinking if it would burn us if that time were doubled.

[reivilibre]

LGTM — suppose it would be prudent to land this after fixing up the (mis-)usages that you identified

[MadLittleMods]

Thanks for the review @reivilibre 🦒