Implement Trace Context standard

CHANGELOG.asciidoc

@@ -25,6 +25,10 @@ https://github.com/elastic/apm-agent-python/compare/v5.3.1\...master[Check the d
 // Unreleased changes go here
 // When the next release happens, nest these changes under the "Python Agent version 5.x" heading
 
+[float]
+===== New Features
+
+ * Added support for W3C `traceparent` and `tracestate` headers {pull}660[#660]
 
 
 [[release-notes-5.x]]

docs/configuration.asciidoc

@@ -719,6 +719,21 @@ By default in python 3, the agent will install a <<logging,LogRecord factory>> t
 automatically adds tracing fields to your log records. You can disable this
 behavior by setting this to `True`.
 
+[float]
+[[config-use-elastic-traceparent-header]]
+==== `use_elastic_traceparent_header`
+|============
+| Environment                                  | Django/Flask                     | Default
+| `ELASTIC_APM_USE_ELASTIC_TRACEPARENT_HEADER` | `USE_ELASTIC_TRACEPARENT_HEADER` | `True`
+|============
+
+To enable {apm-overview-ref-v}/distributed-tracing.html[distributed tracing],
+the agent sets a number of HTTP headers to outgoing requests made with <<automatic-instrumentation-http,instrumented HTTP libraries>>.
+These headers (`traceparent` and `tracestate`) are defined in the https://www.w3.org/TR/trace-context-1/[W3C Trace Context] specification.
+
+Additionally, when this setting is set to `True`, the agent will set `elasticapm-traceparent` for backwards compatibility.
+
+
 [float]
 [[config-django-specific]]
 === Django-specific configuration

elasticapm/conf/__init__.py

@@ -334,6 +334,7 @@ class Config(_ConfigBase):
     capture_headers = _BoolConfigValue("CAPTURE_HEADERS", default=True)
     django_transaction_name_from_route = _BoolConfigValue("DJANGO_TRANSACTION_NAME_FROM_ROUTE", default=False)
     disable_log_record_factory = _BoolConfigValue("DISABLE_LOG_RECORD_FACTORY", default=False)
+    use_elastic_traceparent_header = _BoolConfigValue("USE_ELASTIC_TRACEPARENT_HEADER", default=True)
 
 
 class VersionedConfig(object):

elasticapm/conf/constants.py

@@ -35,7 +35,9 @@
 AGENT_CONFIG_PATH = "config/v1/agents"
 
 TRACE_CONTEXT_VERSION = 0
-TRACEPARENT_HEADER_NAME = "elastic-apm-traceparent"
+TRACEPARENT_HEADER_NAME = "traceparent"
+TRACEPARENT_LEGACY_HEADER_NAME = "elastic-apm-traceparent"
+TRACESTATE_HEADER_NAME = "tracestate"
 
 TIMESTAMP_FORMAT = "%Y-%m-%dT%H:%M:%S.%fZ"
 

elasticapm/contrib/django/apps.py

@@ -47,6 +47,8 @@
 MIDDLEWARE_NAME = "elasticapm.contrib.django.middleware.TracingMiddleware"
 
 TRACEPARENT_HEADER_NAME_WSGI = "HTTP_" + constants.TRACEPARENT_HEADER_NAME.upper().replace("-", "_")
+TRACEPARENT_LEGACY_HEADER_NAME_WSGI = "HTTP_" + constants.TRACEPARENT_LEGACY_HEADER_NAME.upper().replace("-", "_")
+TRACESTATE_HEADER_NAME_WSGI = "HTTP_" + constants.TRACESTATE_HEADER_NAME.upper().replace("-", "_")
 
 
 class ElasticAPMConfig(AppConfig):
@@ -131,15 +133,15 @@ def _request_started_handler(client, sender, *args, **kwargs):
     if not _should_start_transaction(client):
         return
     # try to find trace id
-    traceparent_header = None
     if "environ" in kwargs:
-        traceparent_header = kwargs["environ"].get(TRACEPARENT_HEADER_NAME_WSGI)
-    elif "scope" in kwargs:
-        # TODO handle Django Channels
-        traceparent_header = None
-    if traceparent_header:
-        trace_parent = TraceParent.from_string(traceparent_header)
-        logger.debug("Read traceparent header %s", traceparent_header)
+        trace_parent = TraceParent.from_headers(
+            kwargs["environ"],
+            TRACEPARENT_HEADER_NAME_WSGI,
+            TRACEPARENT_LEGACY_HEADER_NAME_WSGI,
+            TRACESTATE_HEADER_NAME_WSGI,
+        )
+    elif "scope" in kwargs and "headers" in kwargs["scope"]:
+        trace_parent = TraceParent.from_headers(kwargs["scope"]["headers"])
     else:
         trace_parent = None
     client.begin_transaction("request", trace_parent=trace_parent)

elasticapm/contrib/flask/__init__.py

@@ -37,7 +37,7 @@
 import elasticapm
 import elasticapm.instrumentation.control
 from elasticapm.base import Client
-from elasticapm.conf import constants, setup_logging
+from elasticapm.conf import setup_logging
 from elasticapm.contrib.flask.utils import get_data_from_request, get_data_from_response
 from elasticapm.handlers.logging import LoggingHandler
 from elasticapm.traces import execution_context
@@ -183,10 +183,7 @@ def rum_tracing():
 
     def request_started(self, app):
         if not self.app.debug or self.client.config.debug:
-            if constants.TRACEPARENT_HEADER_NAME in request.headers:
-                trace_parent = TraceParent.from_string(request.headers[constants.TRACEPARENT_HEADER_NAME])
-            else:
-                trace_parent = None
+            trace_parent = TraceParent.from_headers(request.headers)
             self.client.begin_transaction("request", trace_parent=trace_parent)
             elasticapm.set_context(
                 lambda: get_data_from_request(

elasticapm/contrib/opentracing/tracer.py

@@ -115,16 +115,19 @@ def start_span(
 
     def extract(self, format, carrier):
         if format in (Format.HTTP_HEADERS, Format.TEXT_MAP):
-            if constants.TRACEPARENT_HEADER_NAME not in carrier:
+            trace_parent = disttracing.TraceParent.from_headers(carrier)
+            if not trace_parent:
                 raise SpanContextCorruptedException("could not extract span context from carrier")
-            trace_parent = disttracing.TraceParent.from_string(carrier[constants.TRACEPARENT_HEADER_NAME])
             return OTSpanContext(trace_parent=trace_parent)
         raise UnsupportedFormatException
 
     def inject(self, span_context, format, carrier):
         if format in (Format.HTTP_HEADERS, Format.TEXT_MAP):
             if not isinstance(carrier, dict):
                 raise InvalidCarrierException("carrier for {} format should be dict-like".format(format))
-            carrier[constants.TRACEPARENT_HEADER_NAME] = span_context.trace_parent.to_ascii()
+            val = span_context.trace_parent.to_ascii()
+            carrier[constants.TRACEPARENT_HEADER_NAME] = val
+            if self._agent.config.use_elastic_traceparent_header:
+                carrier[constants.TRACEPARENT_LEGACY_HEADER_NAME] = val
             return
         raise UnsupportedFormatException

elasticapm/instrumentation/packages/urllib.py

@@ -90,7 +90,7 @@ def call(self, module, method, wrapped, instance, args, kwargs):
             trace_parent = transaction.trace_parent.copy_from(
                 span_id=parent_id, trace_options=TracingOptions(recorded=True)
             )
-            request_object.add_header(constants.TRACEPARENT_HEADER_NAME, trace_parent.to_string())
+            self._set_disttracing_headers(request_object, trace_parent, transaction)
             return wrapped(*args, **kwargs)
 
     def mutate_unsampled_call_args(self, module, method, wrapped, instance, args, kwargs, transaction):
@@ -100,5 +100,13 @@ def mutate_unsampled_call_args(self, module, method, wrapped, instance, args, kw
             span_id=transaction.id, trace_options=TracingOptions(recorded=False)
         )
 
-        request_object.add_header(constants.TRACEPARENT_HEADER_NAME, trace_parent.to_string())
+        self._set_disttracing_headers(request_object, trace_parent, transaction)
         return args, kwargs
+
+    def _set_disttracing_headers(self, request_object, trace_parent, transaction):
+        trace_parent_str = trace_parent.to_string()
+        request_object.add_header(constants.TRACEPARENT_HEADER_NAME, trace_parent_str)
+        if transaction.tracer.config.use_elastic_traceparent_header:
+            request_object.add_header(constants.TRACEPARENT_LEGACY_HEADER_NAME, trace_parent_str)
+        if trace_parent.tracestate:
+            request_object.add_header(constants.TRACESTATE_HEADER_NAME, trace_parent.tracestate)

elasticapm/instrumentation/packages/urllib3.py

@@ -89,7 +89,7 @@ def call(self, module, method, wrapped, instance, args, kwargs):
                 trace_parent = transaction.trace_parent.copy_from(
                     span_id=parent_id, trace_options=TracingOptions(recorded=True)
                 )
-                headers[constants.TRACEPARENT_HEADER_NAME] = trace_parent.to_string()
+                self._set_disttracing_headers(headers, trace_parent, transaction)
             return wrapped(*args, **kwargs)
 
     def mutate_unsampled_call_args(self, module, method, wrapped, instance, args, kwargs, transaction):
@@ -102,5 +102,13 @@ def mutate_unsampled_call_args(self, module, method, wrapped, instance, args, kw
             if headers is None:
                 headers = {}
                 kwargs["headers"] = headers
-            headers[constants.TRACEPARENT_HEADER_NAME] = trace_parent.to_string()
+            self._set_disttracing_headers(headers, trace_parent, transaction)
         return args, kwargs
+
+    def _set_disttracing_headers(self, headers, trace_parent, transaction):
+        trace_parent_str = trace_parent.to_string()
+        headers[constants.TRACEPARENT_HEADER_NAME] = trace_parent_str
+        if transaction.tracer.config.use_elastic_traceparent_header:
+            headers[constants.TRACEPARENT_LEGACY_HEADER_NAME] = trace_parent_str
+        if trace_parent.tracestate:
+            headers[constants.TRACESTATE_HEADER_NAME] = trace_parent.tracestate

elasticapm/utils/disttracing.py

@@ -30,26 +30,30 @@
 
 import ctypes
 
+from elasticapm.conf import constants
 from elasticapm.utils.logging import get_logger
 
 logger = get_logger("elasticapm.utils")
 
 
 class TraceParent(object):
-    __slots__ = ("version", "trace_id", "span_id", "trace_options")
+    __slots__ = ("version", "trace_id", "span_id", "trace_options", "tracestate", "is_legacy")
 
-    def __init__(self, version, trace_id, span_id, trace_options):
+    def __init__(self, version, trace_id, span_id, trace_options, tracestate=None, is_legacy=False):
         self.version = version
         self.trace_id = trace_id
         self.span_id = span_id
         self.trace_options = trace_options
+        self.is_legacy = is_legacy
+        self.tracestate = tracestate
 
-    def copy_from(self, version=None, trace_id=None, span_id=None, trace_options=None):
+    def copy_from(self, version=None, trace_id=None, span_id=None, trace_options=None, tracestate=None):
         return TraceParent(
             version or self.version,
             trace_id or self.trace_id,
             span_id or self.span_id,
             trace_options or self.trace_options,
+            tracestate or self.tracestate,
         )
 
     def to_string(self):
@@ -59,7 +63,7 @@ def to_ascii(self):
         return self.to_string().encode("ascii")
 
     @classmethod
-    def from_string(cls, traceparent_string):
+    def from_string(cls, traceparent_string, tracestate_string=None, is_legacy=False):
         try:
             parts = traceparent_string.split("-")
             version, trace_id, span_id, trace_flags = parts[:4]
@@ -79,7 +83,42 @@ def from_string(cls, traceparent_string):
         except ValueError:
             logger.debug("Invalid trace-options field, value %s", trace_flags)
             return
-        return TraceParent(version, trace_id, span_id, tracing_options)
+        return TraceParent(version, trace_id, span_id, tracing_options, tracestate_string, is_legacy)
+
+    @classmethod
+    def from_headers(
+        cls,
+        headers,
+        header_name=constants.TRACEPARENT_HEADER_NAME,
+        legacy_header_name=constants.TRACEPARENT_LEGACY_HEADER_NAME,
+        tracestate_header_name=constants.TRACESTATE_HEADER_NAME,
+    ):
+        tracestate = cls.merge_duplicate_headers(headers, tracestate_header_name)
+        if header_name in headers:
+            return TraceParent.from_string(headers[header_name], tracestate, is_legacy=False)
+        elif legacy_header_name in headers:
+            return TraceParent.from_string(headers[legacy_header_name], tracestate, is_legacy=False)
+        else:
+            return None
+
+    @classmethod
+    def merge_duplicate_headers(cls, headers, key):
+        """
+        HTTP allows multiple values for the same header name. Most WSGI implementations
+        merge these values using a comma as separator (this has been confirmed for wsgiref,
+        werkzeug, gunicorn and uwsgi). Other implementations may use containers like
+        multidict to store headers and have APIs to iterate over all values for a given key.
+
+        This method is provided as a hook for framework integrations to provide their own
+        TraceParent implementation. The implementation should return a single string. Multiple
+        values for the same key should be merged using a comma as separator.
+
+        :param headers: a dict-like header object
+        :param key: header name
+        :return: a single string value
+        """
+        # this works for all known WSGI implementations
+        return headers.get(key)
 
 
 class TracingOptions_bits(ctypes.LittleEndianStructure):

tests/contrib/django/django_tests.py

@@ -65,6 +65,7 @@
 from elasticapm.contrib.django.handlers import LoggingHandler
 from elasticapm.contrib.django.middleware.wsgi import ElasticAPM
 from elasticapm.utils import compat
+from elasticapm.utils.disttracing import TraceParent
 from tests.contrib.django.testapp.views import IgnoredException, MyException
 from tests.utils.compat import middleware_setting
 
@@ -923,16 +924,25 @@ def test_tracing_middleware_autoinsertion_wrong_type(middleware_attr, caplog):
     assert "not of type list or tuple" in record.message
 
 
-def test_traceparent_header_handling(django_elasticapm_client, client):
+@pytest.mark.parametrize("header_name", [constants.TRACEPARENT_HEADER_NAME, constants.TRACEPARENT_LEGACY_HEADER_NAME])
+def test_traceparent_header_handling(django_elasticapm_client, client, header_name):
     with override_settings(
         **middleware_setting(django.VERSION, ["elasticapm.contrib.django.middleware.TracingMiddleware"])
-    ):
-        header_name = "HTTP_" + constants.TRACEPARENT_HEADER_NAME.upper().replace("-", "_")
-        kwargs = {header_name: "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-03"}
+    ), mock.patch(
+        "elasticapm.contrib.django.apps.TraceParent.from_string", wraps=TraceParent.from_string
+    ) as wrapped_from_string:
+        wsgi = lambda s: "HTTP_" + s.upper().replace("-", "_")
+        wsgi_header_name = wsgi(header_name)
+        wsgi_tracestate_name = wsgi(constants.TRACESTATE_HEADER_NAME)
+        kwargs = {
+            wsgi_header_name: "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-03",
+            wsgi_tracestate_name: "foo=bar,baz=bazzinga",
+        }
         client.get(reverse("elasticapm-no-error"), **kwargs)
         transaction = django_elasticapm_client.events[TRANSACTION][0]
         assert transaction["trace_id"] == "0af7651916cd43dd8448eb211c80319c"
         assert transaction["parent_id"] == "b7ad6b7169203331"
+        assert "foo=bar,baz=bazzinga" in wrapped_from_string.call_args[0]
 
 
 def test_get_service_info(django_elasticapm_client):

tests/contrib/flask/flask_tests.py

@@ -35,10 +35,13 @@
 import logging
 import os
 
+import mock
+
 from elasticapm.conf import constants
 from elasticapm.conf.constants import ERROR, TRANSACTION
 from elasticapm.contrib.flask import ElasticAPM
 from elasticapm.utils import compat
+from elasticapm.utils.disttracing import TraceParent
 from tests.contrib.flask.utils import captured_templates
 
 try:
@@ -222,20 +225,28 @@ def test_instrumentation_404(flask_apm_client):
     assert len(spans) == 0, [t["signature"] for t in spans]
 
 
-def test_traceparent_handling(flask_apm_client):
-    resp = flask_apm_client.app.test_client().post(
-        "/users/",
-        data={"foo": "bar"},
-        headers={constants.TRACEPARENT_HEADER_NAME: "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-03"},
-    )
-    resp.close()
+@pytest.mark.parametrize("header_name", [constants.TRACEPARENT_HEADER_NAME, constants.TRACEPARENT_LEGACY_HEADER_NAME])
+def test_traceparent_handling(flask_apm_client, header_name):
+    with mock.patch(
+        "elasticapm.contrib.flask.TraceParent.from_string", wraps=TraceParent.from_string
+    ) as wrapped_from_string:
+        resp = flask_apm_client.app.test_client().post(
+            "/users/",
+            data={"foo": "bar"},
+            headers={
+                header_name: "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-03",
+                constants.TRACESTATE_HEADER_NAME: "foo=bar,baz=bazzinga",
+            },
+        )
+        resp.close()
 
     assert resp.status_code == 200, resp.response
 
     transaction = flask_apm_client.client.events[TRANSACTION][0]
 
     assert transaction["trace_id"] == "0af7651916cd43dd8448eb211c80319c"
     assert transaction["parent_id"] == "b7ad6b7169203331"
+    assert "foo=bar,baz=bazzinga" in wrapped_from_string.call_args[0]
 
 
 def test_non_standard_http_status(flask_apm_client):

tests/contrib/opentracing/tests.py

@@ -249,22 +249,42 @@ def test_tracer_extract_corrupted(tracer):
         tracer.extract(Format.HTTP_HEADERS, {"nothing-to": "see-here"})
 
 
+@pytest.mark.parametrize(
+    "elasticapm_client",
+    [
+        pytest.param({"use_elastic_traceparent_header": True}, id="use_elastic_traceparent_header-True"),
+        pytest.param({"use_elastic_traceparent_header": False}, id="use_elastic_traceparent_header-False"),
+    ],
+    indirect=True,
+)
 def test_tracer_inject_http(tracer):
     span_context = OTSpanContext(
         trace_parent=TraceParent.from_string("00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01")
     )
     carrier = {}
     tracer.inject(span_context, Format.HTTP_HEADERS, carrier)
-    assert carrier["elastic-apm-traceparent"] == b"00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"
-
-
+    assert carrier[constants.TRACEPARENT_HEADER_NAME] == b"00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"
+    if tracer._agent.config.use_elastic_traceparent_header:
+        assert carrier[constants.TRACEPARENT_LEGACY_HEADER_NAME] == carrier[constants.TRACEPARENT_HEADER_NAME]
+
+
+@pytest.mark.parametrize(
+    "elasticapm_client",
+    [
+        pytest.param({"use_elastic_traceparent_header": True}, id="use_elastic_traceparent_header-True"),
+        pytest.param({"use_elastic_traceparent_header": False}, id="use_elastic_traceparent_header-False"),
+    ],
+    indirect=True,
+)
 def test_tracer_inject_map(tracer):
     span_context = OTSpanContext(
         trace_parent=TraceParent.from_string("00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01")
     )
     carrier = {}
     tracer.inject(span_context, Format.TEXT_MAP, carrier)
-    assert carrier["elastic-apm-traceparent"] == b"00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"
+    assert carrier[constants.TRACEPARENT_HEADER_NAME] == b"00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"
+    if tracer._agent.config.use_elastic_traceparent_header:
+        assert carrier[constants.TRACEPARENT_LEGACY_HEADER_NAME] == carrier[constants.TRACEPARENT_HEADER_NAME]
 
 
 def test_tracer_inject_binary(tracer):