Azure / azure-sdk-for-python

This repository is for active development of the Azure SDK for Python. For consumers of the SDK we recommend visiting our public developer docs at https://learn.microsoft.com/python/azure/ or our versioned developer docs at https://azure.github.io/azure-sdk-for-python.
MIT License
4.63k stars 2.83k forks source link

Azure Monitor Tracing Resource Warning when using tracer in fastapi with async dependency #29430

Closed cirezd closed 1 year ago

cirezd commented 1 year ago

Describe the bug Using the tracer to track a dependency manually results in Resource Warning and warning Overriding of current TracerProvider is not allowed. I am using the Azure Monitor package for telemetry in a fastAPI application that makes API calls, whereby the client is an async dependency. There is no other telemetry running. This is basically just the sample here https://github.com/Azure/azure-sdk-for-python/blob/main/sdk/monitor/azure-monitor-opentelemetry-exporter/samples/traces/sample_trace.py applied to a fastAPI app. I am using fastAPI version 0.92.

INFO:     Started reloader process [26395] using WatchFiles
Overriding of current TracerProvider is not allowed
INFO:     Started server process [26421]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
INFO:     127.0.0.1:57798 - "GET /docs HTTP/1.1" 200 OK
INFO:     127.0.0.1:57798 - "GET /openapi.json HTTP/1.1" 200 OK
INFO:     127.0.0.1:57798 - "GET / HTTP/1.1" 200 OK
^CINFO:     Shutting down
INFO:     Waiting for application shutdown.
INFO:     Application shutdown complete.
INFO:     Finished server process [26421]
sys:1: ResourceWarning: unclosed file <_io.TextIOWrapper name=0 mode='r' encoding='UTF-8'>
INFO:     Stopping reloader process [26395]

To Reproduce Steps to reproduce the behavior:

from azure.monitor.opentelemetry.exporter import AzureMonitorTraceExporter
from fastapi import Depends, FastAPI
from httpx import AsyncClient
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor

app = FastAPI()

trace.set_tracer_provider(TracerProvider())
tracer = trace.get_tracer(__name__)
exporter = AzureMonitorTraceExporter(
    connection_string="<ConnStr>"
)
span_processor = BatchSpanProcessor(exporter)
trace.get_tracer_provider().add_span_processor(span_processor)

async def get_client():
    async with AsyncClient() as client:
        yield client

@app.get("/")
async def read_root(client=Depends(get_client)):
    with tracer.start_as_current_span("read_root"):
        response = await client.get("https://httpbin.org/get")
        return response.json()

if __name__ == "__main__":
    import uvicorn

    uvicorn.run("telemetry_tests:app", port=8008, reload=True)

Expected behavior No error

Screenshots If applicable, add screenshots to help explain your problem.

Additional context Add any other context about the problem here.

kashifkhan commented 1 year ago

Thank you for the feedback @cirezd. We will investigate and get back to you asap.

ghost commented 1 year ago

Thank you for your feedback. This has been routed to the support team for assistance.

lzchen commented 1 year ago

@cirezd

Could you try installing https://pypi.org/project/azure-monitor-opentelemetry-exporter/ instead? Your current code is set up to use this exporter library. The library you are using currently is our all-inclusive "distro" offering which we recommend using a different api and is still in development.

cirezd commented 1 year ago

@lzchen You are right, I confused the packages. I actually had both installed (so many packages it gets confusing...).

I reinstalled azure-monitor-opentelemetry-exporter --pre and I still get the same error message.

lzchen commented 1 year ago

I can reproduce this if I execute this in VSCode. I believe the warning message is outputted because the TracerProvider is being set more than once. The line trace.set_tracer_provider(TracerProvider()) is being run once (when the Python file is interpreted), and then another time (when uvicorn.run("telemetry_tests:app", port=8008, reload=True)) is run in the subprocess. If you just run the Python file via uvicorn telemetry_tests:app --reload in the command line it should only run the trace.set_tracer_provider(TracerProvider()) once. If you still want to continue to execute this via VSCode debug, you can move that line, the exporter, the span processor lines in the if __name__ == "__main__": clause.

ghost commented 1 year ago

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @cijothomas, @reyang, @rajkumar-rangaraj, @TimothyMothra, @vishweshbankwar, @ramthi.

