diff options
author | Eric Eastwood <erice@element.io> | 2022-08-02 12:49:57 -0500 |
---|---|---|
committer | Eric Eastwood <erice@element.io> | 2022-08-02 12:49:57 -0500 |
commit | 0f93ec8d590c447339cc735c05eab0577a68adcd (patch) | |
tree | 4631aacfc7701295a6a981cc0b9d321681362a44 | |
parent | Revert crazy custom sampler and span process to try force tracing for users (diff) | |
download | synapse-0f93ec8d590c447339cc735c05eab0577a68adcd.tar.xz |
Fix lints
-rw-r--r-- | synapse/api/auth.py | 7 | ||||
-rw-r--r-- | synapse/http/server.py | 2 | ||||
-rw-r--r-- | synapse/http/site.py | 4 | ||||
-rw-r--r-- | synapse/logging/tracing.py | 43 | ||||
-rw-r--r-- | synapse/storage/controllers/persist_events.py | 2 | ||||
-rw-r--r-- | synapse/util/caches/response_cache.py | 6 | ||||
-rw-r--r-- | tests/logging/test_tracing.py | 15 |
7 files changed, 38 insertions, 41 deletions
diff --git a/synapse/api/auth.py b/synapse/api/auth.py index 85dd71aac2..aa4ad9a506 100644 --- a/synapse/api/auth.py +++ b/synapse/api/auth.py @@ -30,12 +30,7 @@ from synapse.api.errors import ( from synapse.appservice import ApplicationService from synapse.http import get_request_user_agent from synapse.http.site import SynapseRequest -from synapse.logging.tracing import ( - force_tracing, - get_active_span, - start_active_span, - SynapseTags, -) +from synapse.logging.tracing import force_tracing, get_active_span, start_active_span from synapse.storage.databases.main.registration import TokenLookupResult from synapse.types import Requester, UserID, create_requester diff --git a/synapse/http/server.py b/synapse/http/server.py index c12028c921..5b94e159d6 100644 --- a/synapse/http/server.py +++ b/synapse/http/server.py @@ -868,7 +868,7 @@ async def _async_write_json_to_request_in_thread( expensive. """ - def encode(tracing_span: Optional["opentelemetry.trace.span.Span"]) -> bytes: + def encode(tracing_span: Optional["opentelemetry.trace.Span"]) -> bytes: # it might take a while for the threadpool to schedule us, so we write # opentracing logs once we actually get scheduled, so that we can see how # much that contributed. diff --git a/synapse/http/site.py b/synapse/http/site.py index bca7fba471..a82c23174a 100644 --- a/synapse/http/site.py +++ b/synapse/http/site.py @@ -87,7 +87,7 @@ class SynapseRequest(Request): # An opentracing span for this request. Will be closed when the request is # completely processed. - self._tracing_span: Optional["opentelemetry.trace.span.Span"] = None + self._tracing_span: Optional["opentelemetry.trace.Span"] = None # we can't yet create the logcontext, as we don't know the method. self.logcontext: Optional[LoggingContext] = None @@ -164,7 +164,7 @@ class SynapseRequest(Request): # If there's no authenticated entity, it was the requester. self.logcontext.request.authenticated_entity = authenticated_entity or requester - def set_tracing_span(self, span: "opentelemetry.trace.span.Span") -> None: + def set_tracing_span(self, span: "opentelemetry.trace.Span") -> None: """attach an opentracing span to this request Doing so will cause the span to be closed when we finish processing the request diff --git a/synapse/logging/tracing.py b/synapse/logging/tracing.py index 734e94f6e0..cee4a9f36c 100644 --- a/synapse/logging/tracing.py +++ b/synapse/logging/tracing.py @@ -163,7 +163,6 @@ Gotchas with an active span? """ import contextlib -import enum import inspect import logging import re @@ -299,12 +298,6 @@ _homeserver_whitelist: Optional[Pattern[str]] = None # Util methods -class _Sentinel(enum.Enum): - # defining a sentinel in this way allows mypy to correctly handle the - # type of a dictionary lookup. - sentinel = object() - - P = ParamSpec("P") R = TypeVar("R") @@ -405,6 +398,13 @@ def init_tracer(hs: "HomeServer") -> None: } ) + # TODO: `force_tracing_for_users` is not compatible with OTEL samplers + # because you can only determine `opentelemetry.trace.TraceFlags.SAMPLED` + # and whether it uses a recording span when the span is created and we don't + # have enough information at that time (we can determine in + # `synapse/api/auth.py`). There isn't a way to change the trace flags after + # the fact so there is no way to programmatically force + # recording/tracing/sampling like there was in opentracing. sampler = opentelemetry.sdk.trace.sampling.ParentBasedTraceIdRatio( hs.config.tracing.sample_rate ) @@ -465,16 +465,16 @@ def whitelisted_homeserver(destination: str) -> bool: def use_span( - span: "opentelemetry.trace.span.Span", + span: "opentelemetry.trace.Span", end_on_exit: bool = True, -) -> ContextManager["opentelemetry.trace.span.Span"]: +) -> ContextManager["opentelemetry.trace.Span"]: if opentelemetry is None: return contextlib.nullcontext() # type: ignore[unreachable] return opentelemetry.trace.use_span(span=span, end_on_exit=end_on_exit) -def create_non_recording_span() -> "opentelemetry.trace.span.Span": +def create_non_recording_span() -> "opentelemetry.trace.Span": """Create a no-op span that does not record or become part of a recorded trace""" return opentelemetry.trace.NonRecordingSpan( @@ -495,7 +495,7 @@ def start_span( end_on_exit: bool = True, # For testing only tracer: Optional["opentelemetry.trace.Tracer"] = None, -) -> "opentelemetry.trace.span.Span": +) -> "opentelemetry.trace.Span": if opentelemetry is None: raise Exception("Not able to create span without opentelemetry installed.") @@ -532,7 +532,7 @@ def start_active_span( end_on_exit: bool = True, # For testing only tracer: Optional["opentelemetry.trace.Tracer"] = None, -) -> ContextManager["opentelemetry.trace.span.Span"]: +) -> ContextManager["opentelemetry.trace.Span"]: if opentelemetry is None: return contextlib.nullcontext() # type: ignore[unreachable] @@ -566,7 +566,7 @@ def start_active_span_from_edu( operation_name: str, *, edu_content: Dict[str, Any], -) -> ContextManager["opentelemetry.trace.span.Span"]: +) -> ContextManager["opentelemetry.trace.Span"]: """ Extracts a span context from an edu and uses it to start a new active span @@ -589,14 +589,14 @@ def start_active_span_from_edu( # OpenTelemetry setters for attributes, logs, etc @only_if_tracing -def get_active_span() -> Optional["opentelemetry.trace.span.Span"]: +def get_active_span() -> Optional["opentelemetry.trace.Span"]: """Get the currently active span, if any""" return opentelemetry.trace.get_current_span() def get_span_context_from_context( context: "opentelemetry.context.context.Context", -) -> Optional["opentelemetry.trace.span.SpanContext"]: +) -> Optional["opentelemetry.trace.SpanContext"]: """Utility function to convert a `Context` to a `SpanContext` Based on https://github.com/open-telemetry/opentelemetry-python/blob/43288ca9a36144668797c11ca2654836ec8b5e99/opentelemetry-api/src/opentelemetry/trace/propagation/tracecontext.py#L99-L102 @@ -609,7 +609,7 @@ def get_span_context_from_context( def get_context_from_span( - span: "opentelemetry.trace.span.Span", + span: "opentelemetry.trace.Span", ) -> "opentelemetry.context.context.Context": # This doesn't affect the current context at all, it just converts a span # into `Context` object basically (bad name). @@ -650,7 +650,7 @@ def log_kv(key_values: Dict[str, Any], timestamp: Optional[int] = None) -> None: @only_if_tracing -def force_tracing(span: Optional["opentelemetry.trace.span.Span"] = None) -> None: +def force_tracing(span: Optional["opentelemetry.trace.Span"] = None) -> None: """Force sampling for the active/given span and its children. Args: @@ -661,7 +661,7 @@ def force_tracing(span: Optional["opentelemetry.trace.span.Span"] = None) -> Non def is_context_forced_tracing( - span_context: Optional["opentelemetry.shim.opentracing_shim.SpanContextShim"], + context: "opentelemetry.context.context.Context", ) -> bool: """Check if sampling has been force for the given span context.""" # TODO @@ -942,6 +942,7 @@ def trace_servlet( # with JsonResource). span.update_name(request.request_metrics.name) - span.set_attribute( - SynapseTags.REQUEST_TAG, request.request_metrics.start_context.tag - ) + if request.request_metrics.start_context.tag is not None: + span.set_attribute( + SynapseTags.REQUEST_TAG, request.request_metrics.start_context.tag + ) diff --git a/synapse/storage/controllers/persist_events.py b/synapse/storage/controllers/persist_events.py index 756a73be2e..0c379814c3 100644 --- a/synapse/storage/controllers/persist_events.py +++ b/synapse/storage/controllers/persist_events.py @@ -273,8 +273,6 @@ class _EventPeristenceQueue(Generic[_PersistResult]): Link(span_context) for span_context in item.parent_tracing_span_contexts ], - # TODO: inherit_force_tracing - inherit_force_tracing=True, ) as span: if span: item.tracing_span_context = span.get_span_context() diff --git a/synapse/util/caches/response_cache.py b/synapse/util/caches/response_cache.py index 3ea48a8551..1dd2d3e62e 100644 --- a/synapse/util/caches/response_cache.py +++ b/synapse/util/caches/response_cache.py @@ -78,7 +78,7 @@ class ResponseCacheEntry: easier to cache Failure results. """ - tracing_span_context: Optional["opentelemetry.trace.span.SpanContext"] + tracing_span_context: Optional["opentelemetry.trace.SpanContext"] """The tracing span which generated/is generating the result""" @@ -137,7 +137,7 @@ class ResponseCache(Generic[KV]): self, context: ResponseCacheContext[KV], deferred: "defer.Deferred[RV]", - tracing_span_context: Optional["opentelemetry.trace.span.SpanContext"], + tracing_span_context: Optional["opentelemetry.trace.SpanContext"], ) -> ResponseCacheEntry: """Set the entry for the given key to the given deferred. @@ -230,7 +230,7 @@ class ResponseCache(Generic[KV]): if cache_context: kwargs["cache_context"] = context - span_context: Optional["opentelemetry.trace.span.SpanContext"] = None + span_context: Optional["opentelemetry.trace.SpanContext"] = None async def cb() -> RV: # NB it is important that we do not `await` before setting span_context! diff --git a/tests/logging/test_tracing.py b/tests/logging/test_tracing.py index 59529c9d01..98a37e5235 100644 --- a/tests/logging/test_tracing.py +++ b/tests/logging/test_tracing.py @@ -64,13 +64,13 @@ class TracingTestCase(TestCase): # start_active_span should start and activate a span. with start_active_span("new-span", tracer=self._tracer) as span: self.assertEqual(opentelemetry.trace.get_current_span(), span) - self.assertIsNotNone(span.start_time) + self.assertIsNotNone(span.start_time) # type: ignore[attr-defined] # ... but leaving it unsets the active span, and finishes the span. self.assertEqual( opentelemetry.trace.get_current_span(), opentelemetry.trace.INVALID_SPAN ) - self.assertIsNotNone(span.end_time) + self.assertIsNotNone(span.end_time) # type: ignore[attr-defined] # the span should have been reported self.assertListEqual( @@ -92,7 +92,10 @@ class TracingTestCase(TestCase): child_span1, "child_span1 was not activated", ) - self.assertEqual(child_span1.parent.span_id, root_context.span_id) + self.assertEqual( + child_span1.parent.span_id, # type: ignore[attr-defined] + root_context.span_id, + ) with start_active_span( "child_span2", @@ -102,14 +105,14 @@ class TracingTestCase(TestCase): opentelemetry.trace.get_current_span(), child_span2 ) self.assertEqual( - child_span2.parent.span_id, + child_span2.parent.span_id, # type: ignore[attr-defined] child_span1.get_span_context().span_id, ) # the root scope should be restored self.assertEqual(opentelemetry.trace.get_current_span(), root_span) - self.assertIsNotNone(child_span1.end_time) - self.assertIsNotNone(child_span2.end_time) + self.assertIsNotNone(child_span1.end_time) # type: ignore[attr-defined] + self.assertIsNotNone(child_span2.end_time) # type: ignore[attr-defined] # Active span is unset now that we're outside of the `with` scopes self.assertEqual( |