Failing to join #matrix:matrix.org after being state reset out.

[Half-Shot]

I was reset out of the room (at least all my clients were still joined to the room, but the server believes I am not in the room). I am using Synapse 1.5.1. My logs barfed the following:

2019-11-08 09:49:51,712 - synapse.http.server - 109 - ERROR - POST-260645- Failed handle request via 'ReplicationRemoteJoinRestServlet': <SynapseRequest at 0x7f3fa4a82ac8 method='POST' uri='/_synapse/replication/remote_join/%21QtykxKocfZaZOUrTwp%3Amatrix.org/%40Half-Shot%3Ahalf-shot.uk/XNttnNDwzg' clientproto='HTTP/1.1' site=9593>
Traceback (most recent call last):
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
StopIteration: {'event': {'auth_events': [['$1568844654113223sIdXa:matrix.org', {'sha256': 'v3beNwaX8KJ1SfTa9X3TVc0M04f3QzbJt0k5XzwFuCE'}], ['$152873010877837iaEeS:matrix.org', {'sha256': 'FadaICEbPU11CFeC8NlvANHQdkviLqR7R3dgLQ7tElE'}], ['$152873067778016gOxgX:matrix.org', {'sha256': '6QyXfF6kZQqD69jwk86IW4PVTaTw8fN7rebtTPK8E2k'}]], 'prev_events': [['$15732062804729lEWEc:matrix.org', {'sha256': 'JQEou9q9bR6UVvMeLZPg9i2IvecOYKSmO2r3OkxdiUI'}]], 'type': 'm.room.member', 'room_id': '!QtykxKocfZaZOUrTwp:matrix.org', 'sender': '@Half-Shot:half-shot.uk', 'content': {'membership': 'join', 'avatar_url': 'mxc://half-shot.uk/6fc3fb176d5246f1e7cf7d89ad4248b8', 'displayname': 'Half-Shot'}, 'depth': 189281, 'prev_state': [], 'state_key': '@Half-Shot:half-shot.uk', 'event_id': '$157320659112doEas:half-shot.uk', 'origin': 'half-shot.uk', 'origin_server_ts': 1573206591669, 'hashes': {'sha256': 'YxfQW/xz3TmmEXrHKLIBVhsKZQiPjDlDBudH0nfsLHo'}, 'signatures': {'matrix.org': {'ed25519:auto': '+v+E3MFixl4VcHikHpKyvtTA0LKI+GKZfGBPLbE/LgNd9/HhD5whpRNpMjxJDf2ftLFHz5X47QX0F4f0PPsbBQ'}, 'half-shot.uk': {'ed25519:a_fBAF': 'YUa8E6jyJx3YRmRog+1nSRj4ysJbnG1cLpI1d4PofxOo2VnnYX5vgl9YGrQ9vVuRbCHTvcw/UcAmoZRCqWuDAw'}}, 'unsigned': {'replaces_state': '$15732062516zVTWQ:half-shot.uk', 'age_ts': 1573206591671}}, 'room_version': '1'}

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
StopIteration: {'event': {'auth_events': [['$1568844654113223sIdXa:matrix.org', {'sha256': 'v3beNwaX8KJ1SfTa9X3TVc0M04f3QzbJt0k5XzwFuCE'}], ['$152873010877837iaEeS:matrix.org', {'sha256': 'FadaICEbPU11CFeC8NlvANHQdkviLqR7R3dgLQ7tElE'}], ['$152873067778016gOxgX:matrix.org', {'sha256': '6QyXfF6kZQqD69jwk86IW4PVTaTw8fN7rebtTPK8E2k'}]], 'prev_events': [['$15732062804729lEWEc:matrix.org', {'sha256': 'JQEou9q9bR6UVvMeLZPg9i2IvecOYKSmO2r3OkxdiUI'}]], 'type': 'm.room.member', 'room_id': '!QtykxKocfZaZOUrTwp:matrix.org', 'sender': '@Half-Shot:half-shot.uk', 'content': {'membership': 'join', 'avatar_url': 'mxc://half-shot.uk/6fc3fb176d5246f1e7cf7d89ad4248b8', 'displayname': 'Half-Shot'}, 'depth': 189281, 'prev_state': [], 'state_key': '@Half-Shot:half-shot.uk', 'event_id': '$157320659112doEas:half-shot.uk', 'origin': 'half-shot.uk', 'origin_server_ts': 1573206591669, 'hashes': {'sha256': 'YxfQW/xz3TmmEXrHKLIBVhsKZQiPjDlDBudH0nfsLHo'}, 'signatures': {'matrix.org': {'ed25519:auto': '+v+E3MFixl4VcHikHpKyvtTA0LKI+GKZfGBPLbE/LgNd9/HhD5whpRNpMjxJDf2ftLFHz5X47QX0F4f0PPsbBQ'}, 'half-shot.uk': {'ed25519:a_fBAF': 'YUa8E6jyJx3YRmRog+1nSRj4ysJbnG1cLpI1d4PofxOo2VnnYX5vgl9YGrQ9vVuRbCHTvcw/UcAmoZRCqWuDAw'}}, 'unsigned': {'replaces_state': '$15732062516zVTWQ:half-shot.uk', 'age_ts': 1573206591671}}, 'room_version': '1'}

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
StopIteration: {'event': {'auth_events': [['$1568844654113223sIdXa:matrix.org', {'sha256': 'v3beNwaX8KJ1SfTa9X3TVc0M04f3QzbJt0k5XzwFuCE'}], ['$152873010877837iaEeS:matrix.org', {'sha256': 'FadaICEbPU11CFeC8NlvANHQdkviLqR7R3dgLQ7tElE'}], ['$152873067778016gOxgX:matrix.org', {'sha256': '6QyXfF6kZQqD69jwk86IW4PVTaTw8fN7rebtTPK8E2k'}]], 'prev_events': [['$15732062804729lEWEc:matrix.org', {'sha256': 'JQEou9q9bR6UVvMeLZPg9i2IvecOYKSmO2r3OkxdiUI'}]], 'type': 'm.room.member', 'room_id': '!QtykxKocfZaZOUrTwp:matrix.org', 'sender': '@Half-Shot:half-shot.uk', 'content': {'membership': 'join', 'avatar_url': 'mxc://half-shot.uk/6fc3fb176d5246f1e7cf7d89ad4248b8', 'displayname': 'Half-Shot'}, 'depth': 189281, 'prev_state': [], 'state_key': '@Half-Shot:half-shot.uk', 'event_id': '$157320659112doEas:half-shot.uk', 'origin': 'half-shot.uk', 'origin_server_ts': 1573206591669, 'hashes': {'sha256': 'YxfQW/xz3TmmEXrHKLIBVhsKZQiPjDlDBudH0nfsLHo'}, 'signatures': {'matrix.org': {'ed25519:auto': '+v+E3MFixl4VcHikHpKyvtTA0LKI+GKZfGBPLbE/LgNd9/HhD5whpRNpMjxJDf2ftLFHz5X47QX0F4f0PPsbBQ'}, 'half-shot.uk': {'ed25519:a_fBAF': 'YUa8E6jyJx3YRmRog+1nSRj4ysJbnG1cLpI1d4PofxOo2VnnYX5vgl9YGrQ9vVuRbCHTvcw/UcAmoZRCqWuDAw'}}, 'unsigned': {'replaces_state': '$15732062516zVTWQ:half-shot.uk', 'age_ts': 1573206591671}}, 'room_version': '1'}

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
StopIteration: ('matrix.org', <FrozenEvent event_id='$157320659112doEas:half-shot.uk', type='m.room.member', state_key='@Half-Shot:half-shot.uk'>, 1)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
StopIteration: ('matrix.org', <FrozenEvent event_id='$157320659112doEas:half-shot.uk', type='m.room.member', state_key='@Half-Shot:half-shot.uk'>, 1)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
StopIteration: ('matrix.org', <FrozenEvent event_id='$157320659112doEas:half-shot.uk', type='m.room.member', state_key='@Half-Shot:half-shot.uk'>, 1)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/lib/python3.7/site-packages/synapse/http/server.py", line 77, in wrapped_request_handler
    await h(self, request)
  File "/opt/synapse/lib/python3.7/site-packages/synapse/http/server.py", line 326, in _async_render
    callback_return = await callback_return
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/opt/synapse/lib/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/opt/synapse/lib/python3.7/site-packages/synapse/replication/http/membership.py", line 83, in _handle_request
    remote_room_hosts, room_id, user_id, event_content
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/opt/synapse/lib/python3.7/site-packages/synapse/handlers/federation.py", line 1128, in do_invite_join
    assert room_id not in self.room_queues
AssertionError
2019-11-08 09:49:51,714 - synapse.access.http.9593 - 302 - INFO - POST-260645- 127.0.0.1 - 9593 - {@Half-Shot:half-shot.uk} Processed request: 0.126sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 55B 500 "POST /_synapse/replication/remote_join/%21QtykxKocfZaZOUrTwp%3Amatrix.org/%40Half-Shot%3Ahalf-shot.uk/XNttnNDwzg HTTP/1.1" "Synapse/1.5.1" [0 dbevts]

synapse/synapse/handlers/federation.py

Lines 1125 to 1128 in 9ffcf0f

	# This shouldn't happen, because the RoomMemberHandler has a
	# linearizer lock which only allows one operation per user per room
	# at a time - so this is just paranoia.
	assert room_id not in self.room_queues

According to the comments, this shoudln't happen. According to the logs, it did.

[richvdh]

dup #5705