Skip to content

Fix run_as_background_process not be awaited properly causing LoggingContext problems #18938

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.

Sign up for GitHub

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

Merged
merged 5 commits into from
Sep 22, 2025
Merged

Fix run_as_background_process not be awaited properly causing LoggingContext problems #18938

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
1668023
Reproduce `sentinel` context
MadLittleMods Sep 18, 2025
1b931b1
Cleanup
MadLittleMods Sep 18, 2025
cfb3ee5
Fix lints
MadLittleMods Sep 18, 2025
1400935
Add changelog
MadLittleMods Sep 18, 2025
7641b4f
Merge branch 'develop' into madlittlemods/delayed-events-run-as-backg…
MadLittleMods Sep 18, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions changelog.d/18938.misc
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
Fix `run_as_background_process` not be awaited properly causing `LoggingContext` problems in experimental [MSC4140](https://github.com/matrix-org/matrix-spec-proposals/pull/4140): Delayed events implementation.
11 changes: 7 additions & 4 deletions synapse/handlers/delayed_events.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,9 +21,12 @@
from synapse.api.errors import ShadowBanError
from synapse.api.ratelimiting import Ratelimiter
from synapse.config.workers import MAIN_PROCESS_INSTANCE_NAME
from synapse.logging.context import make_deferred_yieldable
from synapse.logging.opentracing import set_tag
from synapse.metrics import SERVER_NAME_LABEL, event_processing_positions
from synapse.metrics.background_process_metrics import run_as_background_process
from synapse.metrics.background_process_metrics import (
run_as_background_process,
)
from synapse.replication.http.delayed_events import (
ReplicationAddedDelayedEventRestServlet,
)
Expand Down Expand Up @@ -328,7 +331,7 @@ async def cancel(self, requester: Requester, delay_id: str) -> None:
requester,
(requester.user.to_string(), requester.device_id),
)
await self._initialized_from_db
await make_deferred_yieldable(self._initialized_from_db)
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As described in the docstring for why we need to do this:

synapse/synapse/metrics/background_process_metrics.py

Lines 231 to 234 in 4367fb2

Because the returned Deferred does not follow the synapse logcontext rules, awaiting
the result of this function will result in the log context being cleared (bad). In
order to properly await the result of this function and maintain the current log
context, use `make_deferred_yieldable`.

(docstring updated in #18900)

If you're wondering what the problem looks like in practice, see 1668023


next_send_ts = await self._store.cancel_delayed_event(
delay_id=delay_id,
Expand All @@ -354,7 +357,7 @@ async def restart(self, requester: Requester, delay_id: str) -> None:
requester,
(requester.user.to_string(), requester.device_id),
)
await self._initialized_from_db
await make_deferred_yieldable(self._initialized_from_db)

next_send_ts = await self._store.restart_delayed_event(
delay_id=delay_id,
Expand All @@ -380,7 +383,7 @@ async def send(self, requester: Requester, delay_id: str) -> None:
# Use standard request limiter for sending delayed events on-demand,
# as an on-demand send is similar to sending a regular event.
await self._request_ratelimiter.ratelimit(requester)
await self._initialized_from_db
await make_deferred_yieldable(self._initialized_from_db)

event, next_send_ts = await self._store.process_target_delayed_event(
delay_id=delay_id,
Expand Down
Loading