From f5710dea3dd6a69050dc1cfe990c479b5658952b Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Wed, 24 Jun 2026 19:57:50 -0500 Subject: [PATCH 1/8] Try `FakeChannel.await_result(...)` changes on their own Split off from https://github.com/element-hq/synapse/pull/19878 --- tests/server.py | 51 ++++++++++++++++++++++++++++++++++++++++++++++--- 1 file changed, 48 insertions(+), 3 deletions(-) diff --git a/tests/server.py b/tests/server.py index ce5eaad63da..52b7dba7491 100644 --- a/tests/server.py +++ b/tests/server.py @@ -101,6 +101,7 @@ from synapse.storage.prepare_database import prepare_database from synapse.types import ISynapseReactor, JsonDict from synapse.util.clock import Clock +from synapse.util.duration import Duration from synapse.util.json import json_encoder from tests.utils import ( @@ -301,15 +302,59 @@ def transport(self) -> "FakeChannel": def await_result(self, timeout_ms: int = 1000) -> None: """ Wait until the request is finished. + + Advances the Twisted reactor clock by 0.1s and suspending execution of the + Python thread (to allow other threads to do work) in a loop until we see a + result. We timeout when both the Twisted reactor clock has been advanced enough + AND we've waited the same amount of in real-time for the specified timeout + before giving up. + + The loop 1) allows `clock.call_later` scheduled callbacks to run if they are + scheduled to run now and 2) will also allow other threads to make progress. This + could be things spawned on the Twisted reactor threadpool or Tokio runtime + (async Rust code). """ - end_time = self._reactor.seconds() + timeout_ms / 1000.0 + timeout = Duration(milliseconds=timeout_ms) + start_time_seconds = self._reactor.seconds() + start_real_time_seconds = time.time() + + # TODO: Why? self._reactor.run() while not self.is_finished(): - if self._reactor.seconds() > end_time: + if ( + # Exceeded the Twisted reactor time timeout + start_time_seconds + timeout.as_secs() < self._reactor.seconds() + # And exceeded the real-time timeout + and start_real_time_seconds + timeout.as_secs() < time.time() + ): raise TimedOutException("Timed out waiting for request to finish.") - self._reactor.advance(0.1) + # Suspend execution of this thread to allow other threads to do work. This + # could be things spawned on the Twisted reactor threadpool or Tokio thread + # pool (async Rust code). + # + # Note: Since we're waiting real-time (`timeout` duration), the tests also + # pass with `time.sleep(0)` commented out because Python has a default + # thread switch interval (5ms for cpython) (see + # `sys.setswitchinterval(interval)`). We still want this here as we're able + # to preempt and cause the thread context swtich to happen faster. + time.sleep(0) + + # Advance the Twisted reactor and run any scheduled callbacks + # + # Don't advance the Twisted reactor clock further than the timeout duration + # as someone should increase the timeout if they expect things to take + # longer. + if start_time_seconds + timeout.as_secs() > self._reactor.seconds(): + self._reactor.advance(0.1) + else: + # But we want to still keep running whatever might be getting scheduled + # to run now. + # + # For example from other threads, they may have scheduled something on + # the reactor to run (like `reactor.callFromThread(...)`) + self._reactor.advance(0) def extract_cookies(self, cookies: MutableMapping[str, str]) -> None: """Process the contents of any Set-Cookie headers in the response From bb9e266454d39a0f63345f897924c7d22812ac79 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Wed, 24 Jun 2026 19:59:21 -0500 Subject: [PATCH 2/8] Add changelog --- changelog.d/19879.misc | 1 + 1 file changed, 1 insertion(+) create mode 100644 changelog.d/19879.misc diff --git a/changelog.d/19879.misc b/changelog.d/19879.misc new file mode 100644 index 00000000000..83760993ca1 --- /dev/null +++ b/changelog.d/19879.misc @@ -0,0 +1 @@ +Stub. From 0fb37223cf8323bc9fde2ca148329a65aba74236 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Wed, 24 Jun 2026 21:13:23 -0500 Subject: [PATCH 3/8] Fix infinite loop getting the tests stuck in CI --- tests/server.py | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/tests/server.py b/tests/server.py index 52b7dba7491..91d38bc3923 100644 --- a/tests/server.py +++ b/tests/server.py @@ -324,9 +324,13 @@ def await_result(self, timeout_ms: int = 1000) -> None: while not self.is_finished(): if ( # Exceeded the Twisted reactor time timeout - start_time_seconds + timeout.as_secs() < self._reactor.seconds() + # + # We use `>=` for the reactor time condition as it's possible we advance + # exactly the `timeout` amount and we don't want to get stuck in an + # infinite loop + self._reactor.seconds() >= start_time_seconds + timeout.as_secs() # And exceeded the real-time timeout - and start_real_time_seconds + timeout.as_secs() < time.time() + and time.time() > start_real_time_seconds + timeout.as_secs() ): raise TimedOutException("Timed out waiting for request to finish.") @@ -346,7 +350,7 @@ def await_result(self, timeout_ms: int = 1000) -> None: # Don't advance the Twisted reactor clock further than the timeout duration # as someone should increase the timeout if they expect things to take # longer. - if start_time_seconds + timeout.as_secs() > self._reactor.seconds(): + if self._reactor.seconds() < start_time_seconds + timeout.as_secs(): self._reactor.advance(0.1) else: # But we want to still keep running whatever might be getting scheduled From c10f8cb3b3605b2d9f9e6e6538a7e444ee2ce290 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Thu, 25 Jun 2026 10:24:38 -0500 Subject: [PATCH 4/8] Fix typo --- tests/server.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/server.py b/tests/server.py index 91d38bc3923..dcaa58bfc4a 100644 --- a/tests/server.py +++ b/tests/server.py @@ -306,7 +306,7 @@ def await_result(self, timeout_ms: int = 1000) -> None: Advances the Twisted reactor clock by 0.1s and suspending execution of the Python thread (to allow other threads to do work) in a loop until we see a result. We timeout when both the Twisted reactor clock has been advanced enough - AND we've waited the same amount of in real-time for the specified timeout + AND we've waited the same amount of real-time for the specified timeout before giving up. The loop 1) allows `clock.call_later` scheduled callbacks to run if they are From 0281dd2b2cd6925117d45fe172f046a4f437ff11 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Thu, 25 Jun 2026 16:14:40 -0500 Subject: [PATCH 5/8] `time.sleep(0.001)` after a few loops Same thing we did in https://github.com/element-hq/synapse/pull/19871 --- tests/server.py | 14 +++++++++++++- 1 file changed, 13 insertions(+), 1 deletion(-) diff --git a/tests/server.py b/tests/server.py index dcaa58bfc4a..2d92d71bdfe 100644 --- a/tests/server.py +++ b/tests/server.py @@ -321,6 +321,7 @@ def await_result(self, timeout_ms: int = 1000) -> None: # TODO: Why? self._reactor.run() + loop_count = 0 while not self.is_finished(): if ( # Exceeded the Twisted reactor time timeout @@ -343,7 +344,16 @@ def await_result(self, timeout_ms: int = 1000) -> None: # thread switch interval (5ms for cpython) (see # `sys.setswitchinterval(interval)`). We still want this here as we're able # to preempt and cause the thread context swtich to happen faster. - time.sleep(0) + # + # After a few cycles, we use `time.sleep(0.001)` instead of `time.sleep(0)` + # to avoid tightlooping on the main thread (CPU 100%) because it's wasteful + # and may starve out other threads. 10 is arbitrary but many cases will have + # none or only a few round-trips so we can just try to go as fast as + # posssible. + if loop_count < 10: + time.sleep(0) + else: + time.sleep(0.001) # Advance the Twisted reactor and run any scheduled callbacks # @@ -360,6 +370,8 @@ def await_result(self, timeout_ms: int = 1000) -> None: # the reactor to run (like `reactor.callFromThread(...)`) self._reactor.advance(0) + loop_count += 1 + def extract_cookies(self, cookies: MutableMapping[str, str]) -> None: """Process the contents of any Set-Cookie headers in the response From 842fd5959410ed95d0b7a78f4f9db11126aa7c68 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Thu, 25 Jun 2026 16:15:09 -0500 Subject: [PATCH 6/8] Use 1s real-time instead of `timeout_ms` arg --- tests/server.py | 16 +++++++++++++--- 1 file changed, 13 insertions(+), 3 deletions(-) diff --git a/tests/server.py b/tests/server.py index 2d92d71bdfe..2069565a147 100644 --- a/tests/server.py +++ b/tests/server.py @@ -306,16 +306,26 @@ def await_result(self, timeout_ms: int = 1000) -> None: Advances the Twisted reactor clock by 0.1s and suspending execution of the Python thread (to allow other threads to do work) in a loop until we see a result. We timeout when both the Twisted reactor clock has been advanced enough - AND we've waited the same amount of real-time for the specified timeout - before giving up. + AND we've waited the 1s of real-time before giving up. The loop 1) allows `clock.call_later` scheduled callbacks to run if they are scheduled to run now and 2) will also allow other threads to make progress. This could be things spawned on the Twisted reactor threadpool or Tokio runtime (async Rust code). + + Args: + timeout_ms: The Twisted reactor time we wait until we raise a `TimedOutException` """ timeout = Duration(milliseconds=timeout_ms) start_time_seconds = self._reactor.seconds() + + # 1s is an arbitrary small number so we don't have to wait that long when + # something is stuck and because we assume any task on another thread will be + # fast enough. + # + # We don't use the same `timeout_ms` passed in because some tests specify 20s + # and we don't want to be waiting that long unnecessarily. + real_time_timeout = Duration(seconds=1) start_real_time_seconds = time.time() # TODO: Why? @@ -331,7 +341,7 @@ def await_result(self, timeout_ms: int = 1000) -> None: # infinite loop self._reactor.seconds() >= start_time_seconds + timeout.as_secs() # And exceeded the real-time timeout - and time.time() > start_real_time_seconds + timeout.as_secs() + and time.time() > start_real_time_seconds + real_time_timeout.as_secs() ): raise TimedOutException("Timed out waiting for request to finish.") From 3565a7fa53e0c3d84cdba4b6506e4d3cdd2d80c6 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Thu, 25 Jun 2026 16:18:44 -0500 Subject: [PATCH 7/8] Fix `tests.rest.client.sliding_sync.test_sliding_sync.SlidingSyncTestCase_new.test_wait_for_sync_token` --- tests/rest/client/sliding_sync/test_sliding_sync.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/tests/rest/client/sliding_sync/test_sliding_sync.py b/tests/rest/client/sliding_sync/test_sliding_sync.py index 2fd18f0e545..c43ed650174 100644 --- a/tests/rest/client/sliding_sync/test_sliding_sync.py +++ b/tests/rest/client/sliding_sync/test_sliding_sync.py @@ -566,7 +566,9 @@ def test_wait_for_sync_token(self) -> None: # timeout with self.assertRaises(TimedOutException): channel.await_result(timeout_ms=9900) - channel.await_result(timeout_ms=200) + # `notifier.wait_for_stream_token(from_token)` only checks every 500ms so we + # need to match that in order to make sure we hit the wake-up for sure. + channel.await_result(timeout_ms=500) self.assertEqual(channel.code, 200, channel.json_body) # We expect the next `pos` in the result to be the same as what we requested From 7c19a47448e56d8909a2515162855f7dba3eb1c1 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Thu, 25 Jun 2026 16:37:25 -0500 Subject: [PATCH 8/8] Update changelog --- changelog.d/19879.misc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/changelog.d/19879.misc b/changelog.d/19879.misc index 83760993ca1..be10ee05403 100644 --- a/changelog.d/19879.misc +++ b/changelog.d/19879.misc @@ -1 +1 @@ -Stub. +Update `HomeserverTestCase.get_success(...)` and friends to drive async Rust (Tokio runtime/thread pool).