-
Notifications
You must be signed in to change notification settings - Fork 564
Update wait_for_stream_token(...) patterns and fix sync fetching with unbounded token
#19644
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
2bdafec
dc3d205
6eda766
f61d795
03e5f47
2945a02
22d879c
4ba64fc
ff5402f
154b41d
edfcb53
46f3158
01a6898
5c7f96e
9c9a1d2
9cc939a
e7b9a91
be05994
83d6bdb
a2a9d42
1b3ac39
d9d5f54
a8e81d6
13d9907
6acc2a9
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1 @@ | ||
| Fix long-standing but niche bug with sync where it could attempt to fetch data with flawed invalid future tokens. |
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -414,6 +414,15 @@ async def _wait_for_sync_for_user( | |
| context.tag = sync_label | ||
|
|
||
| if since_token is not None: | ||
| # Work around a bug where older Synapse versions gave out tokens "from the | ||
| # future", i.e. that are ahead of the tokens persisted in the DB. This could | ||
| # also happen if a user is intentionally messing with the token so this also | ||
| # acts as sanitization/validation. | ||
| # | ||
| # If the token has positions ahead of our persisted positions in the | ||
| # database (invalid), then we simply use our max persisted position (recover | ||
| # gracefully); instead of waiting for a position that may never come around. | ||
| since_token = await self.event_sources.bound_future_token(since_token) | ||
|
Comment on lines
+417
to
+425
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This was done in order to fix sync waiting for a bounded token ( We moved the token bounding outside as it encourages people to update the token before waiting and use the updated token afterwards. Otherwise, it's too easy to carry on with the foot-guns like we had before. |
||
| # We need to make sure this worker has caught up with the token. If | ||
| # this returns false it means we timed out waiting, and we should | ||
| # just return an empty response. | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -51,6 +51,7 @@ | |
| create_requester, | ||
| ) | ||
| from synapse.util.clock import Clock | ||
| from synapse.util.duration import Duration | ||
|
|
||
| import tests.unittest | ||
| import tests.utils | ||
|
|
@@ -1058,13 +1059,22 @@ def test_wait_for_future_sync_token(self) -> None: | |
| ) | ||
|
|
||
| # This should block waiting for the presence stream to update | ||
| self.pump() | ||
|
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This pump doesn't actually do anything (doesn't even advance time at all since the default is But it's good practice for us to advance time and actually stress the sleep loop to make sure we're actually waiting so I've carried that forward with |
||
| # | ||
| # Advance time a little bit to make the | ||
| # `wait_for_stream_token(...)` sleep loop iterate. | ||
| self.reactor.advance(Duration(seconds=2).as_secs()) | ||
| # It should still not be done yet | ||
| self.assertFalse(sync_d.called) | ||
|
|
||
| # Marking the stream ID as persisted should unblock the request. | ||
| self.get_success(ctx_mgr.__aexit__(None, None, None)) | ||
|
|
||
| self.get_success(sync_d, by=1.0) | ||
|
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Instead of relying on |
||
| # Advance time to make another iteration of `wait_for_stream_token(...)` sleep | ||
| # loop so it sees that we're finally caught up now. | ||
| self.reactor.advance(Duration(seconds=1).as_secs()) | ||
|
|
||
| # Done waiting | ||
| self.get_success(sync_d) | ||
|
|
||
| @parameterized.expand( | ||
| [(key,) for key in StreamKeyType.__members__.values()], | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,136 @@ | ||
| # This file is licensed under the Affero General Public License (AGPL) version 3. | ||
| # | ||
| # Copyright (C) 2026 Element Creations Ltd | ||
| # | ||
| # This program is free software: you can redistribute it and/or modify | ||
| # it under the terms of the GNU Affero General Public License as | ||
| # published by the Free Software Foundation, either version 3 of the | ||
| # License, or (at your option) any later version. | ||
| # | ||
| # See the GNU Affero General Public License for more details: | ||
| # <https://www.gnu.org/licenses/agpl-3.0.html>. | ||
|
|
||
| import logging | ||
|
|
||
| from twisted.internet import defer | ||
| from twisted.internet.testing import MemoryReactor | ||
|
|
||
| from synapse.server import HomeServer | ||
| from synapse.types import MultiWriterStreamToken, StreamKeyType, StreamToken | ||
| from synapse.util.clock import Clock | ||
| from synapse.util.duration import Duration | ||
|
|
||
| import tests.unittest | ||
|
|
||
| logger = logging.getLogger(__name__) | ||
|
|
||
|
|
||
| class NotifierTestCase(tests.unittest.HomeserverTestCase): | ||
| def prepare(self, reactor: MemoryReactor, clock: Clock, hs: HomeServer) -> None: | ||
| self.store = self.hs.get_datastores().main | ||
| self.notifier = self.hs.get_notifier() | ||
|
|
||
| def test_wait_for_stream_token_with_caught_up_token(self) -> None: | ||
| """ | ||
| Test `wait_for_stream_token` when we receive a token that we are caught up to. | ||
| """ | ||
| # Create a token | ||
| receipt_id_gen = self.store.get_receipts_stream_id_gen() | ||
| receipt_token = MultiWriterStreamToken.from_generator(receipt_id_gen) | ||
| token = StreamToken.START.copy_and_replace(StreamKeyType.RECEIPT, receipt_token) | ||
|
|
||
| # Function under test | ||
| wait_d = defer.ensureDeferred(self.notifier.wait_for_stream_token(token)) | ||
|
|
||
| # Done waiting and caught-up (True) | ||
| wait_result = self.get_success(wait_d) | ||
| self.assertEqual(wait_result, True) | ||
|
|
||
| def test_wait_for_stream_token_with_future_sync_token(self) -> None: | ||
| """ | ||
| Test `wait_for_stream_token` when we receive a token that is ahead of our | ||
| current token, we'll wait until the stream position advances. | ||
|
|
||
| This can happen if replication streams start lagging, and the client's | ||
| previous sync request was serviced by a worker ahead of ours. | ||
| """ | ||
| # We simulate a lagging stream by getting a stream ID from the ID gen | ||
| # and then waiting to mark it as "persisted". | ||
| receipt_id_gen = self.store.get_receipts_stream_id_gen() | ||
| ctx_mgr = receipt_id_gen.get_next() | ||
| receipt_stream_id = self.get_success(ctx_mgr.__aenter__()) | ||
|
|
||
| # Create the new token based on the stream ID above. | ||
| current_receipt_token = MultiWriterStreamToken.from_generator(receipt_id_gen) | ||
| receipt_token = current_receipt_token.copy_and_advance( | ||
| MultiWriterStreamToken(stream=receipt_stream_id) | ||
| ) | ||
| token = StreamToken.START.copy_and_advance(StreamKeyType.RECEIPT, receipt_token) | ||
|
|
||
| # Function under test | ||
| wait_d = defer.ensureDeferred(self.notifier.wait_for_stream_token(token)) | ||
|
|
||
| # This should block waiting for the stream to update | ||
| # | ||
| # Advance time a little bit to make the | ||
| # `wait_for_stream_token(...)` sleep loop iterate. | ||
| self.reactor.advance(Duration(seconds=2).as_secs()) | ||
| # It should still not be done yet | ||
| self.assertFalse(wait_d.called) | ||
|
|
||
| # Marking the stream ID as persisted should unblock the request. | ||
| self.get_success(ctx_mgr.__aexit__(None, None, None)) | ||
|
|
||
| # Advance time to make another iteration of | ||
| # `wait_for_stream_token(...)` sleep loop so it sees that we're | ||
| # finally caught up now. | ||
| self.reactor.advance(Duration(seconds=1).as_secs()) | ||
|
|
||
| # Done waiting and caught-up (True) | ||
| wait_result = self.get_success(wait_d) | ||
| self.assertEqual(wait_result, True) | ||
|
|
||
| def test_wait_for_stream_token_with_future_sync_token_timeout( | ||
| self, | ||
| ) -> None: | ||
| """ | ||
| Test `wait_for_stream_token` when we receive a token that is ahead of our | ||
| current token, we'll wait until the stream position advances *until* we hit the | ||
| timeout. | ||
|
|
||
| This can happen if replication streams start lagging, and the client's | ||
| previous sync request was serviced by a worker ahead of ours. | ||
| """ | ||
| # We simulate a lagging stream by getting a stream ID from the ID gen | ||
| # and then waiting to mark it as "persisted". | ||
| receipt_id_gen = self.store.get_receipts_stream_id_gen() | ||
| ctx_mgr = receipt_id_gen.get_next() | ||
| receipt_stream_id = self.get_success(ctx_mgr.__aenter__()) | ||
|
|
||
| # Create the new token based on the stream ID above. | ||
| current_receipt_token = MultiWriterStreamToken.from_generator(receipt_id_gen) | ||
| receipt_token = current_receipt_token.copy_and_advance( | ||
| MultiWriterStreamToken(stream=receipt_stream_id) | ||
| ) | ||
| token = StreamToken.START.copy_and_advance(StreamKeyType.RECEIPT, receipt_token) | ||
|
|
||
| # Function under test | ||
| wait_d = defer.ensureDeferred(self.notifier.wait_for_stream_token(token)) | ||
| # Advance time a little bit to make the | ||
| # `wait_for_stream_token(...)` sleep loop record 0 as the `start` time. | ||
| self.reactor.advance(Duration(seconds=0).as_secs()) | ||
|
|
||
| # This should block waiting for the stream to update | ||
| # | ||
| # Advance time a little bit to make the | ||
| # `wait_for_stream_token(...)` sleep loop iterate. | ||
| self.reactor.advance(Duration(seconds=5).as_secs()) | ||
| # It should still not be done yet (not enough time to hit the timeout) | ||
| self.assertFalse(wait_d.called) | ||
| # Advance time past the 10 second timeout (5 + 6 = 11 seconds) to make the | ||
| # `wait_for_stream_token(...)` sleep loop give up. | ||
| self.reactor.advance(Duration(seconds=6).as_secs()) | ||
|
|
||
| # Make sure we gave up waiting and not caught-up (False) | ||
| wait_result = self.get_success(wait_d) | ||
| self.assertEqual(wait_result, False) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Same concept as the fix for
synapse/handlers/sync.pybelow. Jump down to that one first as it's simpler to understand.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I wonder if instead we should reset the connection, since this shouldn't happen and that is a clearer way of restoring things?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think that sounds good but should be tackled in another PR where it can get its own dedicated place to lay out the reasoning ⏩ - I've added a
FIXMEcomment to mark the plansIt also gets to the point behind why we tried to gracefully handle this situation for
/syncin the first place? I would have gone the route of blowing up the requests so clients can just restart their sync loop. Depends if we trust clients to restart on Matrix errors likeM_INVALID_PARAM🤷 which they probably should.In the case of Sliding Sync (which spec'ed
M_UNKNOWN_POS), sendingM_UNKNOWN_POS(resetting the connection) fits perfectly for this scenario to convey what we're running into 👍There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yes, we didn't do this on
/syncbecause we didn't have a mechanism to signal to clients that they should clear their cache and restart (and that is a much more invasive things to do in the v2 api)