Skip to content

Fix run_in_background not be awaited properly causing LoggingContext problems #18937

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 7 commits into from
Sep 22, 2025
Merged

Fix run_in_background not be awaited properly causing LoggingContext problems #18937

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
c582067
Manually fix logcontexts in test
MadLittleMods Sep 18, 2025
a355439
Revert "Manually fix logcontexts in test"
MadLittleMods Sep 18, 2025
589c518
Add a default log context for anything running with `get_success(...)`
MadLittleMods Sep 18, 2025
77f52e9
Revert "Add a default log context for anything running with `get_succ…
MadLittleMods Sep 18, 2025
fc5bded
No need for `run_in_background` or `LoggingContext` in `test_federation`
MadLittleMods Sep 18, 2025
29a657f
Add changelog
MadLittleMods Sep 18, 2025
8fcfe29
Merge branch 'develop' into madlittlemods/run_in_background_logcontex…
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/18937.misc
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
Fix `run_in_background` not be awaited properly in some tests causing `LoggingContext` problems.
36 changes: 14 additions & 22 deletions tests/handlers/test_federation.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -38,7 +38,6 @@
from synapse.events import EventBase, make_event_from_dict
from synapse.federation.federation_base import event_from_pdu_json
from synapse.federation.federation_client import SendJoinResult
from synapse.logging.context import LoggingContext, run_in_background
from synapse.rest import admin
from synapse.rest.client import login, room
from synapse.server import HomeServer
Expand Down Expand Up @@ -149,11 +148,9 @@ def test_rejected_message_event_state(self) -> None:
room_version,
)

with LoggingContext("send_rejected"):
Copy link
Contributor Author

@MadLittleMods MadLittleMods Sep 18, 2025 •
edited
Loading

Choose a reason for hiding this comment

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

I originally tried adapting things to keep these LoggingContext around but then realized there is no point in having these here in the tests.

The only reason I can see why this might have been added was to avoid these kind of warnings in _trial_temp/test.log:

Starting metrics collection 'xxx' from sentinel context: metrics will be lost

But it's expected that test things run outside of Synapse and by their nature should happen in the sentinel logcontext. And if we really don't want to see these kind of errors, we would need to refactor get_success(...) to look more like get_success(func, OTHER_SERVER, ev) where we call the function with some homeserver_test_case logcontext instead of passing in an awaitable.

Copy link
Contributor

@reivilibre reivilibre Sep 22, 2025

Choose a reason for hiding this comment

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

is it possible the name was added here for logging clarity, to be fair?

Copy link
Contributor Author

@MadLittleMods MadLittleMods Sep 22, 2025 •
edited
Loading

Choose a reason for hiding this comment

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

It's possible that was the original reason but with a more nailed down definition of sentinel logcontext and when it should be used, I don't think it makes sense.

And after working with logcontext a bunch, I've kinda come to the conclusion that the name doesn't matter much outside of a request. Or at-least doesn't matter much to what I'm trying to accomplish.

d = run_in_background(
self.hs.get_federation_event_handler().on_receive_pdu, OTHER_SERVER, ev
)
self.get_success(d)
self.get_success(
self.hs.get_federation_event_handler().on_receive_pdu(OTHER_SERVER, ev)
)

# that should have been rejected
e = self.get_success(self.store.get_event(ev.event_id, allow_rejected=True))
Expand Down Expand Up @@ -203,11 +200,9 @@ def test_rejected_state_event_state(self) -> None:
room_version,
)

with LoggingContext("send_rejected"):
d = run_in_background(
self.hs.get_federation_event_handler().on_receive_pdu, OTHER_SERVER, ev
)
self.get_success(d)
self.get_success(
self.hs.get_federation_event_handler().on_receive_pdu(OTHER_SERVER, ev)
)

# that should have been rejected
e = self.get_success(self.store.get_event(ev.event_id, allow_rejected=True))
Expand Down Expand Up @@ -323,15 +318,14 @@ def test_backfill_with_many_backward_extremities(self) -> None:

current_depth = 1
limit = 100
with LoggingContext("receive_pdu"):
# Make sure backfill still works
d = run_in_background(
self.hs.get_federation_handler().maybe_backfill,
# Make sure backfill still works
self.get_success(
self.hs.get_federation_handler().maybe_backfill(
room_id,
current_depth,
limit,
)
self.get_success(d)
)

def test_backfill_ignores_known_events(self) -> None:
"""
Expand Down Expand Up @@ -491,13 +485,11 @@ def _build_and_send_join_event(
# the auth code requires that a signature exists, but doesn't check that
# signature... go figure.
join_event.signatures[other_server] = {"x": "y"}
with LoggingContext("send_join"):
d = run_in_background(
self.hs.get_federation_event_handler().on_send_membership_event,
other_server,
join_event,
self.get_success(
self.hs.get_federation_event_handler().on_send_membership_event(
other_server, join_event
)
self.get_success(d)
)

# sanity-check: the room should show that the new user is a member
r = self.get_success(self.store.get_partial_current_state_ids(room_id))
Expand Down
Loading