Issue Details
- **Package Name**: azure-monitor-opentelemetry-exporter --pre - **Package Version**: 1.0.0b10 - **Operating System**: ubuntu 20.04 (WSL2) - **Python Version**: 3.8.5 **Describe the bug** Using the tracer to track a dependency manually results in Resource Warning and warning `Overriding of current TracerProvider is not allowed`. I am using the Azure Monitor package for telemetry in a fastAPI application that makes API calls, whereby the client is an async dependency. There is no other telemetry running. This is basically just the sample here https://github.com/Azure/azure-sdk-for-python/blob/main/sdk/monitor/azure-monitor-opentelemetry-exporter/samples/traces/sample_trace.py applied to a fastAPI app. I am using fastAPI version 0.92. ```INFO: Uvicorn running on http://127.0.0.1:8008 (Press CTRL+C to quit) INFO: Started reloader process [26395] using WatchFiles Overriding of current TracerProvider is not allowed INFO: Started server process [26421] INFO: Waiting for application startup. INFO: Application startup complete. INFO: 127.0.0.1:57798 - "GET /docs HTTP/1.1" 200 OK INFO: 127.0.0.1:57798 - "GET /openapi.json HTTP/1.1" 200 OK INFO: 127.0.0.1:57798 - "GET / HTTP/1.1" 200 OK ^CINFO: Shutting down INFO: Waiting for application shutdown. INFO: Application shutdown complete. INFO: Finished server process [26421] sys:1: ResourceWarning: unclosed file <_io.TextIOWrapper name=0 mode='r' encoding='UTF-8'> INFO: Stopping reloader process [26395] ``` **To Reproduce** Steps to reproduce the behavior: ``` py from azure.monitor.opentelemetry.exporter import AzureMonitorTraceExporter from fastapi import Depends, FastAPI from httpx import AsyncClient from opentelemetry import trace from opentelemetry.sdk.trace import TracerProvider from opentelemetry.sdk.trace.export import BatchSpanProcessor app = FastAPI() trace.set_tracer_provider(TracerProvider()) tracer = trace.get_tracer(__name__) exporter = AzureMonitorTraceExporter( connection_string="" ) span_processor = BatchSpanProcessor(exporter) trace.get_tracer_provider().add_span_processor(span_processor) async def get_client(): async with AsyncClient() as client: yield client @app.get("/") async def read_root(client=Depends(get_client)): with tracer.start_as_current_span("read_root"): response = await client.get("https://httpbin.org/get") return response.json() if __name__ == "__main__": import uvicorn uvicorn.run("telemetry_tests:app", port=8008, reload=True) ``` **Expected behavior** No error **Screenshots** If applicable, add screenshots to help explain your problem. **Additional context** Add any other context about the problem here.
Author: cirezd
Assignees: lzchen
Labels: `question`, `Service Attention`, `customer-reported`, `Monitor - Exporter`
Milestone: -
cijothomas commented 1 year ago

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @cijothomas, @reyang, @rajkumar-rangaraj, @TimothyMothra, @vishweshbankwar, @ramthi.

Issue Details

Hello dear Bot. You are tagging the wrong people ;)

lzchen commented 1 year ago

@cijothomas

I fixed the CODEOWNERS file so you shouldn't be tagged anymore :)

cirezd commented 1 year ago

I can reproduce this if I execute this in VSCode. I believe the warning message is outputted because the TracerProvider is being set more than once. The line trace.set_tracer_provider(TracerProvider()) is being run once (when the Python file is interpreted), and then another time (when uvicorn.run("telemetry_tests:app", port=8008, reload=True)) is run in the subprocess. If you just run the Python file via uvicorn telemetry_tests:app --reload in the command line it should only run the trace.set_tracer_provider(TracerProvider()) once. If you still want to continue to execute this via VSCode debug, you can move that line, the exporter, the span processor lines in the if __name__ == "__main__": clause.

Thank you that indeed solves the issue of Overriding of current TracerProvider is not allowed. It also works if one puts the lines into a fastapi startup event. But in that case the error of sys:1: ResourceWarning: unclosed file <_io.TextIOWrapper name=0 mode='r' encoding='UTF-8'> remains.

lzchen commented 1 year ago

@cirezd If you are still getting errors, please paste the code snippet you are using.

ghost commented 1 year ago

Hi, we're sending this friendly reminder because we haven't heard back from you in a while. We need more information about this issue to help address it. Please be sure to give us your input within the next 7 days. If we don't hear back from you within 14 days of this comment the issue will be automatically closed. Thank you!