Skip to content

fix: async profiler task names and blocking call detection - #67

Merged
JacobCoffee merged 5 commits into
mainfrom
fix/async-profiler-names-and-blocking
Oct 11, 2026
Merged

JacobCoffee merged 5 commits into
mainfrom
fix/async-profiler-names-and-blocking

Conversation

@JacobCoffee

Copy link
Copy Markdown
Owner

Fixes two bugs in the Async Profiler panel ahead of 1.1.0.

Task names always showed Task-N

asyncio.BaseEventLoop.create_task calls the installed task factory without the caller-supplied name, then applies the real name via tasks._set_task_name() only after the factory returns. TaskFactoryBackend recorded task.get_name() inside the factory call, so the 'created' event (which the timeline and task list display) always showed the auto-generated Task-N name instead of a name passed to create_task(..., name=...).

Fix: keep a live reference to each created task and resolve its current name from the task object when building stats, instead of trusting the name captured inside the factory call.

Blocking call detection never fired

BlockingCallDetector installed a custom loop exception handler and looked for an 'Executing ... took ... seconds' message in its context. CPython's event loop reports slow callbacks by calling logging.getLogger("asyncio").warning(...) directly from BaseEventLoop._run_once, never through call_exception_handler, so a real blocking call (e.g. time.sleep() inside an async handler) was never recorded and blocking_calls_count stayed 0.

Fix: attach a logging handler directly to the asyncio logger while installed, parse the slow-callback warning record for duration and source location, and remove the handler plus restore the logger level and loop debug state on uninstall so nothing leaks across requests.

Verification

  • New regression tests: tests/unit/test_async_profiler_taskfactory.py::test_task_name_reflects_create_task_name, tests/unit/test_async_profiler_detector.py (detects a real blocking call, no false positives, uninstall cleanup).
  • Both fixes verified on Python 3.10, 3.11, 3.12, 3.13, 3.14, 3.15, and under uvloop.
  • make ci passes (664 passed, 13 skipped).
  • Browser check against examples/litestar_advanced_alchemy /async-demo on port 8985: the Async panel now shows real task names (fast_task_1, slow_task_1, blocking_task, etc.) and a detected blocking call for the route's time.sleep(0.1).

asyncio's create_task() calls the installed task factory without the
caller-supplied name, then applies tasks._set_task_name() after the
factory returns. The factory therefore always saw name=None and
recorded the auto-generated Task-N name for the 'created' event, which
is what the timeline and task list display.

Keep a live reference to each created task and resolve its current
name from the task object when building stats, instead of trusting the
name captured inside the factory call. Verified on Python 3.10, 3.11,
3.12, 3.13, 3.14, 3.15 and under uvloop.
BlockingCallDetector installed a custom loop exception handler and
looked for an 'Executing ... took ... seconds' message in its context,
but CPython's event loop reports slow callbacks by calling
logging.getLogger('asyncio').warning(...) directly from
BaseEventLoop._run_once, never through call_exception_handler. As a
result, a real blocking call (e.g. time.sleep inside an async handler)
was never recorded and blocking_calls_count stayed 0.

Attach a logging.Handler directly to the 'asyncio' logger while
installed, parse the slow-callback warning record for the duration and
source location, and remove the handler plus restore the logger level
and loop debug state on uninstall so nothing leaks across requests.
Verified on Python 3.10, 3.11, 3.12, 3.13, 3.14, 3.15 and under
uvloop.
Copilot AI balanced review requested due to automatic review settings October 11, 2026 01:05

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copilot was unable to review this pull request because the user who requested the review has reached their quota limit.

@github-actions

github-actions Bot commented Oct 11, 2026 •

Copy link
Copy Markdown
Contributor
PR Preview Action v1.8.1

QR code for preview link

🚀 View preview at
https://JacobCoffee.github.io/debug-toolbar/pr-preview/pr-67/

Built to branch gh-pages at 2026-10-11 01:38 UTC.
Preview will be ready when the GitHub Pages deployment is complete.

…ing detectors

BlockingCallDetector.install()/uninstall() saved and restored the
loop's debug mode, slow_callback_duration, and the asyncio logger
level directly. With two overlapping requests on the same loop, the
first detector to uninstall would reset debug mode to its pre-install
value while the second detector was still running (breaking its
detection), and the second detector's uninstall would then restore
whatever the first detector had captured, permanently changing the
loop's debug mode and the asyncio logger's level after both requests
finished.

Track the patched loop state in a refcounted, per-loop structure
(keyed by a WeakKeyDictionary so it never outlives the loop): the
first install on a loop captures the original debug/duration/logger
level and the last uninstall restores them; slow_callback_duration is
kept at the minimum of all currently active thresholds so every
installed detector still gets notified. Each detector keeps its own
log handler and now filters incoming slow-callback records against its
own threshold, since the shared slow_callback_duration may be lower
than that threshold. The asyncio logger's level is only raised to
WARNING when it is currently more restrictive (e.g. ERROR); a level
that is already more verbose (e.g. DEBUG) is left untouched.

