Skip to content

Commit 25fa555

Browse files
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 <lambda> 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(...)`.
1 parent 7708801 commit 25fa555

File tree

4 files changed

+11
-6
lines changed

4 files changed

+11
-6
lines changed

changelog.d/18959.misc

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
1+
Fix `no active span when trying to log` tracing error on startup (when OpenTracing is enabled).

synapse/app/_base.py

Lines changed: 0 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -73,7 +73,6 @@
7373
from synapse.handlers.auth import load_legacy_password_auth_providers
7474
from synapse.http.site import SynapseSite
7575
from synapse.logging.context import LoggingContext, PreserveLoggingContext
76-
from synapse.logging.opentracing import init_tracer
7776
from synapse.metrics import install_gc_manager, register_threadpool
7877
from synapse.metrics.background_process_metrics import run_as_background_process
7978
from synapse.metrics.jemalloc import setup_jemalloc_stats
@@ -574,9 +573,6 @@ def run_sighup(*args: Any, **kwargs: Any) -> None:
574573
# Load the certificate from disk.
575574
refresh_certificate(hs)
576575

577-
# Start the tracer
578-
init_tracer(hs) # noqa
579-
580576
# Instantiate the modules so they can register their web resources to the module API
581577
# before we start the listeners.
582578
module_api = hs.get_module_api()

synapse/app/generic_worker.py

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -49,6 +49,7 @@
4949
from synapse.federation.transport.server import TransportLayerServer
5050
from synapse.http.server import JsonResource, OptionsResource
5151
from synapse.logging.context import LoggingContext
52+
from synapse.logging.opentracing import init_tracer
5253
from synapse.metrics import METRICS_PREFIX, MetricsResource, RegistryProxy
5354
from synapse.replication.http import REPLICATION_PREFIX, ReplicationRestResource
5455
from synapse.rest import ClientRestResource, admin
@@ -359,6 +360,9 @@ def start(config: HomeServerConfig) -> None:
359360

360361
setup_logging(hs, config, use_worker_options=True)
361362

363+
# Start the tracer
364+
init_tracer(hs) # noqa
365+
362366
try:
363367
hs.setup()
364368

synapse/app/homeserver.py

Lines changed: 6 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -29,7 +29,6 @@
2929
from twisted.web.server import GzipEncoderFactory
3030

3131
import synapse
32-
import synapse.config.logger
3332
from synapse import events
3433
from synapse.api.urls import (
3534
CLIENT_API_PREFIX,
@@ -50,6 +49,7 @@
5049
)
5150
from synapse.config._base import ConfigError, format_config_error
5251
from synapse.config.homeserver import HomeServerConfig
52+
from synapse.config.logger import setup_logging
5353
from synapse.config.server import ListenerConfig, TCPListenerConfig
5454
from synapse.federation.transport.server import TransportLayerServer
5555
from synapse.http.additional_resource import AdditionalResource
@@ -60,6 +60,7 @@
6060
StaticResource,
6161
)
6262
from synapse.logging.context import LoggingContext
63+
from synapse.logging.opentracing import init_tracer
6364
from synapse.metrics import METRICS_PREFIX, MetricsResource, RegistryProxy
6465
from synapse.replication.http import REPLICATION_PREFIX, ReplicationRestResource
6566
from synapse.rest import ClientRestResource, admin
@@ -385,7 +386,10 @@ def setup(config: HomeServerConfig) -> SynapseHomeServer:
385386
version_string=f"Synapse/{VERSION}",
386387
)
387388

388-
synapse.config.logger.setup_logging(hs, config, use_worker_options=False)
389+
setup_logging(hs, config, use_worker_options=False)
390+
391+
# Start the tracer
392+
init_tracer(hs) # noqa
389393

390394
logger.info("Setting up server")
391395

0 commit comments

Comments
 (0)