From a4cfb5556e45512e53718667b0788134139c4301 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Mon, 13 Oct 2025 16:21:52 -0500 Subject: [PATCH 1/7] Fix logcontext problems in `tests/util/test_task_scheduler.py` ``` builtins.AssertionError: Expected `looping_call` callback from the reactor to start with the sentinel logcontext but saw task-_resumable_task-0-IBzAmHUoepQfLnEA. In other words, another task shouldn't have leaked their logcontext to us. ``` --- tests/util/test_task_scheduler.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/tests/util/test_task_scheduler.py b/tests/util/test_task_scheduler.py index e97f0ed6111..f8f3c9dafda 100644 --- a/tests/util/test_task_scheduler.py +++ b/tests/util/test_task_scheduler.py @@ -23,6 +23,7 @@ from twisted.internet.task import deferLater from twisted.internet.testing import MemoryReactor +from synapse.logging.context import make_deferred_yieldable from synapse.server import HomeServer from synapse.types import JsonMapping, ScheduledTask, TaskStatus from synapse.util.clock import Clock @@ -87,7 +88,7 @@ async def _sleeping_task( self, task: ScheduledTask ) -> Tuple[TaskStatus, Optional[JsonMapping], Optional[str]]: # Sleep for a second - await deferLater(self.reactor, 1, lambda: None) + await make_deferred_yieldable(deferLater(self.reactor, 1, lambda: None)) return TaskStatus.COMPLETE, None, None def test_schedule_lot_of_tasks(self) -> None: @@ -171,7 +172,7 @@ async def _resumable_task( else: await self.task_scheduler.update_task(task.id, result={"in_progress": True}) # Await forever to simulate an aborted task because of a restart - await deferLater(self.reactor, 2**16, lambda: None) + await make_deferred_yieldable(deferLater(self.reactor, 2**16, lambda: None)) # This should never been called return TaskStatus.ACTIVE, None, None From e4a733fe19da88407e4369852e6066d89eafcb0a Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Mon, 13 Oct 2025 16:26:50 -0500 Subject: [PATCH 2/7] Better conversion --- tests/util/test_task_scheduler.py | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/tests/util/test_task_scheduler.py b/tests/util/test_task_scheduler.py index f8f3c9dafda..992e05d76c3 100644 --- a/tests/util/test_task_scheduler.py +++ b/tests/util/test_task_scheduler.py @@ -20,10 +20,8 @@ # from typing import List, Optional, Tuple -from twisted.internet.task import deferLater from twisted.internet.testing import MemoryReactor -from synapse.logging.context import make_deferred_yieldable from synapse.server import HomeServer from synapse.types import JsonMapping, ScheduledTask, TaskStatus from synapse.util.clock import Clock @@ -88,7 +86,7 @@ async def _sleeping_task( self, task: ScheduledTask ) -> Tuple[TaskStatus, Optional[JsonMapping], Optional[str]]: # Sleep for a second - await make_deferred_yieldable(deferLater(self.reactor, 1, lambda: None)) + await self.hs.get_clock().sleep(1) return TaskStatus.COMPLETE, None, None def test_schedule_lot_of_tasks(self) -> None: @@ -172,7 +170,7 @@ async def _resumable_task( else: await self.task_scheduler.update_task(task.id, result={"in_progress": True}) # Await forever to simulate an aborted task because of a restart - await make_deferred_yieldable(deferLater(self.reactor, 2**16, lambda: None)) + await self.hs.get_clock().sleep(2**16) # This should never been called return TaskStatus.ACTIVE, None, None From 37f8fc0da4f845f4da3d839f22aaa72618cadf82 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Mon, 13 Oct 2025 16:35:22 -0500 Subject: [PATCH 3/7] Remove `deferLater from other tests --- tests/rest/admin/test_room.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/rest/admin/test_room.py b/tests/rest/admin/test_room.py index 30b2de26e4a..4d90b83b069 100644 --- a/tests/rest/admin/test_room.py +++ b/tests/rest/admin/test_room.py @@ -861,7 +861,7 @@ def test_delete_same_room_twice(self) -> None: # Mock PaginationHandler.purge_room to sleep for 100s, so we have time to do a second call # before the purge is over. Note that it doesn't purge anymore, but we don't care. async def purge_room(room_id: str, force: bool) -> None: - await deferLater(self.hs.get_reactor(), 100, lambda: None) + await self.hs.get_clock().sleep(100) self.pagination_handler.purge_room = AsyncMock(side_effect=purge_room) # type: ignore[method-assign] From 08e66e34175c9edcd6d256daba443d81aa745fdd Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Mon, 13 Oct 2025 16:35:52 -0500 Subject: [PATCH 4/7] Remove mentions of `deferLater` --- synapse/util/task_scheduler.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/synapse/util/task_scheduler.py b/synapse/util/task_scheduler.py index 8dd6f12feb3..91174769cd3 100644 --- a/synapse/util/task_scheduler.py +++ b/synapse/util/task_scheduler.py @@ -53,8 +53,8 @@ class TaskScheduler: """ This is a simple task scheduler designed for resumable tasks. Normally, - you'd use `run_in_background` to start a background task or Twisted's - `deferLater` if you want to run it later. + you'd use `run_in_background` to start a background task or `clock.call_later` + if you want to run it later. The issue is that these tasks stop completely and won't resume if Synapse is shut down for any reason. From 1e1d092125f53244826a45c45884e67d06198b02 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Mon, 13 Oct 2025 16:33:15 -0500 Subject: [PATCH 5/7] Even better adaption `incomplete_d` --- tests/util/test_task_scheduler.py | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/tests/util/test_task_scheduler.py b/tests/util/test_task_scheduler.py index 992e05d76c3..bebe51a12ba 100644 --- a/tests/util/test_task_scheduler.py +++ b/tests/util/test_task_scheduler.py @@ -20,8 +20,10 @@ # from typing import List, Optional, Tuple +from twisted.internet.defer import Deferred from twisted.internet.testing import MemoryReactor +from synapse.logging.context import make_deferred_yieldable from synapse.server import HomeServer from synapse.types import JsonMapping, ScheduledTask, TaskStatus from synapse.util.clock import Clock @@ -169,8 +171,10 @@ async def _resumable_task( return TaskStatus.COMPLETE, {"success": True}, None else: await self.task_scheduler.update_task(task.id, result={"in_progress": True}) + # Create a deferred which we will never complete + incomplete_d: Deferred = Deferred() # Await forever to simulate an aborted task because of a restart - await self.hs.get_clock().sleep(2**16) + await make_deferred_yieldable(incomplete_d) # This should never been called return TaskStatus.ACTIVE, None, None From da7fb0cc4679dd34a4e0d9f6ec7f7639409b555f Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Mon, 13 Oct 2025 16:45:17 -0500 Subject: [PATCH 6/7] Add changelog --- changelog.d/19058.misc | 1 + 1 file changed, 1 insertion(+) create mode 100644 changelog.d/19058.misc diff --git a/changelog.d/19058.misc b/changelog.d/19058.misc new file mode 100644 index 00000000000..15bc4b39bd2 --- /dev/null +++ b/changelog.d/19058.misc @@ -0,0 +1 @@ +Remove logcontext problems caused by awaiting raw `deferLater(...)`. From 66f3b29f76e9020f49fd26691bc0f846207fed56 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Mon, 13 Oct 2025 16:48:52 -0500 Subject: [PATCH 7/7] Fix lints --- tests/rest/admin/test_room.py | 1 - 1 file changed, 1 deletion(-) diff --git a/tests/rest/admin/test_room.py b/tests/rest/admin/test_room.py index 4d90b83b069..2885b068883 100644 --- a/tests/rest/admin/test_room.py +++ b/tests/rest/admin/test_room.py @@ -27,7 +27,6 @@ from parameterized import parameterized -from twisted.internet.task import deferLater from twisted.internet.testing import MemoryReactor import synapse.rest.admin