Optimize filter_events_for_client for faster /messages - v2

[MadLittleMods]

Optimize filter_events_for_client -> _get_state_groups_from_groups for faster /messages. Seems like it will make it a magnitude faster (see comment below for actual matrix.org results). As discussed at #14494 (comment) (which was a v1 of this PR)

Fix #14108

Part of #13356 (comment)

SQL query optimization

More context on how we arrived at these queries is available at #14494 (comment)

Before

One query that takes ~80ms: https://explain.depesz.com/s/OtpN

Before raw query and EXPLAIN ANALYZE

EXPLAIN ANALYZE WITH RECURSIVE state(state_group) AS (
    VALUES(739988088::bigint)
    UNION ALL
    SELECT prev_state_group FROM state_group_edges e, state s
    WHERE s.state_group = e.state_group
)
SELECT DISTINCT ON (type, state_key)
    type, state_key, event_id
FROM state_groups_state
WHERE
    state_group IN (
        SELECT state_group FROM state
    )
    AND ((type = 'm.room.history_visibility' AND state_key = '') OR (type = 'm.room.member' AND state_key = '@madlittlemods:matrix.org'))
ORDER BY type, state_key, state_group DESC;
                                                                                          QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Unique  (cost=5274.51..5274.52 rows=1 width=87) (actual time=76.555..76.561 rows=2 loops=1)
   CTE state
     ->  Recursive Union  (cost=0.00..284.28 rows=101 width=8) (actual time=0.002..0.443 rows=59 loops=1)
           ->  Result  (cost=0.00..0.01 rows=1 width=8) (actual time=0.001..0.002 rows=1 loops=1)
           ->  Nested Loop  (cost=0.57..28.23 rows=10 width=8) (actual time=0.006..0.007 rows=1 loops=59)
                 ->  WorkTable Scan on state s  (cost=0.00..0.20 rows=10 width=8) (actual time=0.000..0.000 rows=1 loops=59)
                 ->  Index Only Scan using state_group_edges_unique_idx on state_group_edges e  (cost=0.57..2.79 rows=1 width=16) (actual time=0.006..0.006 rows=1 loops=59)
                       Index Cond: (state_group = s.state_group)
                       Heap Fetches: 58
   ->  Sort  (cost=4990.23..4990.23 rows=1 width=87) (actual time=76.554..76.555 rows=2 loops=1)
         Sort Key: state_groups_state.type, state_groups_state.state_key, state_groups_state.state_group DESC
         Sort Method: quicksort  Memory: 25kB
         ->  Nested Loop  (cost=3.11..4990.22 rows=1 width=87) (actual time=0.740..76.542 rows=2 loops=1)
               ->  HashAggregate  (cost=2.27..3.28 rows=101 width=8) (actual time=0.484..0.498 rows=59 loops=1)
                     Group Key: state.state_group
                     Batches: 1  Memory Usage: 24kB
                     ->  CTE Scan on state  (cost=0.00..2.02 rows=101 width=8) (actual time=0.004..0.459 rows=59 loops=1)
               ->  Index Scan using state_groups_state_type_idx on state_groups_state  (cost=0.84..49.37 rows=1 width=87) (actual time=0.009..1.289 rows=0 loops=59)
                     Index Cond: (state_group = state.state_group)
                     Filter: (((type = 'm.room.history_visibility'::text) AND (state_key = ''::text)) OR ((type = 'm.room.member'::text) AND (state_key = '@madlittlemods:matrix.org'::text)))
                     Rows Removed by Filter: 1495
 Planning Time: 3.309 ms
 Execution Time: 76.629 ms
(23 rows)

Time: 80.624 ms

After

One query that takes ~8ms: https://explain.depesz.com/s/Qi4A

After raw query and EXPLAIN ANALYZE

