diff --git a/changelog.d/11870.misc b/changelog.d/11870.misc
new file mode 100644
index 0000000000..2cb0efdb45
--- /dev/null
+++ b/changelog.d/11870.misc
@@ -0,0 +1 @@
+Improve opentracing for incoming federation requests.
diff --git a/synapse/federation/transport/server/_base.py b/synapse/federation/transport/server/_base.py
index 2ca7c05835..dff2b68359 100644
--- a/synapse/federation/transport/server/_base.py
+++ b/synapse/federation/transport/server/_base.py
@@ -15,6 +15,7 @@
import functools
import logging
import re
+import time
from typing import TYPE_CHECKING, Any, Awaitable, Callable, Optional, Tuple, cast
from synapse.api.errors import Codes, FederationDeniedError, SynapseError
@@ -24,8 +25,10 @@ from synapse.http.servlet import parse_json_object_from_request
from synapse.http.site import SynapseRequest
from synapse.logging.context import run_in_background
from synapse.logging.opentracing import (
+ active_span,
set_tag,
span_context_from_request,
+ start_active_span,
start_active_span_follows_from,
whitelisted_homeserver,
)
@@ -265,9 +268,10 @@ class BaseFederationServlet:
content = parse_json_object_from_request(request)
try:
- origin: Optional[str] = await authenticator.authenticate_request(
- request, content
- )
+ with start_active_span("authenticate_request"):
+ origin: Optional[str] = await authenticator.authenticate_request(
+ request, content
+ )
except NoAuthenticationError:
origin = None
if self.REQUIRE_AUTH:
@@ -282,32 +286,57 @@ class BaseFederationServlet:
# update the active opentracing span with the authenticated entity
set_tag("authenticated_entity", origin)
- # if the origin is authenticated and whitelisted, link to its span context
+ # if the origin is authenticated and whitelisted, use its span context
+ # as the parent.
context = None
if origin and whitelisted_homeserver(origin):
context = span_context_from_request(request)
- scope = start_active_span_follows_from(
- "incoming-federation-request", contexts=(context,) if context else ()
- )
+ if context:
+ servlet_span = active_span()
+ # a scope which uses the origin's context as a parent
+ processing_start_time = time.time()
+ scope = start_active_span_follows_from(
+ "incoming-federation-request",
+ child_of=context,
+ contexts=(servlet_span,),
+ start_time=processing_start_time,
+ )
- with scope:
- if origin and self.RATELIMIT:
- with ratelimiter.ratelimit(origin) as d:
- await d
- if request._disconnected:
- logger.warning(
- "client disconnected before we started processing "
- "request"
+ else:
+ # just use our context as a parent
+ scope = start_active_span(
+ "incoming-federation-request",
+ )
+
+ try:
+ with scope:
+ if origin and self.RATELIMIT:
+ with ratelimiter.ratelimit(origin) as d:
+ await d
+ if request._disconnected:
+ logger.warning(
+ "client disconnected before we started processing "
+ "request"
+ )
+ return None
+ response = await func(
+ origin, content, request.args, *args, **kwargs
)
- return None
+ else:
response = await func(
origin, content, request.args, *args, **kwargs
)
- else:
- response = await func(
- origin, content, request.args, *args, **kwargs
+ finally:
+ # if we used the origin's context as the parent, add a new span using
+ # the servlet span as a parent, so that we have a link
+ if context:
+ scope2 = start_active_span_follows_from(
+ "process-federation_request",
+ contexts=(scope.span,),
+ start_time=processing_start_time,
)
+ scope2.close()
return response
diff --git a/synapse/logging/opentracing.py b/synapse/logging/opentracing.py
index d25f25ecb5..3ebed5c161 100644
--- a/synapse/logging/opentracing.py
+++ b/synapse/logging/opentracing.py
@@ -478,6 +478,8 @@ def start_active_span(
def start_active_span_follows_from(
operation_name: str,
contexts: Collection,
+ child_of=None,
+ start_time: Optional[float] = None,
*,
inherit_force_tracing=False,
tracer=None,
@@ -487,6 +489,14 @@ def start_active_span_follows_from(
Args:
operation_name: name of the operation represented by the new span
contexts: the previous spans to inherit from
+
+ child_of: optionally override the parent span. If unset, the currently active
+ span will be the parent. (If there is no currently active span, the first
+ span in `contexts` will be the parent.)
+
+ start_time: optional override for the start time of the created span. Seconds
+ since the epoch.
+
inherit_force_tracing: if set, and any of the previous contexts have had tracing
forced, the new span will also have tracing forced.
tracer: override the opentracing tracer. By default the global tracer is used.
@@ -497,7 +507,9 @@ def start_active_span_follows_from(
references = [opentracing.follows_from(context) for context in contexts]
scope = start_active_span(
operation_name,
+ child_of=child_of,
references=references,
+ start_time=start_time,
tracer=tracer,
)
|
