Include _run_once duration in asyncio debug
Nobody has claimed this yet.
- Dominant language
- Python
- Stars
- 77.2k
- Forks
- 36k
- PR merge metrics
- PR metrics pending
Description
Feature or enhancement
In asyncio debug mode, log the duration of the asyncio iteration if it exceeds the slow_callback_duration (or a separate duration), as is done now for individual coroutine durations.
Pitch
This will capture when one eventloop iteration is slow, not just because one coroutine is blocking for a while, but because there might be several smaller tasks to process (e.g. 10 10ms operations in one tick blocks incoming operations just as much as one 100ms task, but nothing is logged, currently). It might be less actionable info if it doesn’t log the tasks, but it’s proved useful to us in the past as a more general diagnostic with other event loops (pre-asyncio tornado.IOLoop.set_blocking_log_threshold). This may be an indicator that a web worker is overloaded and more replicas are needed, for example, even if each individual task is handled quickly.
I see three possible versions of this:
- like slow coroutines, log only a single time for
_run_onceif it exceeds a threshold. This doesn't contain actionable info on its own other than 'things are slow' - add to 1. some summary information about the tasks (e.g. log total number and top N coroutines and durations if the sum of durations exceeds some threshold)
- replicate tornado's pre-asyncio set_blocking_log_threshold, which logs the stack when the time is crossed via
signal.setitimer. The nice thing about this is it can diagnose hangs, not just slowness, unlike after-complete timer logs. Only available wheresetitimeris also available, of course.
Previous discussion
Brought up originally on async-sig.
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start in Lib/asyncio/base_events.py around the existing slow-callback duration logging referenced in the issue, then review how _run_once is handled. The issue presents three possible designs, so first clarify which behavior should be implemented and what threshold and diagnostic output are expected. Done means an agreed debug-mode event-loop duration diagnostic with corresponding coverage.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- python
- Domain
- backend
- Issue type
- Feature
- Difficulty
- 5/5
- Estimated time
- Over a week
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 25/100