Datadog spans lost in python thread pool

Viewed 920

I have a function that runs in a thread pool, but it only shows up in the Datadog tracing UI when I run it outside of my threadpool. In the screenshot below you can see it show up in sync_work but not in async_work.

enter image description here

Here is my code, contained in a script called ddtrace_threadpool_example.py:

from concurrent.futures import ThreadPoolExecutor
from ddtrace import tracer
from random import random
import time


def perform_work(input_value):
    with tracer.trace('do_something') as _:
        seconds = random()
        time.sleep(seconds)
        return input_value**2


def sync_work(input_values):
    with tracer.trace('sync_work') as _:
        results = []
        for input_value in input_values:
            result = perform_work(input_value=input_value)
            results.append(result)
        return results


def async_work(input_values):
    with tracer.trace('async_work') as _:
        thread_pool = ThreadPoolExecutor(max_workers=10)
        futures = thread_pool.map(
            lambda input_value:
            perform_work(input_value=input_value),
            input_values
        )
        results = list(futures)
        return results


@tracer.wrap(service='ddtrace-example')
def start_work():
    input_values = list(range(15))
    sync_results = sync_work(input_values=input_values)
    print(sync_results)
    async_results = async_work(input_values=input_values)
    print(async_results)


if __name__ == '__main__':
    start_work()

I run the script like this: python ddtrace_threadpool_example.py. I'm using Python 3.7, and pip freeze shows ddtrace==0.29.0.

1 Answers

After talking with Datadog support, it seems like this is a known issue.

Thanks for your patience while we looked into this issue. We we're currently investigating this along with PoolExecutors and will reach out with updates. Right now it looks like those child spans within the async call lose context, so they appear disconnected.

The workaround for now is to pass in the parent's context. Add this line just before calling the thread pool executor.

current_context = tracer.get_call_context()

Then pass that context to the function that gets run in the threadpool:

perform_work(
    input_value=input_value,
    parent_context=current_context
)

And use it to create a span inside the function like this:

span = tracer.start_span('do_something', child_of=parent_context)
seconds = random()
time.sleep(seconds)
span.finish()

The complete example looks like this:

from concurrent.futures import ThreadPoolExecutor
from ddtrace import tracer
from random import random
import time


def perform_work(input_value, parent_context=None):
    span = tracer.start_span('do_something', child_of=parent_context)
    seconds = random()
    time.sleep(seconds)
    span.finish()
    return input_value ** 2


def sync_work(input_values):
    with tracer.trace('sync_work') as _:
        results = []
        for input_value in input_values:
            result = perform_work(input_value=input_value)
            results.append(result)
        return results


def async_work(input_values):
    with tracer.trace('async_work') as _:
        current_context = tracer.get_call_context()
        thread_pool = ThreadPoolExecutor(max_workers=10)
        futures = thread_pool.map(
            lambda input_value:
            perform_work(
                input_value=input_value,
                parent_context=current_context
            ),
            input_values
        )
        results = list(futures)
        return results


@tracer.wrap(service='ddtrace-example')
def start_work():
    input_values = list(range(15))
    sync_results = sync_work(input_values=input_values)
    print(sync_results)
    async_results = async_work(input_values=input_values)
    print(async_results)


if __name__ == '__main__':
    start_work()

This will produce a result that looks like this:

enter image description here

Related