Azure Functions Python Logging from coroutines

[karpikpl]

When using coroutines, logs are not visible in the application insights.

There's a stack overflow answer on how to manage that https://stackoverflow.com/questions/55934085/how-to-redirect-logs-from-secondary-threads-in-azure-functions-using-python but it's outdated and not an official fix.

The solution using the thread local storage to assign invocationId works for traces but not dependencies, when open telemetry exporter is used. Is there a way to solve it also for other kids of telemetry?

Here's the repository: https://github.com/karpikpl/azure-functions-threads-logging

Can we include in the documentation, that when coroutines are used, logs won't be available?

---

Document Details

⚠ Do not edit this section. It is required for learn.microsoft.com ➟ GitHub issue linking.

• ID: 6cd61eed-2347-7a72-0d0a-67d9d582e26f
• Version Independent ID: 7be46f73-a54f-29c3-8a75-54a82f70d0b5
• Content: Improve throughput performance of Python apps in Azure Functions
• Content Source: articles/azure-functions/python-scale-performance-reference.md
• Service: azure-functions
• GitHub Login: @ggailey777
• Microsoft Alias: glenga

[karpikpl]

hey @lzchen would you know the answer for open telemetry? when I see logs in Application Insights, my traces have open operation id but all my dependencies (from coroutines) get new, unique operation ids

[AjayBathini-MSFT]

@karpikpl Thanks for your feedback! I've assigned this issue to the author who will investigate and update as appropriate.

[lzchen]

@karpikpl

I'm not too familiar if Azure functions provides mechanisms to pass information between threads but if you have access to context similarly to the stack overflow post, you can set the operation ids manually yourself like in this example. Note that the example is not exactly intended for the use case you outlined but the basic idea should still work.

[karpikpl]

I'm using that to pass in trace parent and trace state for open telemetry. This generally works until I have coroutines.

With the "solution" from stack overflow and setting thread local storage, I can get traces (logs) connected to same operation id.

It doesn't work for dependencies though.

[lzchen]

@karpikpl

I can't seem to find that login the repository you linked. Could you post a code a snippet of exactly how you are instrumenting with OpenTelemetry with your trace correlation logic?

[karpikpl]

sorry - I just noticed I forgot to push last changes :/

Code:

    with tracer.start_as_current_span(f"foo {st} operation", kind=trace.SpanKind.INTERNAL):

        tls.invocation_id = context.invocation_id

        logging.info(f"THREAD: Running thread for arg {st}")
        response = get('https://www.google.com')
        logging.info(f"THREAD: Thread {st} result: {response.status_code}")
        return context.invocation_id

Here's how it looks like in app insights - the dependency:

and the main operation:

the parent of the trace is not set, so they show up as disconnected operations

[lzchen]

Is invocation_Id the operationId that you want to be correlated with your log.info call that shows up in Trace? If log.info exists inside the start_as_current_span context manager, the Trace telemetry will be correlated with the Dependency that is type Internal as you see there.