census-instrumentation / opencensus-python

A stats collection and distributed tracing framework
Apache License 2.0
669 stars 250 forks source link

OpenCensus threading extension not graceful in case of missing global tracer #1191

Open DRV2SI opened 1 year ago

DRV2SI commented 1 year ago

I ran into this situation in the context of Python Azure Functions, so I will stick to this context for explanation.

TL;DR

OpenCensus threading extension expects a global tracer to be present in execution_context; if it is absent, it will fail. In particular, it cannot deal with the situation that individual threads may use tracing, while others (especially the parent ones) don't.

Context

Currently, when running Python Azure functions, the tracing for the Azure SDK itself breaks when activated. This is covered elsewhere already, namely on azure-functions-python-worker, see here

I have looked into the issue and believe that the root cause should rather be fixed in opencensus-ext-threading, hence this bug report here. For description and reproducibility, please refer to the other ticket, no duplication needed.

Discussion

Upon analysis, I realised that the Azure Python Function worker itself does not instantiate a root OpenCensus tracer, i.e. one persisted in OpenCensus' execution_context. That by itself is completely fine, as opencensus-extension-azure-functions plucks the necessary contextual information from the context parameter and injects that into the tracer it creates. Note that also this tracer is only attached to context, which is subsequently passed into the Azure function main handler itself. So, altogether, it does not store the tracer at execution_contextat any point in time.

Now the problem arises because opencensus-ext-threading expects execution_contextto be populated with a tracer when new threads for multiprocessing are created. This is not the case for the aforementioned situation. Also, this cannot be fixed in "user code" (i.e. the Azure function itself), as the user code is executed after all logic from opencensus-ext-threading.

There are two ways to fix this:

I argue that the second solution should be preferred; there is no point to try to propagate the tracer if there is none. Note that it is generally absolutely fine to just instrument "user code" in the Azure Function without instrumenting the Python Worker itself. This is only possible if the threading extension can shortcut and refrain from passing on a (non-existing) tracer.

Consider def wrap_submit(submit_func): here

def wrap_submit(submit_func):
    """Wrap the apply_async function of multiprocessing.pools. Get the function
    that will be called and wrap it then add the opencensus context."""

    def call(self, func, *args, **kwargs):
        wrapped_func = wrap_task_func(func)
        _tracer = execution_context.get_opencensus_tracer()
        propagator = binary_format.BinaryFormatPropagator()

        wrapped_kwargs = {}
        wrapped_kwargs["span_context_binary"] = propagator.to_header(
            _tracer.span_context
        )
        wrapped_kwargs["kwds"] = kwargs
        wrapped_kwargs["sampler"] = _tracer.sampler
        wrapped_kwargs["exporter"] = _tracer.exporter
        wrapped_kwargs["propagator"] = _tracer.propagator

        return submit_func(self, wrapped_func, *args, **wrapped_kwargs)

    return call

This can easily be "fixed" by simply adding a check and cutting short in case no tracer is present:

def wrap_submit(submit_func):
    """Wrap the apply_async function of multiprocessing.pools. Get the function
    that will be called and wrap it then add the opencensus context."""

    def call(self, func, *args, **kwargs):
        _tracer = execution_context.get_opencensus_tracer()

        from opencensus.trace.tracers.noop_tracer import NoopTracer
        if isinstance(_tracer, NoopTracer):
            return submit_func(self, func, *args, **kwargs)

        wrapped_func = wrap_task_func(func)
        propagator = binary_format.BinaryFormatPropagator()

        wrapped_kwargs = {}
        wrapped_kwargs["span_context_binary"] = propagator.to_header(
            _tracer.span_context
        )

        wrapped_kwargs["kwds"] = kwargs
        wrapped_kwargs["sampler"] = _tracer.sampler
        wrapped_kwargs["exporter"] = _tracer.exporter
        wrapped_kwargs["propagator"] = _tracer.propagator

        return submit_func(self, wrapped_func, *args, **wrapped_kwargs)

    return call

The other thread creation methods can be fixed just in the very same way.

... I've had a long day and hope that I am still making sense. I am looking forward to your response!

macieyng commented 1 year ago

Hi 👋 I can confirm the issue and what you've investigated. We faced this issue like few weeks ago (probably at the same time as you), but didn't have a time to find a solution. Seems like #1192 is legit. Hi @lzchen - it's me again 😅 Can you take a look at what @DRV2SI described and solution for it?

DRV2SI commented 1 year ago

@lzchen push would you have time to look into it in the near future? While the analysis is somewhat extensive, the fix itself is not :)

lzchen commented 1 year ago

@jeremydvoss

DRV2SI commented 1 year ago

@lzchen @jeremydvoss