Skip to content
1 change: 1 addition & 0 deletions changelog.d/19108.bugfix
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
Fix lost logcontext when using `HomeServer.shutdown()`.
4 changes: 3 additions & 1 deletion synapse/server.py
Original file line number Diff line number Diff line change
Expand Up @@ -143,6 +143,7 @@
SimpleHttpClient,
)
from synapse.http.matrixfederationclient import MatrixFederationHttpClient
from synapse.logging.context import PreserveLoggingContext
from synapse.media.media_repository import MediaRepository
from synapse.metrics import (
all_later_gauges_to_clean_up_on_shutdown,
Expand Down Expand Up @@ -507,7 +508,8 @@ async def shutdown(self) -> None:

for background_process in list(self._background_processes):
try:
background_process.cancel()
with PreserveLoggingContext():
background_process.cancel()
Comment on lines +511 to +512
Copy link
Contributor Author

Choose a reason for hiding this comment

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

This is the main fix!

See the Deferred callbacks section of our logcontext docs for more info (specifically using solution 2).

Heads-up, I wrote the docs too so it's my assumptions/understanding all the way down. Apply your own scrutiny.

except Exception:
pass
self._background_processes.clear()
Expand Down
23 changes: 18 additions & 5 deletions tests/app/test_homeserver_shutdown.py
Original file line number Diff line number Diff line change
Expand Up @@ -22,14 +22,15 @@
import weakref

from synapse.app.homeserver import SynapseHomeServer
from synapse.logging.context import LoggingContext
from synapse.storage.background_updates import UpdaterStatus

from tests.server import (
cleanup_test_reactor_system_event_triggers,
get_clock,
setup_test_homeserver,
)
from tests.unittest import HomeserverTestCase
from tests.unittest import HomeserverTestCase, logcontext_clean


class HomeserverCleanShutdownTestCase(HomeserverTestCase):
Expand All @@ -44,6 +45,7 @@ def setUp(self) -> None:
# closed in a timely manner during shutdown. Simulating this behaviour in a unit test
# won't be as good as a proper integration test in complement.

@logcontext_clean
def test_clean_homeserver_shutdown(self) -> None:
"""Ensure the `SynapseHomeServer` can be fully shutdown and garbage collected"""
self.reactor, self.clock = get_clock()
Expand All @@ -63,8 +65,13 @@ def test_clean_homeserver_shutdown(self) -> None:
# we use in tests doesn't handle this properly (see doc comment)
cleanup_test_reactor_system_event_triggers(self.reactor)

# Cleanup the homeserver.
self.get_success(self.hs.shutdown())
async def shutdown() -> None:
# Use a logcontext just to double-check that we don't mangle the logcontext
# during shutdown.
with LoggingContext(name="hs_shutdown", server_name=self.hs.hostname):
await self.hs.shutdown()

self.get_success(shutdown())

# Cleanup the internal reference in our test case
del self.hs
Expand Down Expand Up @@ -114,6 +121,7 @@ def test_clean_homeserver_shutdown(self) -> None:
# # to generate the result.
# objgraph.show_backrefs(synapse_hs, max_depth=10, too_many=10)

@logcontext_clean
def test_clean_homeserver_shutdown_mid_background_updates(self) -> None:
"""Ensure the `SynapseHomeServer` can be fully shutdown and garbage collected
before background updates have completed"""
Expand Down Expand Up @@ -141,8 +149,13 @@ def test_clean_homeserver_shutdown_mid_background_updates(self) -> None:
# Ensure the background updates are not complete.
self.assertNotEqual(store.db_pool.updates.get_status(), UpdaterStatus.COMPLETE)

# Cleanup the homeserver.
self.get_success(self.hs.shutdown())
async def shutdown() -> None:
# Use a logcontext just to double-check that we don't mangle the logcontext
# during shutdown.
with LoggingContext(name="hs_shutdown", server_name=self.hs.hostname):
await self.hs.shutdown()

self.get_success(shutdown())

# Cleanup the internal reference in our test case
del self.hs
Expand Down
Loading