From 25fa555395d1f80349a80d7c82ad8d5af8063edb Mon Sep 17 00:00:00 2001 From: Eric Eastwood Date: Wed, 24 Sep 2025 10:12:08 -0500 Subject: [PATCH] Fix `no active span when trying to log` tracing error on startup (#18959) Fix `no active span when trying to log` tracing error on startup. Example error: ```log synapse.logging.opentracing - 427 - ERROR - wake_destinations_needing_catchup-0 - There was no active span when trying to log. Did you forget to start one or did a context slip? Stack (most recent call last): File "/usr/lib/python3.13/threading.py", line 1014, in _bootstrap self._bootstrap_inner() File "/usr/lib/python3.13/threading.py", line 1043, in _bootstrap_inner self.run() File "/usr/lib/python3.13/threading.py", line 994, in run self._target(*self._args, **self._kwargs) File "python3.13/site-packages/twisted/_threads/_threadworker.py", line 75, in work task() File "python3.13/site-packages/twisted/_threads/_team.py", line 192, in doWork task() File "python3.13/site-packages/twisted/python/threadpool.py", line 269, in inContext result = inContext.theWork() # type: ignore[attr-defined] File "python3.13/site-packages/twisted/python/threadpool.py", line 285, in inContext.theWork = lambda: context.call( # type: ignore[attr-defined] File "python3.13/site-packages/twisted/python/context.py", line 117, in callWithContext return self.currentContext().callWithContext(ctx, func, *args, **kw) File "python3.13/site-packages/twisted/python/context.py", line 82, in callWithContext return func(*args, **kw) File "python3.13/site-packages/twisted/enterprise/adbapi.py", line 282, in _runWithConnection result = func(conn, *args, **kw) File "synapse/synapse/storage/database.py", line 1094, in inner_func return func(db_conn, *args, **kwargs) File "synapse/synapse/storage/database.py", line 822, in new_transaction opentracing.log_kv({"message": "commit"}) File "synapse/synapse/logging/opentracing.py", line 427, in ensure_active_span_inner_2 logger.error( ``` ### Why did this happen before? This previously occurred because we called `init_tracer(...)` after the reactor started up in `_base.start()`. But we actually attempt some database transactions earlier than that which try to do some tracing because of that `oidc = hs.get_oidc_handler()` line. Notice `oidc = hs.get_oidc_handler()` happened before `_base.start(hs)`: https://github.com/element-hq/synapse/blob/5be7679dd9dec79b72a2c541ab61efbbd79e1d62/synapse/app/homeserver.py#L397-L408 With this PR, I've updated things to `init_tracer(...)` earlier on alongside where we `setup_logging(...)`. --- changelog.d/18959.misc | 1 + synapse/app/_base.py | 4 ---- synapse/app/generic_worker.py | 4 ++++ synapse/app/homeserver.py | 8 ++++++-- 4 files changed, 11 insertions(+), 6 deletions(-) create mode 100644 changelog.d/18959.misc diff --git a/changelog.d/18959.misc b/changelog.d/18959.misc new file mode 100644 index 0000000000..e97475eec2 --- /dev/null +++ b/changelog.d/18959.misc @@ -0,0 +1 @@ +Fix `no active span when trying to log` tracing error on startup (when OpenTracing is enabled). diff --git a/synapse/app/_base.py b/synapse/app/_base.py index 1cf76d2a0b..d8e1d30b44 100644 --- a/synapse/app/_base.py +++ b/synapse/app/_base.py @@ -73,7 +73,6 @@ from synapse.events.presence_router import load_legacy_presence_router from synapse.handlers.auth import load_legacy_password_auth_providers from synapse.http.site import SynapseSite from synapse.logging.context import LoggingContext, PreserveLoggingContext -from synapse.logging.opentracing import init_tracer from synapse.metrics import install_gc_manager, register_threadpool from synapse.metrics.background_process_metrics import run_as_background_process from synapse.metrics.jemalloc import setup_jemalloc_stats @@ -574,9 +573,6 @@ async def start(hs: "HomeServer") -> None: # Load the certificate from disk. refresh_certificate(hs) - # Start the tracer - init_tracer(hs) # noqa - # Instantiate the modules so they can register their web resources to the module API # before we start the listeners. module_api = hs.get_module_api() diff --git a/synapse/app/generic_worker.py b/synapse/app/generic_worker.py index afc6b85eae..fbc85b2f34 100644 --- a/synapse/app/generic_worker.py +++ b/synapse/app/generic_worker.py @@ -49,6 +49,7 @@ from synapse.config.server import ListenerConfig, TCPListenerConfig from synapse.federation.transport.server import TransportLayerServer from synapse.http.server import JsonResource, OptionsResource from synapse.logging.context import LoggingContext +from synapse.logging.opentracing import init_tracer from synapse.metrics import METRICS_PREFIX, MetricsResource, RegistryProxy from synapse.replication.http import REPLICATION_PREFIX, ReplicationRestResource from synapse.rest import ClientRestResource, admin @@ -359,6 +360,9 @@ def start(config: HomeServerConfig) -> None: setup_logging(hs, config, use_worker_options=True) + # Start the tracer + init_tracer(hs) # noqa + try: hs.setup() diff --git a/synapse/app/homeserver.py b/synapse/app/homeserver.py index 163f7c70ab..159075e886 100644 --- a/synapse/app/homeserver.py +++ b/synapse/app/homeserver.py @@ -29,7 +29,6 @@ from twisted.web.resource import EncodingResourceWrapper, Resource from twisted.web.server import GzipEncoderFactory import synapse -import synapse.config.logger from synapse import events from synapse.api.urls import ( CLIENT_API_PREFIX, @@ -50,6 +49,7 @@ from synapse.app._base import ( ) from synapse.config._base import ConfigError, format_config_error from synapse.config.homeserver import HomeServerConfig +from synapse.config.logger import setup_logging from synapse.config.server import ListenerConfig, TCPListenerConfig from synapse.federation.transport.server import TransportLayerServer from synapse.http.additional_resource import AdditionalResource @@ -60,6 +60,7 @@ from synapse.http.server import ( StaticResource, ) from synapse.logging.context import LoggingContext +from synapse.logging.opentracing import init_tracer from synapse.metrics import METRICS_PREFIX, MetricsResource, RegistryProxy from synapse.replication.http import REPLICATION_PREFIX, ReplicationRestResource from synapse.rest import ClientRestResource, admin @@ -385,7 +386,10 @@ def setup(config: HomeServerConfig) -> SynapseHomeServer: version_string=f"Synapse/{VERSION}", ) - synapse.config.logger.setup_logging(hs, config, use_worker_options=False) + setup_logging(hs, config, use_worker_options=False) + + # Start the tracer + init_tracer(hs) # noqa logger.info("Setting up server")