Fix join being denied after being invited over federation #18075

MadLittleMods · 2025-01-10T21:19:45Z

Fix join being denied after being invited over federation. This probably also happens for rejecting an invite or trying to accept/deny someones knock request. 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.

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).

Note

The fix hasn't been implemented yet (just an investigation)

Probably fixes matrix-org/synapse#15012 (#15012)

Problems:

We don't consider out-of-band membership (outliers) in our event_auth logic even though we expose them in /sync.
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 a Complement test that stresses this exact scenario and reproduces the problem: matrix-org/complement#754

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):

@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.
@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:

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

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)

Reproduction test for element-hq/synapse#18075

synapse/handlers/federation_event.py

MadLittleMods · 2025-01-10T23:59:51Z

synapse/event_auth.py

+            # You can only join the room if you are invited or are already in the room.
+            if not (caller_in_room or caller_invited):


I think this is equivalent to before but I found this easier to grok.

It's the same via De Morgan's theorem.

This reverts commit a32c1ba.

…nvite-join

This is just normal for how someone finds out about an invite over federation See #18075 (comment)

MadLittleMods · 2025-01-14T20:26:00Z

synapse/handlers/federation_event.py

-            # After persistence we always need to notify replication there may
-            # be new data.
-            self._notifier.notify_replication()


Removed as this already happens in _notify_persisted_event -> on_new_room_events -> notify_new_room_events -> notify_replication

I guess there is one difference that this happens for every event (backfilled or not) 🤔

(vs we only call _notify_persisted_event -> notify_replication for non-backfilled events)

I've restored this call for now but I've left a TODO to fill in the "why" we have to do this.

We never notify clients about backfilled events but it's important to let all the workers know about any new event (backfilled or not) because TODO

See #18075 (comment)

Doesn't work very well because we need a lot of interaction with another homeserver

MadLittleMods added 2 commits January 10, 2025 12:17

Add membership to event representation when logging

e4c3e7b

Debug logging

d31ff53

MadLittleMods added a commit to MadLittleMods/fork-complement that referenced this pull request Jan 10, 2025

Add reproduction of the situation for a Synapse consistency issue

f26f2c0

Reproduction test for element-hq/synapse#18075

MadLittleMods added a commit to MadLittleMods/fork-complement that referenced this pull request Jan 10, 2025

Add reproduction of the situation for a Synapse consistency issue

3e03473

Reproduction test for element-hq/synapse#18075

MadLittleMods mentioned this pull request Jan 10, 2025

Add reproduction of the situation for a Synapse consistency issue matrix-org/complement#754

Draft

1 task

MadLittleMods changed the title ~~Fix Synapse consistency issue with join being denied after being invited over federation~~ Fix join being denied after being invited over federation Jan 10, 2025

MadLittleMods added 2 commits January 10, 2025 17:07

A couple more debug logs

1d64beb

Pipe store access to check_state_dependent_auth_rules

a32c1ba

MadLittleMods commented Jan 10, 2025

View reviewed changes

synapse/handlers/federation_event.py Outdated Show resolved Hide resolved

MadLittleMods commented Jan 10, 2025

View reviewed changes

synapse/handlers/federation_event.py Outdated Show resolved Hide resolved

MadLittleMods commented Jan 10, 2025

View reviewed changes

MadLittleMods added A-Federated-Join A-Invite A-Federation A-Join T-Defect z-auth labels Jan 11, 2025

MadLittleMods mentioned this pull request Jan 13, 2025

processing send_join races with local users sending messages #17720

Open

MadLittleMods added the A-Testing label Jan 13, 2025

MadLittleMods added 7 commits January 13, 2025 18:06

Revert "Pipe store access to check_state_dependent_auth_rules"

9a35155

This reverts commit a32c1ba.

Add out-of-band membership to auth events when creating new events

825b249

Add changelog

0698dcf

Clean up fix

8c6b294

Merge branch 'develop' into madlittlemods/debug-synapse-consistency-i…

e4dad14

…nvite-join

It's fine to notify about out-of-band membership

7e60ec0

This is just normal for how someone finds out about an invite over federation See #18075 (comment)

Remove duplicated code

ad8ed0c

MadLittleMods commented Jan 14, 2025

View reviewed changes

MadLittleMods added 3 commits January 14, 2025 14:44

Restore notifier.notify_replication()

d0639e4

See #18075 (comment)

Log all handled events

7855892

Clean up some pre-existing tests

b3bda0e

MadLittleMods added 2 commits January 14, 2025 18:36

Try adding out of band federation trial tests

0d01cda

Doesn't work very well because we need a lot of interaction with another homeserver

User1 can join remote room

83237f7

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix join being denied after being invited over federation #18075

Fix join being denied after being invited over federation #18075

MadLittleMods commented Jan 10, 2025 •

edited

Loading

MadLittleMods Jan 10, 2025

clokep Jan 11, 2025

MadLittleMods Jan 14, 2025

MadLittleMods Jan 14, 2025

MadLittleMods Jan 14, 2025

		# You can only join the room if you are invited or are already in the room.
		if not (caller_in_room or caller_invited):

Fix join being denied after being invited over federation #18075

Are you sure you want to change the base?

Fix join being denied after being invited over federation #18075

Conversation

MadLittleMods commented Jan 10, 2025 • edited Loading

What happened before?

Dev notes

Pull Request Checklist

MadLittleMods Jan 10, 2025

Choose a reason for hiding this comment

clokep Jan 11, 2025

Choose a reason for hiding this comment

MadLittleMods Jan 14, 2025

Choose a reason for hiding this comment

MadLittleMods Jan 14, 2025

Choose a reason for hiding this comment

MadLittleMods Jan 14, 2025

Choose a reason for hiding this comment

MadLittleMods commented Jan 10, 2025 •

edited

Loading