From 9147a95edd20b19c3fa1f72d6609da447386544d Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Tue, 28 Oct 2025 14:41:42 -0500 Subject: [PATCH 1/5] Fix lost logonctext on `HomeServer.shutdown()` --- synapse/server.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/synapse/server.py b/synapse/server.py index 2c252ce86fd..4ab365d66c0 100644 --- a/synapse/server.py +++ b/synapse/server.py @@ -51,6 +51,7 @@ from twisted.web.iweb import IPolicyForHTTPS from twisted.web.resource import Resource +from synapse.logging.context import PreserveLoggingContext from synapse.api.auth import Auth from synapse.api.auth.internal import InternalAuth from synapse.api.auth.mas import MasDelegatedAuth @@ -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() From 62f72e9e0d2fe7efe3d44298e4942878c4bf8d70 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Tue, 28 Oct 2025 14:54:41 -0500 Subject: [PATCH 2/5] Better test for lost logcontext --- tests/app/test_homeserver_shutdown.py | 19 +++++++++++++++---- tests/unittest.py | 3 +++ 2 files changed, 18 insertions(+), 4 deletions(-) diff --git a/tests/app/test_homeserver_shutdown.py b/tests/app/test_homeserver_shutdown.py index d8119ba3102..b3cf2e4749c 100644 --- a/tests/app/test_homeserver_shutdown.py +++ b/tests/app/test_homeserver_shutdown.py @@ -22,8 +22,11 @@ import weakref from synapse.app.homeserver import SynapseHomeServer +from synapse.logging.context import LoggingContext from synapse.storage.background_updates import UpdaterStatus +from tests.unittest import TestCase, logcontext_clean + from tests.server import ( cleanup_test_reactor_system_event_triggers, get_clock, @@ -44,6 +47,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 +67,11 @@ 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()) + # 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): + # Cleanup the homeserver. + self.get_success(self.hs.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,11 @@ 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()) + # 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): + # Cleanup the homeserver. + self.get_success(self.hs.shutdown()) # Cleanup the internal reference in our test case del self.hs diff --git a/tests/unittest.py b/tests/unittest.py index 1007f404561..049a92caaaf 100644 --- a/tests/unittest.py +++ b/tests/unittest.py @@ -341,6 +341,9 @@ def logcontext_clean(target: TV) -> TV: """ def logcontext_error(msg: str) -> NoReturn: + # Log so we can still see it in the logs like normal + logger.warning(msg) + # But also fail the test raise AssertionError("logcontext error: %s" % (msg)) patcher = patch("synapse.logging.context.logcontext_error", new=logcontext_error) From 2fa1e999751185b10a1f6bde83285bfaf4b7fc19 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Tue, 28 Oct 2025 14:58:07 -0500 Subject: [PATCH 3/5] Fix flawed wait --- tests/app/test_homeserver_shutdown.py | 24 ++++++++++++++---------- 1 file changed, 14 insertions(+), 10 deletions(-) diff --git a/tests/app/test_homeserver_shutdown.py b/tests/app/test_homeserver_shutdown.py index b3cf2e4749c..5dd740d2c75 100644 --- a/tests/app/test_homeserver_shutdown.py +++ b/tests/app/test_homeserver_shutdown.py @@ -67,11 +67,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) - # 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): - # 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 @@ -149,11 +151,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) - # 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): - # 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 From 4d1d05c274d423331a7c1012cb1294683c151a93 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Tue, 28 Oct 2025 14:59:18 -0500 Subject: [PATCH 4/5] Add changelog --- changelog.d/19108.bugfix | 1 + 1 file changed, 1 insertion(+) create mode 100644 changelog.d/19108.bugfix 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()`. From ac11619554847c2df7f70b3f3e28c9a6d9fb2dc7 Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Tue, 28 Oct 2025 15:04:50 -0500 Subject: [PATCH 5/5] Fix lints --- synapse/server.py | 2 +- tests/app/test_homeserver_shutdown.py | 4 +--- 2 files changed, 2 insertions(+), 4 deletions(-) diff --git a/synapse/server.py b/synapse/server.py index 4ab365d66c0..766515c930e 100644 --- a/synapse/server.py +++ b/synapse/server.py @@ -51,7 +51,6 @@ from twisted.web.iweb import IPolicyForHTTPS from twisted.web.resource import Resource -from synapse.logging.context import PreserveLoggingContext from synapse.api.auth import Auth from synapse.api.auth.internal import InternalAuth from synapse.api.auth.mas import MasDelegatedAuth @@ -144,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, diff --git a/tests/app/test_homeserver_shutdown.py b/tests/app/test_homeserver_shutdown.py index 5dd740d2c75..f127e5571de 100644 --- a/tests/app/test_homeserver_shutdown.py +++ b/tests/app/test_homeserver_shutdown.py @@ -25,14 +25,12 @@ from synapse.logging.context import LoggingContext from synapse.storage.background_updates import UpdaterStatus -from tests.unittest import TestCase, logcontext_clean - 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):