diff --git a/synapse/federation/federation_base.py b/synapse/federation/federation_base.py
index 6bd4742140..d5d1b06fa4 100644
--- a/synapse/federation/federation_base.py
+++ b/synapse/federation/federation_base.py
@@ -23,7 +23,7 @@ from synapse.crypto.keyring import Keyring
from synapse.events import EventBase, make_event_from_dict
from synapse.events.utils import prune_event, validate_canonicaljson
from synapse.http.servlet import assert_params_in_dict
-from synapse.logging.opentracing import log_kv, trace
+from synapse.logging.tracing import log_kv, trace
from synapse.types import JsonDict, get_domain_from_id
if TYPE_CHECKING:
diff --git a/synapse/federation/federation_client.py b/synapse/federation/federation_client.py
index c4c0bc7315..0615ce0870 100644
--- a/synapse/federation/federation_client.py
+++ b/synapse/federation/federation_client.py
@@ -61,7 +61,7 @@ from synapse.federation.federation_base import (
)
from synapse.federation.transport.client import SendJoinResponse
from synapse.http.types import QueryParams
-from synapse.logging.opentracing import SynapseTags, log_kv, set_tag, tag_args, trace
+from synapse.logging.tracing import SynapseTags, log_kv, set_attribute, tag_args, trace
from synapse.types import JsonDict, UserID, get_domain_from_id
from synapse.util.async_helpers import concurrently_execute
from synapse.util.caches.expiringcache import ExpiringCache
@@ -507,19 +507,19 @@ class FederationClient(FederationBase):
state_event_ids = result["pdu_ids"]
auth_event_ids = result.get("auth_chain_ids", [])
- set_tag(
+ set_attribute(
SynapseTags.RESULT_PREFIX + "state_event_ids",
str(state_event_ids),
)
- set_tag(
+ set_attribute(
SynapseTags.RESULT_PREFIX + "state_event_ids.length",
str(len(state_event_ids)),
)
- set_tag(
+ set_attribute(
SynapseTags.RESULT_PREFIX + "auth_event_ids",
str(auth_event_ids),
)
- set_tag(
+ set_attribute(
SynapseTags.RESULT_PREFIX + "auth_event_ids.length",
str(len(auth_event_ids)),
)
@@ -626,7 +626,7 @@ class FederationClient(FederationBase):
Returns:
A list of PDUs that have valid signatures and hashes.
"""
- set_tag(
+ set_attribute(
SynapseTags.RESULT_PREFIX + "pdus.length",
str(len(pdus)),
)
diff --git a/synapse/federation/federation_server.py b/synapse/federation/federation_server.py
index bb20af6e91..4f4a88b953 100644
--- a/synapse/federation/federation_server.py
+++ b/synapse/federation/federation_server.py
@@ -61,12 +61,7 @@ from synapse.logging.context import (
nested_logging_context,
run_in_background,
)
-from synapse.logging.opentracing import (
- log_kv,
- start_active_span_from_edu,
- tag_args,
- trace,
-)
+from synapse.logging.tracing import log_kv, start_active_span_from_edu, tag_args, trace
from synapse.metrics.background_process_metrics import wrap_as_background_process
from synapse.replication.http.federation import (
ReplicationFederationSendEduRestServlet,
@@ -1449,7 +1444,7 @@ class FederationHandlerRegistry:
# Check if we have a handler on this instance
handler = self.edu_handlers.get(edu_type)
if handler:
- with start_active_span_from_edu(content, "handle_edu"):
+ with start_active_span_from_edu("handle_edu", edu_content=content):
try:
await handler(origin, content)
except SynapseError as e:
diff --git a/synapse/federation/sender/per_destination_queue.py b/synapse/federation/sender/per_destination_queue.py
index 3ae5e8634c..6575c6c8a5 100644
--- a/synapse/federation/sender/per_destination_queue.py
+++ b/synapse/federation/sender/per_destination_queue.py
@@ -32,7 +32,7 @@ from synapse.events import EventBase
from synapse.federation.units import Edu
from synapse.handlers.presence import format_user_presence_state
from synapse.logging import issue9533_logger
-from synapse.logging.opentracing import SynapseTags, set_tag
+from synapse.logging.tracing import SynapseTags, set_attribute
from synapse.metrics import sent_transactions_counter
from synapse.metrics.background_process_metrics import run_as_background_process
from synapse.types import ReadReceipt
@@ -597,7 +597,7 @@ class PerDestinationQueue:
if not message_id:
continue
- set_tag(SynapseTags.TO_DEVICE_MESSAGE_ID, message_id)
+ set_attribute(SynapseTags.TO_DEVICE_MESSAGE_ID, message_id)
edus = [
Edu(
diff --git a/synapse/federation/sender/transaction_manager.py b/synapse/federation/sender/transaction_manager.py
index 75081810fd..3f2c8bcfa1 100644
--- a/synapse/federation/sender/transaction_manager.py
+++ b/synapse/federation/sender/transaction_manager.py
@@ -21,11 +21,13 @@ from synapse.api.errors import HttpResponseException
from synapse.events import EventBase
from synapse.federation.persistence import TransactionActions
from synapse.federation.units import Edu, Transaction
-from synapse.logging.opentracing import (
+from synapse.logging.tracing import (
+ Link,
+ StatusCode,
extract_text_map,
- set_tag,
- start_active_span_follows_from,
- tags,
+ get_span_context_from_context,
+ set_status,
+ start_active_span,
whitelisted_homeserver,
)
from synapse.types import JsonDict
@@ -79,7 +81,7 @@ class TransactionManager:
edus: List of EDUs to send
"""
- # Make a transaction-sending opentracing span. This span follows on from
+ # Make a transaction-sending tracing span. This span follows on from
# all the edus in that transaction. This needs to be done since there is
# no active span here, so if the edus were not received by the remote the
# span would have no causality and it would be forgotten.
@@ -88,13 +90,20 @@ class TransactionManager:
keep_destination = whitelisted_homeserver(destination)
for edu in edus:
- context = edu.get_context()
- if context:
- span_contexts.append(extract_text_map(json_decoder.decode(context)))
+ tracing_context_json = edu.get_tracing_context_json()
+ if tracing_context_json:
+ context = extract_text_map(json_decoder.decode(tracing_context_json))
+ if context:
+ span_context = get_span_context_from_context(context)
+ if span_context:
+ span_contexts.append(span_context)
if keep_destination:
- edu.strip_context()
+ edu.strip_tracing_context()
- with start_active_span_follows_from("send_transaction", span_contexts):
+ with start_active_span(
+ "send_transaction",
+ links=[Link(span_context) for span_context in span_contexts],
+ ):
logger.debug("TX [%s] _attempt_new_transaction", destination)
txn_id = str(self._next_txn_id)
@@ -166,7 +175,7 @@ class TransactionManager:
except HttpResponseException as e:
code = e.code
- set_tag(tags.ERROR, True)
+ set_status(StatusCode.ERROR, e)
logger.info("TX [%s] {%s} got %d response", destination, txn_id, code)
raise
diff --git a/synapse/federation/transport/server/_base.py b/synapse/federation/transport/server/_base.py
index cdaf0d5de7..fd927e0af7 100644
--- a/synapse/federation/transport/server/_base.py
+++ b/synapse/federation/transport/server/_base.py
@@ -15,7 +15,6 @@
import functools
import logging
import re
-import time
from http import HTTPStatus
from typing import TYPE_CHECKING, Any, Awaitable, Callable, Dict, Optional, Tuple, cast
@@ -25,12 +24,15 @@ from synapse.http.server import HttpServer, ServletCallback
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,
+from synapse.logging.tracing import (
+ Link,
+ context_from_request,
+ create_non_recording_span,
+ get_active_span,
+ set_attribute,
start_active_span,
- start_active_span_follows_from,
+ start_span,
+ use_span,
whitelisted_homeserver,
)
from synapse.types import JsonDict
@@ -309,60 +311,71 @@ class BaseFederationServlet:
logger.warning("authenticate_request failed: %s", e)
raise
- # update the active opentracing span with the authenticated entity
- set_tag("authenticated_entity", str(origin))
+ # update the active tracing span with the authenticated entity
+ set_attribute("authenticated_entity", str(origin))
# if the origin is authenticated and whitelisted, use its span context
# as the parent.
- context = None
+ origin_context = None
if origin and whitelisted_homeserver(origin):
- context = span_context_from_request(request)
-
- 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(
+ origin_context = context_from_request(request)
+
+ remote_parent_span = None
+ if origin_context:
+ local_servlet_span = get_active_span()
+ # Create a span which uses the `origin_context` as a parent
+ # so we can see how the incoming payload was processed while
+ # we're looking at the outgoing trace. Since the parent is set
+ # to a remote span (from the origin), it won't show up in the
+ # local trace which is why we create another span below for the
+ # local trace. A span can only have one parent so we have to
+ # create two separate ones.
+ remote_parent_span = start_span(
"incoming-federation-request",
- child_of=context,
- contexts=(servlet_span,),
- start_time=processing_start_time,
+ context=origin_context,
+ # Cross-link back to the local trace so we can jump
+ # to the incoming side from the remote origin trace.
+ links=[Link(local_servlet_span.get_span_context())]
+ if local_servlet_span
+ else None,
)
+ # Create a local span to appear in the local trace
+ local_parent_span_cm = start_active_span(
+ "process-federation-request",
+ # Cross-link back to the remote outgoing trace so we can
+ # jump over there.
+ links=[Link(remote_parent_span.get_span_context())],
+ )
else:
- # just use our context as a parent
- scope = start_active_span(
- "incoming-federation-request",
+ # Otherwise just use our local active servlet context as a parent
+ local_parent_span_cm = start_active_span(
+ "process-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
+ # Don't need to record anything for the remote because no remote
+ # trace context given.
+ remote_parent_span = create_non_recording_span()
+
+ remote_parent_span_cm = use_span(remote_parent_span, end_on_exit=True)
+
+ with remote_parent_span_cm, local_parent_span_cm:
+ 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:
+ return None
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,
+ else:
+ response = await func(
+ origin, content, request.args, *args, **kwargs
)
- scope2.close()
return response
diff --git a/synapse/federation/units.py b/synapse/federation/units.py
index b9b12fbea5..a6b590269e 100644
--- a/synapse/federation/units.py
+++ b/synapse/federation/units.py
@@ -21,6 +21,7 @@ from typing import List, Optional
import attr
+from synapse.api.constants import EventContentFields
from synapse.types import JsonDict
logger = logging.getLogger(__name__)
@@ -54,11 +55,13 @@ class Edu:
"destination": self.destination,
}
- def get_context(self) -> str:
- return getattr(self, "content", {}).get("org.matrix.opentracing_context", "{}")
+ def get_tracing_context_json(self) -> str:
+ return getattr(self, "content", {}).get(
+ EventContentFields.TRACING_CONTEXT, "{}"
+ )
- def strip_context(self) -> None:
- getattr(self, "content", {})["org.matrix.opentracing_context"] = "{}"
+ def strip_tracing_context(self) -> None:
+ getattr(self, "content", {})[EventContentFields.TRACING_CONTEXT] = "{}"
def _none_to_list(edus: Optional[List[JsonDict]]) -> List[JsonDict]:
|
