python / python/cpython

Include _run_once duration in asyncio debug

Open
#101,946 0 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

stdlib topic-asyncio type-feature
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:

  1. like slow coroutines, log only a single time for _run_once if it exceeds a threshold. This doesn't contain actionable info on its own other than 'things are slow'
  2. 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)
  3. 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 where setitimer is also available, of course.

Previous discussion

Brought up originally on async-sig.

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. 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

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.