Added tests for two overlapping detectors uninstalled in order and for
the logger-level raise-only behavior.
Copilot AI balanced review requested due to automatic review settings October 11, 2026 01:10

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copilot was unable to review this pull request because the user who requested the review has reached their quota limit.

@JacobCoffee
JacobCoffee enabled auto-merge (squash) October 11, 2026 01:11
Copilot AI balanced review requested due to automatic review settings October 11, 2026 01:38

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copilot was unable to review this pull request because the user who requested the review has reached their quota limit.

Copilot AI balanced review requested due to automatic review settings October 11, 2026 01:38

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copilot was unable to review this pull request because the user who requested the review has reached their quota limit.

@JacobCoffee
JacobCoffee merged commit b71a105 into main Oct 11, 2026
24 checks passed
@JacobCoffee
JacobCoffee deleted the fix/async-profiler-names-and-blocking branch October 11, 2026 01:44
JacobCoffee added a commit that referenced this pull request Oct 11, 2026
PR #64 made the FastAPI dependency injection panel actually populate
resolved_dependencies for nested Depends() trees; assert on the real
dependency names (get_db, get_current_user, get_token) and counts
instead of only checking the panel key exists.

PR #67 made the async profiler's taskfactory backend report the real
caller-supplied task name (previously always 'Task-N') and made
blocking call detection actually fire (previously silent, since
asyncio logs slow callbacks via the asyncio logger rather than
call_exception_handler). Assert on the real task names and a real
detected blocking call instead of working around both bugs.
JacobCoffee added a commit that referenced this pull request Oct 11, 2026
* fix: cascade-delete posts when deleting a user in advanced-alchemy example

DELETE /api/users/{id} raised a 500 IntegrityError for any user with
posts, since the default relationship behaviour nulls out the foreign
key instead of deleting dependents, and Post.author_id is non-nullable.
Found while writing tests for the example app.

* test: add full test coverage for example apps

Add tests/examples/ covering every app under examples/: asgi_basic,
litestar_basic, litestar_advanced_alchemy, starlette_basic,
fastapi_basic, websocket_panel_example, graphql_panel_example,
mcp_server_example, and the standalone panel demo scripts (cache,
templates, settings, profiling, memory, flamegraph, async_profiler,
alerts).

Each app is exercised through its own framework's real test client:
documented routes are checked for status/content-type, toolbar HTML
injection and static assets, and the per-request panel data the
example is built to demonstrate (SQL N+1 detection, GraphQL resolver
tracking, websocket connection stats, async profiler stats, and so
on).

A shared tests/examples/conftest.py fixture (import_example) imports
each example fresh per test and evicts it afterwards, since several
examples build module-level toolbar/app singletons at import time.

Add make test-examples to run just this suite.

* ci: add weekly workflow to test examples against latest dependencies

Runs tests/examples against uv sync --all-extras --upgrade (ignoring
the lockfile pins) on the oldest and newest supported Python versions,
on a weekly schedule, workflow_dispatch, and PRs touching examples/ or
tests/examples/. Prints resolved versions of the key frameworks for
debugging. Not part of the required CI Success aggregator.

Confirmed this actually catches regressions: with mcp upgraded past
2.0, debug_toolbar.mcp.server fails to import because mcp 2.x renamed
FastMCP to MCPServer, which this workflow surfaces as a test failure
in tests/examples/test_mcp_server_example.py.

* test: exercise the real example scripts instead of replicating panel logic

The standalone panel demo tests previously had a second test per
script that reconstructed the same DebugToolbar/Panel/Config objects
the script's main() builds, independent of the script itself. That
let a broken script (e.g. a renamed import, wrong panel class, wrong
config key) pass the test suite as long as the underlying panel class
still worked when built directly.

Replace those with a single test per script that imports the module
and calls its real main() (or free functions, for cache_panel_demo),
capturing real printed output and asserting on specific computed
values (counts, ratios, byte totals, timings, redacted fields) that
would change if the panel actually broke.

Also widen examples-latest.yml's pull_request trigger to include
src/** and pyproject.toml, since a library change (not just an
examples/tests change) can break examples against upgraded
dependencies.

* test: rebase asgi_basic tests onto the merged PR #61 fix

PR #61 made the asgi_basic example inject the toolbar markup into HTML
responses, serve /_debug_toolbar/static/{toolbar.css,toolbar.js}, and
move its JSON endpoints to /_debug_toolbar/api/requests(/<id>). Flip
the tests that previously asserted the pre-fix absence of these
behaviors to assert the real, now-fixed behavior instead.

* test: assert real behavior now fixed by PR #64 and #67

PR #64 made the FastAPI dependency injection panel actually populate
resolved_dependencies for nested Depends() trees; assert on the real
dependency names (get_db, get_current_user, get_token) and counts
instead of only checking the panel key exists.

PR #67 made the async profiler's taskfactory backend report the real
caller-supplied task name (previously always 'Task-N') and made
blocking call detection actually fire (previously silent, since
asyncio logs slow callbacks via the asyncio logger rather than
call_exception_handler). Assert on the real task names and a real
detected blocking call instead of working around both bugs.

* test: drop comparison of shortened task ids in async profiler example test
@JacobCoffee JacobCoffee mentioned this pull request Oct 11, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants