joerick/pyinstrument

Asyncio background tasks are added to total wall clock time

Opened this issue · 0 comments

When running profiler, it will show a request as the cumulative of all tasks - even ones run in the background. When looking at actual latency of the request, it will accurately represent the time. This is using the profiler as:

profiler = Profiler(async_mode="enabled")
profiler.start()
...
profiler.stop()
...

The output will look like:

Duration: 0.640     CPU time: 0.649
|- 0.320 task_1 (foreground)
    - ...
|- 0.320 task_2 (background task)

Actual measured latency: 0.321
Wall clock time should not include the background task total time since we are not awaiting it. I understand that pyinstrument follows the async context, but it doesn't seem like it is properly measuring the event loop itself.