Calling start_active_span from within asyncio co-routine

[bj00rn]

Requirement - what kind of business use case are you trying to solve?

New to opentracing. No specific requirement, just a question about using client within asyncioco-routine.

Problem - what in Jaeger blocks you from solving the requirement?

Experiencing erratic behaviour when calling start_active_span from within a asyncio co-routine.

Intermittent problems with Spans not being reported

Proposal - what do you suggest to solve the problem or improve the existing situation?

Any open questions to address

[floatliang]

hi, @bj00rn
opentracing provide a scopemanager called AsyncioScopeManager can handle it.
when you using it in a thread that does not have event loop it will fallback to ThreadLocalScopeManger，and when it will store current scope in current task ‘ACTIVE__ATTR' variable when there is a event loop in this thread.

[karlodwyer]

I ran into the same problem trying to instrument aiohttp.

import logging
from types import SimpleNamespace

import aiohttp
from aiohttp import ClientSession, web
from aiohttp.web_exceptions import HTTPException

import opentracing
from jaeger_client import Config
from opentracing.ext import tags
from opentracing.scope_managers.asyncio import AsyncioScopeManager

# Configure tracing client
config = Config(
    config={
        "sampler": {"type": "const", "param": 1},
        "local_agent": {"reporting_host": "localhost", "reporting_port": "6831"},
    },
    service_name="aiohttp_example",
    validate=True,
    scope_manager=AsyncioScopeManager(),
)

tracing_client = config.initialize_tracer()

# define middleware for aiohttp server to use
def opentracing_middleware_factory(app, opentracing_client):
    async def opentracing_middleware(app, handler):
        async def tracing(request):

            try:
                carrier = {}
                for key, value in request.headers.items():
                    carrier[key] = value
                parent_span = opentracing_client.extract(
                    format=Format.HTTP_HEADERS, carrier=carrier
                )
            except Exception as exception:
                parent_span = None

            with opentracing_client.start_span(
                "server_request", child_of=parent_span
            ) as active_span:

                response = None
                try:
                    response = await handler(request)
                except HTTPException as exception:
                    # Non 2XX responses are raised as HTTPExceptions
                    response = exception
                    active_span.set_tag(tags.HTTP_STATUS_CODE, response.status)
                    raise
                except Exception as exception:
                    # Store exception information including the stacktrace to the segment
                    response = None
                    active_span.set_tag(tags.HTTP_STATUS_CODE, 500)
                    raise
                finally:
                    if response is not None:
                        active_span.set_tag(tags.HTTP_STATUS_CODE, response.status)

                return response

        return tracing

    return opentracing_middleware

# aiohttp client tracing config.
def aiohttp_trace_config(tracing_client):
    async def on_request_start(session, context, params):
        tracing_client = opentracing.tracer
        parent_span = tracing_client.active_span

        child_span = tracing_client.start_span("client_span", child_of=parent_span)
        child_span.set_tag(tags.SPAN_KIND, tags.SPAN_KIND_RPC_CLIENT)
        child_span.set_tag(tags.HTTP_URL, str(params.url))
        child_span.set_tag(tags.HTTP_METHOD, params.method)

    async def on_request_end(session, context, params):
        tracing_client = opentracing.tracer
        # Active span is None so the rest of this code doesn't work
        active_span = tracing_client.active_span

        active_span.set_tag(tags.HTTP_STATUS_CODE, context.status)
        active_span.close()

    def _trace_config_ctx_factory(trace_request_ctx):
        return SimpleNamespace(name=None, tracing_client=tracing_client)

    trace_config = aiohttp.TraceConfig(
        trace_config_ctx_factory=_trace_config_ctx_factory
    )

    trace_config.on_request_start.append(on_request_start)
    trace_config.on_request_end.append(on_request_end)

    return trace_config


async def fetch(session):
    print("Query http://httpbin.org/get")
    async with session.get("http://httpbin.org/get") as resp:
        data = await resp.json()
    return data


async def handler(request):
    response = None
    async with ClientSession(
        trace_configs=[aiohttp_trace_config(tracing_client)]
    ) as session:
        response = await fetch(session)
    return web.json_response(response)


def init():
    app = web.Application()
    app.middlewares.append(opentracing_middleware_factory(app, tracing_client))
    app.router.add_get("/", handler)
    return app


web.run_app(init())

I'm seeing the same behaviour, I'm not sure if I am doing something wrong or there is an issue in with the context manager.

It looks like the span is okay in the server middleware, but the client trace config isn't able to access the active span.

[karlodwyer]

@bj00rn have you any other examples of this ?

[condorcet]

Hi @karlodwyer! In on_request_start method you create new span with start_span, but it's not active in this or children coroutines. My recommendation: 1) try start_active_span instead start_span or 2) add span to aiohttp context explicitly and then pop this span in on_request_end.
Also I assume that you should use start_active_span for your server middleware, else you will faced with similar problem. handler coroutine doesn't know about parent span now.

[karlodwyer]

Hi @condorcet, I tried that and I have a similar problem,

def aiohttp_trace_config(tracing_client):
    async def on_request_start(session, context, params):
        tracing_client = opentracing.tracer
        parent_span = tracing_client.active_span

        child_span = tracing_client.start_active_span(
            operation_name="client_span", child_of=parent_span, ignore_active_span=True
        )
        child_span.set_tag(tags.SPAN_KIND, tags.SPAN_KIND_RPC_CLIENT)
        child_span.set_tag(tags.HTTP_URL, str(params.url))
        child_span.set_tag(tags.HTTP_METHOD, params.method)

        context.request_span = child_span

throws an exception:
AttributeError: '_AsyncioScope' object has no attribute 'set_tag'

Any ideas or further guidance would be appreciated.

[condorcet]

@karlodwyer start_active_span returns instance of scope, not span. You should use span attribute of the scope.