Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ddtrace masks asyncio debug logs #10975

Open
j-dutton-alphasights opened this issue Oct 8, 2024 · 2 comments · May be fixed by #12011
Open

ddtrace masks asyncio debug logs #10975

j-dutton-alphasights opened this issue Oct 8, 2024 · 2 comments · May be fixed by #12011
Assignees
Labels
Tracing Distributed Tracing

Comments

@j-dutton-alphasights
Copy link

I'm looking to use asyncio debug mode to understand some issues with blocked event loops. The way that ddtrace patches asyncio leads to the name of each coroutine being masked.

Here's an example of the logs I get out without ddtrace:

Executing <Task finished name='Task-1' coro=<my_function() done, defined at /app/src/block.py:5> result=None created at /usr/lib64/python3.12/asyncio/runners.py:100> took 2.002 seconds

And with ddtrace-run:

Executing <Task finished name='Task-1' coro=<_wrapped_create_task_py37.<locals>.traced_coro() done, defined at /usr/local/lib64/python3.12/site-packages/ddtrace/contrib/asyncio/patch.py:47> result=None created at /usr/local/lib64/python3.12/site-packages/ddtrace/contrib/asyncio/patch.py:53> took 2.008 seconds

Note the _wrapped_create_task_py37.<locals>.traced_coro() is really unhelpful here, and I'd much rather see the reference to the original function.

Here's the minimal example:

test.py:

async def my_function():
    time.sleep(2)


if __name__ == "__main__":
    asyncio.run(my_function())

Run with: PYTHONASYNCIODEBUG=1 ddtrace-run python3 test.py.

@mabdinur mabdinur self-assigned this Oct 22, 2024
@mabdinur mabdinur added the Tracing Distributed Tracing label Oct 22, 2024
@github-actions github-actions bot added the stale label Dec 22, 2024
@serensoner
Copy link

hey @mabdinur do you have any workaround for this?

@github-actions github-actions bot removed the stale label Jan 16, 2025
@mabdinur mabdinur linked a pull request Jan 21, 2025 that will close this issue
2 tasks
@mabdinur
Copy link
Contributor

mabdinur commented Jan 21, 2025

Hey @serensoner

Sorry about the delay.

I see that you're using python3.12. Do you know if your application is setting an asyncio task factory or using the default eager-task-factory (ie: does this assertion pass: task_factory = asyncio.get_event_loop().get_task_factory(); assert task_factory is None and PY_VERSION >= (3, 12) or task_factory is asyncio.eager_task_factory). If this assertion passes then you can safely disable the asyncio integration by setting the following environment variable: DD_TRACE_ASYNCIO_ENABLED=False

Context

The asyncio integration ensures trace info is propagated when an asyncio task is created. When this integration is disabled trace info will always be propagated when the task is executed. In python3.12 asyncio tasks begin execution when a task is constructed (this is the default behavior but it can be overridden).

Next Steps

I opened a fix to ensure the name of coroutine is not overwritten by ddtrace. However the filename in created at and will still reference ddtrace but defined at should reference the original source.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Tracing Distributed Tracing
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants