Remove logcontext problems caused by awaiting raw deferLater(...) (#19058)

This is a normal
problem where we `await` a deferred without wrapping it in
`make_deferred_yieldable(...)`. But I've opted to replace the usage of
`deferLater` with something more standard for the Synapse codebase.

Part of https://github.com/element-hq/synapse/issues/18905

It's unclear why we're only now seeing these failures happen with the
changes from https://github.com/element-hq/synapse/pull/19057

Example failures seen in
https://github.com/element-hq/synapse/actions/runs/18477454390/job/52645183606?pr=19057

```
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.
```
This commit is contained in:
Eric Eastwood 2025-10-29 10:23:10 -05:00 committed by GitHub
parent 18232871d0
commit 0417296b9f
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
4 changed files with 10 additions and 7 deletions

1
changelog.d/19058.misc Normal file
View File

@ -0,0 +1 @@
Remove logcontext problems caused by awaiting raw `deferLater(...)`.

View File

@ -53,8 +53,8 @@ running_tasks_gauge = LaterGauge(
class TaskScheduler: class TaskScheduler:
""" """
This is a simple task scheduler designed for resumable tasks. Normally, 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 you'd use `run_in_background` to start a background task or `clock.call_later`
`deferLater` if you want to run it later. if you want to run it later.
The issue is that these tasks stop completely and won't resume if Synapse is The issue is that these tasks stop completely and won't resume if Synapse is
shut down for any reason. shut down for any reason.

View File

@ -27,7 +27,6 @@ from unittest.mock import AsyncMock, Mock
from parameterized import parameterized from parameterized import parameterized
from twisted.internet.task import deferLater
from twisted.internet.testing import MemoryReactor from twisted.internet.testing import MemoryReactor
import synapse.rest.admin import synapse.rest.admin
@ -1163,7 +1162,7 @@ class DeleteRoomV2TestCase(unittest.HomeserverTestCase):
# Mock PaginationHandler.purge_room to sleep for 100s, so we have time to do a second call # 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. # 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: 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] self.pagination_handler.purge_room = AsyncMock(side_effect=purge_room) # type: ignore[method-assign]

View File

@ -20,9 +20,10 @@
# #
from typing import Optional from typing import Optional
from twisted.internet.task import deferLater from twisted.internet.defer import Deferred
from twisted.internet.testing import MemoryReactor from twisted.internet.testing import MemoryReactor
from synapse.logging.context import make_deferred_yieldable
from synapse.server import HomeServer from synapse.server import HomeServer
from synapse.types import JsonMapping, ScheduledTask, TaskStatus from synapse.types import JsonMapping, ScheduledTask, TaskStatus
from synapse.util.clock import Clock from synapse.util.clock import Clock
@ -87,7 +88,7 @@ class TestTaskScheduler(HomeserverTestCase):
self, task: ScheduledTask self, task: ScheduledTask
) -> tuple[TaskStatus, Optional[JsonMapping], Optional[str]]: ) -> tuple[TaskStatus, Optional[JsonMapping], Optional[str]]:
# Sleep for a second # Sleep for a second
await deferLater(self.reactor, 1, lambda: None) await self.hs.get_clock().sleep(1)
return TaskStatus.COMPLETE, None, None return TaskStatus.COMPLETE, None, None
def test_schedule_lot_of_tasks(self) -> None: def test_schedule_lot_of_tasks(self) -> None:
@ -170,8 +171,10 @@ class TestTaskScheduler(HomeserverTestCase):
return TaskStatus.COMPLETE, {"success": True}, None return TaskStatus.COMPLETE, {"success": True}, None
else: else:
await self.task_scheduler.update_task(task.id, result={"in_progress": True}) 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 forever to simulate an aborted task because of a restart
await deferLater(self.reactor, 2**16, lambda: None) await make_deferred_yieldable(incomplete_d)
# This should never been called # This should never been called
return TaskStatus.ACTIVE, None, None return TaskStatus.ACTIVE, None, None