diff --git a/changelog.d/19108.bugfix b/changelog.d/19108.bugfix new file mode 100644 index 00000000000..a2afe19f410 --- /dev/null +++ b/changelog.d/19108.bugfix @@ -0,0 +1 @@ +Fix lost logcontext when using `HomeServer.shutdown()`. diff --git a/synapse/server.py b/synapse/server.py index 2c252ce86fd..766515c930e 100644 --- a/synapse/server.py +++ b/synapse/server.py @@ -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, @@ -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() except Exception: pass self._background_processes.clear() diff --git a/tests/app/test_homeserver_shutdown.py b/tests/app/test_homeserver_shutdown.py index d8119ba3102..f127e5571de 100644 --- a/tests/app/test_homeserver_shutdown.py +++ b/tests/app/test_homeserver_shutdown.py @@ -22,6 +22,7 @@ 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 ( @@ -29,7 +30,7 @@ get_clock, setup_test_homeserver, ) -from tests.unittest import HomeserverTestCase +from tests.unittest import HomeserverTestCase, logcontext_clean class HomeserverCleanShutdownTestCase(HomeserverTestCase): @@ -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() @@ -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 @@ -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""" @@ -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