Fix join being denied after being invited over federation

[MadLittleMods]

Fix join being denied after being invited over federation. This also happens for rejecting an invite. Basically, any out-of-band membership transition where we first get the membership as an outlier and then rely on federation filling us in to de-outlier it.

This PR mainly addresses automated test flakiness, bots/scripts, and options within Synapse like auto_accept_invites that are able to react quickly (before federation is able to push us events), but also helps in generic scenarios where federation is lagging.

I initially thought this might be a Synapse consistency issue (see issues labeled with Z-Read-After-Write) but it seems to be an event auth logic problem. Workers probably do increase the number of possible race condition scenarios that make this visible though (replication and cache invalidation lag).

Fix #15012
(probably fixes matrix-org/synapse#15012 (#15012))
Related to matrix-org/matrix-spec#2062

Problems:

1. We don't consider out-of-band membership (outliers) in our event_auth logic even though we expose them in /sync.
2. (This PR doesn't address this point) Perhaps we should consider authing events in the persistence queue as events already in the queue could allow subsequent events to be allowed (events come through many channels: federation transaction, remote invite, remote join, local send). But this doesn't save us in the case where the event is more delayed over federation.

What happened before?

I wrote some Complement test that stresses this exact scenario and reproduces the problem: matrix-org/complement#757

COMPLEMENT_ALWAYS_PRINT_SERVER_LOGS=1 COMPLEMENT_DIR=../complement ./scripts-dev/complement.sh -run TestSynapseConsistency

We have hs1 and hs2 running in monolith mode (no workers):

1. @charlie1:hs2 is invited and joins the room:
   1. hs1 invites @charlie1:hs2 to a room which we receive on hs2 as PUT /_matrix/federation/v1/invite/{roomId}/{eventId} (on_invite_request(...)) and the invite membership is persisted as an outlier. The room_memberships and local_current_membership database tables are also updated which means they are visible down /sync at this point.
   2. @charlie1:hs2 decides to join because it saw the invite down /sync. Because hs2 is not yet in the room, this happens as a remote join make_join/send_join which comes back with all of the auth events needed to auth successfully and now @charlie1:hs2 is successfully joined to the room.
2. @charlie2:hs2 is invited and and tries to join the room:
   1. hs1 invites @charlie2:hs2 to the room which we receive on hs2 as PUT /_matrix/federation/v1/invite/{roomId}/{eventId} (on_invite_request(...)) and the invite membership is persisted as an outlier. The room_memberships and local_current_membership database tables are also updated which means they are visible down /sync at this point.
   2. Because hs2 is already participating in the room, we also see the invite come over federation in a transaction and we start processing it (not done yet, see below)
   3. @charlie2:hs2 decides to join because it saw the invite down /sync. Because hs2, is already in the room, this happens as a local join but we deny the event because our event_auth logic thinks that we have no membership in the room ❌ (expected to be able to join because we saw the invite down /sync)
   4. We finally finish processing the @charlie2:hs2 invite event from and de-outlier it.
      • If this finished before we tried to join we would have been fine but this is the race condition that makes this situation visible.

Logs for hs2:

🗳️ on_invite_request: handling event <FrozenEventV3 event_id=$PRPCvdXdcqyjdUKP_NxGF2CcukmwOaoK0ZR1WiVOZVk, type=m.room.member, state_key=@user-2-charlie1:hs2, membership=invite, outlier=False>
🔦 _store_room_members_txn update room_memberships: <FrozenEventV3 event_id=$PRPCvdXdcqyjdUKP_NxGF2CcukmwOaoK0ZR1WiVOZVk, type=m.room.member, state_key=@user-2-charlie1:hs2, membership=invite, outlier=True>
🔦 _store_room_members_txn update local_current_membership: <FrozenEventV3 event_id=$PRPCvdXdcqyjdUKP_NxGF2CcukmwOaoK0ZR1WiVOZVk, type=m.room.member, state_key=@user-2-charlie1:hs2, membership=invite, outlier=True>
📨 Notifying about new event <FrozenEventV3 event_id=$PRPCvdXdcqyjdUKP_NxGF2CcukmwOaoK0ZR1WiVOZVk, type=m.room.member, state_key=@user-2-charlie1:hs2, membership=invite, outlier=True>
✅ on_invite_request: handled event <FrozenEventV3 event_id=$PRPCvdXdcqyjdUKP_NxGF2CcukmwOaoK0ZR1WiVOZVk, type=m.room.member, state_key=@user-2-charlie1:hs2, membership=invite, outlier=True>
🧲 do_invite_join for @user-2-charlie1:hs2 in !sfZVBdLUezpPWetrol:hs1
🔦 _store_room_members_txn update room_memberships: <FrozenEventV3 event_id=$bwv8LxFnqfpsw_rhR7OrTjtz09gaJ23MqstKOcs7ygA, type=m.room.member, state_key=@user-1-alice:hs1, membership=join, outlier=True>
🔦 _store_room_members_txn update room_memberships: <FrozenEventV3 event_id=$oju1ts3G3pz5O62IesrxX5is4LxAwU3WPr4xvid5ijI, type=m.room.member, state_key=@user-2-charlie1:hs2, membership=join, outlier=False>
📨 Notifying about new event <FrozenEventV3 event_id=$oju1ts3G3pz5O62IesrxX5is4LxAwU3WPr4xvid5ijI, type=m.room.member, state_key=@user-2-charlie1:hs2, membership=join, outlier=False>

...

🗳️ on_invite_request: handling event <FrozenEventV3 event_id=$O_54j7O--6xMsegY5EVZ9SA-mI4_iHJOIoRwYyeWIPY, type=m.room.member, state_key=@user-3-charlie2:hs2, membership=invite, outlier=False>
🔦 _store_room_members_txn update room_memberships: <FrozenEventV3 event_id=$O_54j7O--6xMsegY5EVZ9SA-mI4_iHJOIoRwYyeWIPY, type=m.room.member, state_key=@user-3-charlie2:hs2, membership=invite, outlier=True>
🔦 _store_room_members_txn update local_current_membership: <FrozenEventV3 event_id=$O_54j7O--6xMsegY5EVZ9SA-mI4_iHJOIoRwYyeWIPY, type=m.room.member, state_key=@user-3-charlie2:hs2, membership=invite, outlier=True>
📨 Notifying about new event <FrozenEventV3 event_id=$O_54j7O--6xMsegY5EVZ9SA-mI4_iHJOIoRwYyeWIPY, type=m.room.member, state_key=@user-3-charlie2:hs2, membership=invite, outlier=True>
✅ on_invite_request: handled event <FrozenEventV3 event_id=$O_54j7O--6xMsegY5EVZ9SA-mI4_iHJOIoRwYyeWIPY, type=m.room.member, state_key=@user-3-charlie2:hs2, membership=invite, outlier=True>
📬 handling received PDU in room !sfZVBdLUezpPWetrol:hs1: <FrozenEventV3 event_id=$O_54j7O--6xMsegY5EVZ9SA-mI4_iHJOIoRwYyeWIPY, type=m.room.member, state_key=@user-3-charlie2:hs2, membership=invite, outlier=False>
📮 handle_new_client_event: handling <FrozenEventV3 event_id=$WNVDTQrxy5tCdPQHMyHyIn7tE4NWqKsZ8Bn8R4WbBSA, type=m.room.member, state_key=@user-3-charlie2:hs2, membership=join, outlier=False>
❌ Denying new event <FrozenEventV3 event_id=$WNVDTQrxy5tCdPQHMyHyIn7tE4NWqKsZ8Bn8R4WbBSA, type=m.room.member, state_key=@user-3-charlie2:hs2, membership=join, outlier=False> because 403: You are not invited to this room.
synapse.http.server - 130 - INFO - POST-16 - <SynapseRequest at 0x7f460c91fbf0 method='POST' uri='/_matrix/client/v3/join/%21sfZVBdLUezpPWetrol:hs1?server_name=hs1' clientproto='HTTP/1.0' site='8080'> SynapseError: 403 - You are not invited to this room.
📨 Notifying about new event <FrozenEventV3 event_id=$O_54j7O--6xMsegY5EVZ9SA-mI4_iHJOIoRwYyeWIPY, type=m.room.member, state_key=@user-3-charlie2:hs2, membership=invite, outlier=False>
✅ handled received PDU in room !sfZVBdLUezpPWetrol:hs1: <FrozenEventV3 event_id=$O_54j7O--6xMsegY5EVZ9SA-mI4_iHJOIoRwYyeWIPY, type=m.room.member, state_key=@user-3-charlie2:hs2, membership=invite, outlier=False>

Dev notes

Other unrelated but semi-related races:

• Events sent immediately after joining can be incorrectly soft-failed #10066 (Events sent immediately after joining can be incorrectly soft-failed matrix-org/synapse#10066)
• processing send_join races with local users sending messages #17720
• Sync race with get rooms for user cache invalidation over replication #14154 (Sync race with get rooms for user cache invalidation over replication matrix-org/synapse#14154)
• Sync current token may be ahead of event stream cache position using workers #14158 (Sync current token may be ahead of event stream cache position using workers matrix-org/synapse#14158)

---

handle_new_client_event
_persist_events
persist_and_notify_client_events
	persist_events
	notifier.on_new_room_events(

_process_incoming_pdus_in_room_inner
on_receive_pdu
_process_received_pdu
_run_push_actions_and_persist_event
persist_events_and_notify
	_send_events
		ReplicationFederationSendEventsRestServlet._handle_request
		persist_events_and_notify
	persist_events
		enqueue
		_persist_event_batch
		_persist_events_and_state_updates
		_persist_events_txn
		_update_metadata_tables_txn
		_store_room_members_txn
	_notify_persisted_event
		_notifier.on_new_room_events(

on_invite_request
persist_events_and_notify

update_membership_locked
	_remote_join
		do_invite_join
		process_remote_join
		persist_events_and_notify
	_local_membership_update

_notifier.on_new_room_events(
notify_new_room_events
	_notify_pending_new_room_events
		on_new_event
	notify_replication

---

handle_new_client_event
check_auth_rules_from_context
check_state_dependent_auth_rules
_is_membership_change_allowed

Running tests

SYNAPSE_TEST_LOG_LEVEL=INFO poetry run trial tests.federation.test_federation_out_of_band_membership.OutOfBandMembershipTests

COMPLEMENT_DIR=../complement ./scripts-dev/complement.sh -run TestFederationRoomsInvite

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.
• Code style is correct
  (run the linters)

[anoadragon453]

Great work on all the testing here, and for discovering the root cause in the first place. I filed a spec issue off the back of it.

Some small comments below, but otherwise this looks good.

[anoadragon453]

"...they may need to act on that event type"?

One example is facilitating the Synapse Module API; where a module could be loaded on to any worker. A module may want to act on certain types of backfilled events arriving.

[anoadragon453]

Other than updating the comment regarding https://github.com/element-hq/synapse/pull/18075/files/872f717a6ab0a8e9ab598e1c1c853af88c39a11c#r1920895848, this PR now LGTM.

Thanks for all the hard work!

[MadLittleMods]

Thanks for the review @anoadragon453 🦢