[BUG] Logging not working from other threads

[ManelBH]

Investigative information

Python version: 3.9.10 Core Tools Version: 4.0.4915 Function Runtime Version: 4.14.0.19631

Repro steps

dispatch a function that uses logging to a background thread

Expected behavior

The logged text appears in the logs

Actual behavior

The text isn't logged

Example:

import logging
from concurrent.futures import ThreadPoolExecutor
import azure.functions as func

def main(req: func.HttpRequest) -> func.HttpResponse:
    logging.info('Python HTTP trigger function processed a request.')

    with ThreadPoolExecutor() as pool:
        pool.submit(foo)

    return func.HttpResponse(
        "This HTTP triggered function executed successfully",
        status_code=200
    )

def foo():
    logging.info("Hello from foo")
    print("foo completed")

When I trigger this, In the console I can see "foo completed" but not "Hello from foo".

Contents of the requirements.txt file:

azure-functions==1.12.0

[ManelBH]

Related: https://github.com/Azure-Samples/fastapi-on-azure-functions/issues/11

[bhagyshricompany]

Thanks for reporting we will discuss this feature issue and update you on the inputs soon.

[Qmatteo]

@bhagyshricompany Any update on this?

[YunchuWang]

@Qmatteo we have looked and identified the cause, within python function worker there is a managed threadpoolexecutor which wraps cx's sync function by assigning function invocation id to thread_local. This does not apply to cx managed threadpoolexecutor and thread without function invocation id assigned will not be logged https://github.com/Azure/azure-functions-python-worker/blob/9a58193076e9b7b14990aa3fe09b5336b5c3db4c/azure_functions_worker/dispatcher.py#L713

we are working on the fix and will let you know

[asalogni]

@YunchuWang how long do you think it will take to fix the problem?

[bhagyshricompany]

@vrdmr please comment on this

[EvanR-Dev]

Hi, a potential fix is currently under review. Thank you for your patience, and we will keep you updated on this.

[Qmatteo]

@EvanR-Dev ok. Any ideas on the timeline? Coz I think that the PR must be reviewed, approved, completed and released. But right now we have some functions in production that we are not able to monitor since we don't see any logs

[EvanR-Dev]

I understand. It will be merged by the end of this week and part of the next release. The release will take time as we are doing hot fixes and could take by the end of March by the time it is finally out. We thank you for your patience once again.

[GiuseppeChiesa-TomTom]

has this fix been released?

[gavin-aguiar]

This fix will be released with runtime version 4.19. ETA mid-April

[Marco-Santoni]

Hi @gavin-aguiar ,

how can we track when the 4.19 is going live?

[gavin-aguiar]

@Marco-Santoni 4.19 is already deployed for dedicated plan in all regions. Consumption plan deployment has started and should be done in a week.

[Eusinho1985]

Investigative information

Python version: 3.9.10 Core Tools Version: 4.0.4915 Function Runtime Version: 4.14.0.19631

Repro steps

dispatch a function that uses logging to a background thread

Expected behavior

The logged text appears in the logs

Actual behavior

The text isn't logged

Example:

import logging
from concurrent.futures import ThreadPoolExecutor
import azure.functions as func

def main(req: func.HttpRequest) -> func.HttpResponse:
    logging.info('Python HTTP trigger function processed a request.')

    with ThreadPoolExecutor() as pool:
        pool.submit(foo)

    return func.HttpResponse(
        "This HTTP triggered function executed successfully",
        status_code=200
    )

def foo():
    logging.info("Hello from foo")
    print("foo completed")

When I trigger this, In the console I can see "foo completed" but not "Hello from foo".

Contents of the requirements.txt file:

azure-functions==1.12.0