Fix have_seen_event cache not being invalidated

[MadLittleMods]

Fix have_seen_event cache not being invalidated

Fix #13856
Fix #13865

Discovered while trying to make Synapse fast enough for this MSC2716 test for importing many batches. As an example, disabling the have_seen_event cache saves 10 seconds for each /messages request in that MSC2716 Complement test because we're not making as many federation requests for /state (speeding up have_seen_event itself is related to #13625)

But this will also make /messages faster in general so we can include it in the faster /messages milestone.

-- #13856

The problem

_invalidate_caches_for_event doesn't run in monolith mode which means we never even tried to clear the have_seen_event and other caches. And even in worker mode, it only runs on the workers, not the master (AFAICT).

Additionally there was bug with the key being wrong so _invalidate_caches_for_event never invalidates the have_seen_event cache even when it does run.

Because we were using the @cachedList wrong, it was putting items in the cache under keys like ((room_id, event_id),) with a set in a set (ex. (('!TnCIJPKzdQdUlIyXdQ:test', '$Iu0eqEBN7qcyF1S9B3oNB3I91v2o5YOgRNPwi_78s-k'),)) and we we're trying to invalidate with just (room_id, event_id) which did nothing.

Dev notes

Original fix first explored in these scratch changes: #13861

---

SYNAPSE_POSTGRES=1 SYNAPSE_TEST_LOG_LEVEL=INFO python -m twisted.trial tests.storage.databases.main.test_events_worker.HaveSeenEventsTestCase

SYNAPSE_POSTGRES=1 SYNAPSE_TEST_LOG_LEVEL=INFO python -m twisted.trial tests.storage.databases.main.test_events_worker.HaveSeenEventsTestCase.test_persisting_event_invalidates_cache

Persist events

persist_events or persist_event or update_current_state (not really)
self._event_persist_queue
_process_event_persist_queue_task
_persist_event_batch
_persist_events_and_state_updates
_persist_events_txn

Replication stuff

• docs/replication.md

EventsStreamEventRow(BaseEventsStreamRow)
EventsStreamRow

class ReplicationFederationSendEventsRestServlet(ReplicationEndpoint):

class ReplicationSendEventRestServlet(ReplicationEndpoint):

_process_position

on_position
on_rdata

process_replication_rows


get_replication_command_handler

send_federation_ack
send_command

stream_update
RdataCommand

ReplicationStreamer
add_replication_callback

on_new_room_event_args (on_new_room_event)
on_new_event
on_new_replication_data

Caches using tree=True

get_global_account_data_by_type_for_user
get_account_data_for_room
get_account_data_for_room_and_type
_get_cached_user_device
get_unread_event_push_actions_by_room_for_user
have_seen_event
_get_linearized_receipts_for_room
get_relations_for_event
get_aggregation_groups_for_event

Todo

• Future PR: Prefill have_seen_event cache after we persist an event
• Is there we can make the getter, setter and invalidate functions throw errors when you provide the wrong shape of key?

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]

It might be worth additionally adding a test where we try this in worker mode because even though _invalidate_caches_for_event was called via events over replication, the have_seen_event key problem here meant it still didn't work.

Although _invalidate_caches_for_event itself working is already covered by these tests.

Any good examples for a simple master, worker setup in a test?

[MadLittleMods]

This is the fix as described by @erikjohnston in #13865 (comment)

The rest of the changes in this file are adapting to this change.

[MadLittleMods]

Added a safety check so others don't run into the same pitfall and we can see this error obviously.

This also has a test to make sure the safety check works (see tests/util/caches/test_descriptors.py)

Example error: builtins.Exception: Number of args (1) does not match underlying cache_method_name=have_seen_event (2).

Full error

Traceback (most recent call last):
  File "/Users/eric/Documents/github/element/synapse/tests/unittest.py", line 539, in get_success
    deferred: Deferred[TV] = ensureDeferred(d)  # type: ignore[arg-type]
  File "/Users/eric/Documents/github/element/synapse/.venv/lib/python3.9/site-packages/twisted/internet/defer.py", line 1162, in ensureDeferred
    return Deferred.fromCoroutine(coro)
  File "/Users/eric/Documents/github/element/synapse/.venv/lib/python3.9/site-packages/twisted/internet/defer.py", line 1137, in fromCoroutine
    return _cancellableInlineCallbacks(coro)
  File "/Users/eric/Documents/github/element/synapse/.venv/lib/python3.9/site-packages/twisted/internet/defer.py", line 1856, in _cancellableInlineCallbacks
    _inlineCallbacks(None, gen, status, _copy_context())
--- <exception caught here> ---
  File "/Users/eric/Documents/github/element/synapse/.venv/lib/python3.9/site-packages/twisted/internet/defer.py", line 1696, in _inlineCallbacks
    result = context.run(gen.send, result)
  File "/Users/eric/Documents/github/element/synapse/synapse/logging/opentracing.py", line 889, in _wrapper
    return await func(*args, **kwargs)  # type: ignore[misc]
  File "/Users/eric/Documents/github/element/synapse/synapse/logging/opentracing.py", line 889, in _wrapper
    return await func(*args, **kwargs)  # type: ignore[misc]
  File "/Users/eric/Documents/github/element/synapse/synapse/storage/databases/main/events_worker.py", line 1478, in have_seen_events
    r = await self._have_seen_events_dict(
  File "/Users/eric/Documents/github/element/synapse/synapse/util/caches/descriptors.py", line 435, in __get__
    raise Exception(
builtins.Exception: Number of args (1) does not match underlying cache_method_name=have_seen_event (2).

---

There are other ways the args could mismatch like the type but this would have caught the problem encountered here with have_seen_event

[MadLittleMods]

Simplified this test logic by using the real thing.

And makes it easier to to create another event down the line in the new test with create_event(...) without needing to worry about incrementing the stream_ordering manually.

[erikjohnston]

Woop, thanks!

[MadLittleMods]

Thanks for the review @erikjohnston 🐚