dd-trace-py icon indicating copy to clipboard operation
dd-trace-py copied to clipboard

`ddtrace.opentracer` incorrectly raises `SpanContextCorruptedException` on `extract` of missing span context

Open bdowning opened this issue 4 years ago • 4 comments

The documentation for SpanContextCorruptedException says:

SpanContextCorruptedException should be used when the underlying span context state is seemingly present but not well-formed.

ddtrace.opentracer's extract is throwing an error whenever it fails to recover a span, whether or not it was malformed or simply missing. This completely breaks the normal pattern of "I received an HTTP request, so I'll throw the headers at extract and pass the result to child_of for my new span, expecting to get None and therefore make a new root span if I was called without tracing info".

Which version of dd-trace-py are you using?

Python 3.7 ddtrace 0.46.0

How can we reproduce your problem?

In [1]: from opentracing import Format

In [2]: from ddtrace.opentracer import Tracer

In [3]: tracer = Tracer()

In [4]: tracer.extract(Format.HTTP_HEADERS, {})
---------------------------------------------------------------------------
SpanContextCorruptedException             Traceback (most recent call last)
<ipython-input-4-f497fe0c23a2> in <module>
----> 1 tracer.extract(Format.HTTP_HEADERS, {})

~/projects/granular/analysis/analysis-api/.venv/lib/python3.7/site-packages/ddtrace/opentracer/tracer.py in extract(self, format, carrier)
    326         # we have to manually activate the returned context from a distributed
    327         # trace
--> 328         ot_span_ctx = propagator.extract(carrier)
    329         dd_span_ctx = ot_span_ctx._dd_context
    330         self._dd_tracer.context_provider.activate(dd_span_ctx)

~/projects/granular/analysis/analysis-api/.venv/lib/python3.7/site-packages/ddtrace/opentracer/propagation/http.py in extract(self, carrier)
     70         # if this occurs.
     71         if not ddspan_ctx.trace_id:
---> 72             raise SpanContextCorruptedException("failed to extract span context")
     73 
     74         baggage = {}

SpanContextCorruptedException: failed to extract span context

What is the result that you expected?

I expect to get a clean None with no error if no DataDog span context material was present. See Jaeger:

In [1]: from opentracing import Format

In [2]: import jaeger_client

In [3]: tracer = jaeger_client.Config({"service_name": "foo"}).initialize_tracer()

In [4]: tracer.extract(Format.HTTP_HEADERS, {})

In [5]: print(tracer.extract(Format.HTTP_HEADERS, {}))
None

bdowning avatar Feb 13 '21 04:02 bdowning

Actually, seeing that backtrace above, I'm pretty suspicious about this code in extract too: https://github.com/DataDog/dd-trace-py/blob/master/ddtrace/opentracer/tracer.py#L328-L332

Just because I successfully extract a span context does not necessarily mean I will use it, so I'm not sure why it should be activated.

bdowning avatar Feb 13 '21 04:02 bdowning

Thank you @bdowning for reporting the issue. We will look into it and update here when we have a fix.

majorgreys avatar Feb 22 '21 15:02 majorgreys

Running into this (or something similar) as well:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/synapse/http/server.py", line 257, in _async_render_wrapper
    with trace_servlet(request, self._extract_context):
  File "/usr/local/lib/python3.8/contextlib.py", line 113, in __enter__
    return next(self.gen)
  File "/usr/local/lib/python3.8/site-packages/synapse/logging/opentracing.py", line 867, in trace_servlet
    scope = start_active_span_from_request(request, request_name, tags=request_tags)
  File "/usr/local/lib/python3.8/site-packages/synapse/logging/opentracing.py", line 503, in start_active_span_from_request
    context = opentracing.tracer.extract(opentracing.Format.HTTP_HEADERS, header_dict)
  File "/usr/local/lib/python3.8/site-packages/ddtrace/opentracer/tracer.py", line 329, in extract
    ot_span_ctx = propagator.extract(carrier)
  File "/usr/local/lib/python3.8/site-packages/ddtrace/opentracer/propagation/http.py", line 71, in extract
    raise SpanContextCorruptedException("failed to extract span context")

bradtgmurray avatar May 24 '21 22:05 bradtgmurray

@bradtgmurray This is my current set of ddtrace monkey-patches if it helps (for this issue and a few other things that bothered me):

import opentracing
from ddtrace.opentracer import Tracer
from ddtrace.opentracer.span import Span
from opentracing.ext import tags as OTTags

original_extract = Tracer.extract
original_log_kv = Span.log_kv
original_set_tag = Span.set_tag


def extract_wrapper(self, format, carrier):
    try:
        return original_extract(self, format, carrier)
    except opentracing.SpanContextCorruptedException:
        # Workaround for https://github.com/DataDog/dd-trace-py/issues/2030
        return None


def log_kv_wrapper(self, key_values, timestamp=None):
    # Get better error info into Datadog
    original_log_kv(self, key_values, timestamp)
    if key_values.get("event") == "error":
        try:
            exc_type = key_values["error.kind"]
            exc_val = key_values["error.object"]
            exc_tb = key_values["stack"]

            self._dd_span.set_exc_info(exc_type, exc_val, exc_tb)
        except KeyError:
            # welp
            pass
    return self


def set_tag_wrapper(self, key, value):
    original_set_tag(self, key, value)
    # keep actually logging db.statement
    if key == OTTags.DATABASE_STATEMENT:
        self._dd_span.set_tag(key, value)


Tracer.extract = extract_wrapper
Span.log_kv = log_kv_wrapper
Span.set_tag = set_tag_wrapper

bdowning avatar May 24 '21 23:05 bdowning