EXPLAIN ANALYZE WITH RECURSIVE sgs(state_group) AS (
    VALUES(739988088::bigint)
    UNION ALL
    SELECT prev_state_group FROM state_group_edges e, sgs s
    WHERE s.state_group = e.state_group
)
(
    SELECT DISTINCT ON (type, state_key)
        state_group, type, state_key, event_id
    FROM state_groups_state
    INNER JOIN sgs USING (state_group)
    WHERE (type = 'm.room.member' AND state_key = '@madlittlemods:matrix.org')
    ORDER BY type, state_key, state_group DESC
) UNION (
    SELECT DISTINCT ON (type, state_key)
        state_group, type, state_key, event_id
    FROM state_groups_state
    INNER JOIN sgs USING (state_group)
    WHERE (type = 'm.room.history_visibility' AND state_key = '')
    ORDER BY type, state_key, state_group DESC
);
                                                                                                QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Unique  (cost=1272.63..1272.66 rows=2 width=104) (actual time=1.710..1.719 rows=2 loops=1)
   CTE sgs
     ->  Recursive Union  (cost=0.00..284.28 rows=101 width=8) (actual time=0.003..0.623 rows=59 loops=1)
           ->  Result  (cost=0.00..0.01 rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=1)
           ->  Nested Loop  (cost=0.57..28.23 rows=10 width=8) (actual time=0.008..0.009 rows=1 loops=59)
                 ->  WorkTable Scan on sgs s  (cost=0.00..0.20 rows=10 width=8) (actual time=0.000..0.000 rows=1 loops=59)
                 ->  Index Only Scan using state_group_edges_unique_idx on state_group_edges e  (cost=0.57..2.79 rows=1 width=16) (actual time=0.007..0.008 rows=1 loops=59)
                       Index Cond: (state_group = s.state_group)
                       Heap Fetches: 58
   ->  Sort  (cost=988.35..988.36 rows=2 width=104) (actual time=1.709..1.712 rows=2 loops=1)
         Sort Key: state_groups_state.state_group, state_groups_state.type, state_groups_state.state_key, state_groups_state.event_id
         Sort Method: quicksort  Memory: 25kB
         ->  Append  (cost=494.15..988.34 rows=2 width=104) (actual time=1.253..1.702 rows=2 loops=1)
               ->  Unique  (cost=494.15..494.16 rows=1 width=87) (actual time=1.252..1.254 rows=1 loops=1)
                     ->  Sort  (cost=494.15..494.16 rows=1 width=87) (actual time=1.251..1.252 rows=1 loops=1)
                           Sort Key: state_groups_state.state_group DESC
                           Sort Method: quicksort  Memory: 25kB
                           ->  Nested Loop  (cost=0.84..494.14 rows=1 width=87) (actual time=1.232..1.245 rows=1 loops=1)
                                 ->  CTE Scan on sgs  (cost=0.00..2.02 rows=101 width=8) (actual time=0.006..0.656 rows=59 loops=1)
                                 ->  Index Scan using state_groups_state_type_idx on state_groups_state  (cost=0.84..4.86 rows=1 width=87) (actual time=0.009..0.009 rows=0 loops=59)
                                       Index Cond: ((state_group = sgs.state_group) AND (type = 'm.room.member'::text) AND (state_key = '@madlittlemods:matrix.org'::text))
               ->  Unique  (cost=494.15..494.16 rows=1 width=87) (actual time=0.444..0.445 rows=1 loops=1)
                     ->  Sort  (cost=494.15..494.16 rows=1 width=87) (actual time=0.443..0.444 rows=1 loops=1)
                           Sort Key: state_groups_state_1.state_group DESC
                           Sort Method: quicksort  Memory: 25kB
                           ->  Nested Loop  (cost=0.84..494.14 rows=1 width=87) (actual time=0.438..0.440 rows=1 loops=1)
                                 ->  CTE Scan on sgs sgs_1  (cost=0.00..2.02 rows=101 width=8) (actual time=0.001..0.014 rows=59 loops=1)
debug2: channel 0: window 997859 sent adjust 50717
                                 ->  Index Scan using state_groups_state_type_idx on state_groups_state state_groups_state_1  (cost=0.84..4.86 rows=1 width=87) (actual time=0.007..0.007 rows=0 loops=59)
                                       Index Cond: ((state_group = sgs_1.state_group) AND (type = 'm.room.history_visibility'::text) AND (state_key = ''::text))
 Planning Time: 4.756 ms
 Execution Time: 1.814 ms
(31 rows)

Time: 7.538 ms

Dev notes

Previous optimizations:

• Improve performance of _get_state_groups_from_groups_txn #7567
• A v1 attempt of this PR: Optimize filter_events_for_client for faster /messages - v1 #14494

---

Grabbing all of the state via get_state_for_events is the longest part of filter_events_for_client

• filter_events_for_client
  • get_state_for_events
    • get_state_group_for_events
      • _get_state_group_for_events
    • _get_state_for_groups
      • _get_state_for_groups_using_cache
      • _get_state_groups_from_groups 🐢
        • _get_state_groups_from_groups_txn (db._get_state_groups_from_groups)
    • get_events
      • ...

Of all the state we grab in filter_events_for_client, we only ever use EventTypes.RoomHistoryVisibility and EventTypes.Member from it

• filter_events_for_client
• _check_client_allowed_to_see_event
  • _check_filter_send_to_client
    • ->Uses no state
  • get_effective_room_visibility_from_state
    • -> EventTypes.RoomHistoryVisibility 🎈
  • _check_history_visibility
    • -> Uses visibility result from above
  • _check_membership
    • -> Uses visibility result from above
    • -> EventTypes.Member 🎈

---

Relevant database tables:

• state_groups
• state_groups_state
• state_group_edges
• event_to_state_groups

Docs:

• docs/development/room-dag-concepts.md
• docs/usage/administration/state_groups.md

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]

Thanks for the review @DMRobertson and @erikjohnston 🐡

[MadLittleMods]

For my benchmark /messages?dir=b&limit=500 request against Matrix HQ, we've reduced the filter_events_for_client part of the request from ~8s to ~1s.

Looking at the graphs, shows an even better picture where we have improved /messages timing across the board on matrix.org (not just in requests against large rooms or with high limits):

https://grafana.matrix.org/d/dYoRgTgVz/messages-timing?orgId=1&from=1668971225671&to=1669230425671

Improved /messages response time Apdex. We can see the obviously settling down in the blue line for large rooms (>1000 members)

But Apdex also improved across the board regardless of room size when we focus it specifically:

@erikjohnston also saw that we reduced the table block reads from disk for state_groups_state table in the database

https://grafana.matrix.org/d/000000009/postgres?orgId=1&refresh=1m&var-data_source=Prometheus&var-database=matrix&var-bucket_size=%24__auto_interval_bucket_size&var-instance=manticore.matrix.org%3A9113&from=1668971225671&to=1669230425671

There isn't a big obvious an obvious reduction jump in _get_state_groups_from_groups transaction time as I would expect 🤔 although squinting at it, seems to show improvement.