From c9a60458c39b16a93928c8e9d386febfff2f6713 Mon Sep 17 00:00:00 2001 From: Jacob Coffee Date: Sat, 10 Oct 2026 19:34:24 -0500 Subject: [PATCH 1/4] fix: populate FastAPI dependency injection panel with real resolutions The Dependencies panel always showed zero resolved dependencies, even on routes using Depends(). Nothing ever called the tracking hooks, and the fallback population step ran after the request context had already been cleared and the toolbar had stored its (empty) snapshot. Wrap FastAPI's internal solve_dependencies to record each Depends() resolution (name, type, cache hit, duration) as it happens, and write it straight into the live request context instead of deferring to a step that runs too late. Verified with a new integration test and manually against examples/fastapi_basic, where routes using get_db/get_token/ get_current_user now show up in the Dependencies panel. --- src/debug_toolbar/fastapi/middleware.py | 71 ++++++++++++++----- .../test_fastapi_dependencies_panel.py | 51 +++++++++++++ tests/unit/fastapi/test_middleware.py | 25 +++---- 3 files changed, 117 insertions(+), 30 deletions(-) create mode 100644 tests/integration/test_fastapi_dependencies_panel.py diff --git a/src/debug_toolbar/fastapi/middleware.py b/src/debug_toolbar/fastapi/middleware.py index 7ade888..1dcc530 100644 --- a/src/debug_toolbar/fastapi/middleware.py +++ b/src/debug_toolbar/fastapi/middleware.py @@ -23,6 +23,48 @@ _dependency_cache_stats: ContextVar[dict[str, int] | None] = ContextVar("dependency_cache_stats", default=None) +def _install_dependency_instrumentation() -> None: + """Monkeypatch FastAPI's dependency solver to record each resolved dependency. + + FastAPI resolves ``Depends()`` callables internally with no public hook for + observing resolutions, so this wraps ``solve_dependencies`` (both where it is + defined and where ``fastapi.routing`` imported it) to capture each dependency + resolution into the request-scoped tracking contextvars. + """ + import time as time_module + + from fastapi.dependencies import utils as fastapi_dependency_utils + + from fastapi import routing as fastapi_routing + + if fastapi_dependency_utils.solve_dependencies.__name__ == "instrumented_solve_dependencies": + return + + original_solve_dependencies = fastapi_dependency_utils.solve_dependencies + + async def instrumented_solve_dependencies(*, request: Any, dependant: Any, **kwargs: Any) -> Any: + depth_key = "_debug_toolbar_dependency_depth" + depth = request.scope.get(depth_key, 0) + 1 + request.scope[depth_key] = depth + dependency_cache = kwargs.get("dependency_cache") or {} + already_cached = dependant.cache_key in dependency_cache + start = time_module.perf_counter() + try: + result = await original_solve_dependencies(request=request, dependant=dependant, **kwargs) + finally: + request.scope[depth_key] = depth - 1 + + # depth == 1 is the route handler's own top-level dependant, not a Depends(). + if depth > 1 and dependant.call is not None and _dependency_tracking.get() is not None: + duration_ms = (time_module.perf_counter() - start) * 1000 + track_dependency(dependant.call, cached=already_cached, duration_ms=duration_ms) + + return result + + fastapi_dependency_utils.solve_dependencies = instrumented_solve_dependencies # type: ignore[invalid-assignment] + fastapi_routing.solve_dependencies = instrumented_solve_dependencies # type: ignore[invalid-assignment] + + def get_dependency_tracking() -> list[dict[str, Any]]: """Get the current dependency tracking list.""" tracking = _dependency_tracking.get() @@ -83,6 +125,13 @@ def record_dependency_resolution( else: stats["misses"] += 1 + context = get_request_context() + if context is not None: + context.metadata.setdefault( + "dependencies", + {"resolved": tracking, "tree": {}, "cache_stats": stats}, + ) + class DebugToolbarMiddleware(StarletteMiddleware): """FastAPI-specific middleware for the debug toolbar. @@ -107,6 +156,9 @@ def __init__( super().__init__(app, config, toolbar) self.fastapi_config = config + if config.track_dependency_injection: + _install_dependency_instrumentation() + async def __call__(self, scope: Scope, receive: Receive, send: Send) -> None: """Process an ASGI request with dependency tracking.""" if scope["type"] != "http": @@ -117,24 +169,7 @@ async def __call__(self, scope: Scope, receive: Receive, send: Send) -> None: _dependency_tracking.set([]) _dependency_cache_stats.set({"hits": 0, "misses": 0, "total": 0}) - try: - await super().__call__(scope, receive, send) - finally: - if self.fastapi_config.track_dependency_injection: - context = get_request_context() - if context is not None: - self._populate_dependency_metadata(context) - - def _populate_dependency_metadata(self, context: Any) -> None: - """Populate dependency tracking data into the context.""" - tracking = _dependency_tracking.get() - stats = _dependency_cache_stats.get() - - context.metadata["dependencies"] = { - "resolved": tracking, - "tree": {}, - "cache_stats": stats, - } + await super().__call__(scope, receive, send) def track_dependency( diff --git a/tests/integration/test_fastapi_dependencies_panel.py b/tests/integration/test_fastapi_dependencies_panel.py new file mode 100644 index 0000000..ccc43c6 --- /dev/null +++ b/tests/integration/test_fastapi_dependencies_panel.py @@ -0,0 +1,51 @@ +"""Integration tests for the FastAPI dependency injection panel.""" + +from __future__ import annotations + +from typing import Annotated + +from fastapi.testclient import TestClient + +from debug_toolbar.fastapi import FastAPIDebugToolbarConfig, setup_debug_toolbar +from fastapi import Depends, FastAPI + + +def get_settings() -> dict: + return {"debug": True} + + +def get_current_user(settings: Annotated[dict, Depends(get_settings)]) -> dict: + return {"id": 1, "debug": settings["debug"]} + + +def make_app() -> tuple[FastAPI, object]: + app = FastAPI() + config = FastAPIDebugToolbarConfig(enabled=True, track_dependency_injection=True) + toolbar = setup_debug_toolbar(app, config) + + @app.get("/users/me") + def read_current_user(user: Annotated[dict, Depends(get_current_user)]) -> dict: + return user + + return app, toolbar + + +class TestDependenciesPanelIntegration: + def test_resolved_dependencies_populated_for_depends_route(self) -> None: + """A route using Depends() must report non-empty resolved_dependencies.""" + app, toolbar = make_app() + client = TestClient(app) + + response = client.get("/users/me") + assert response.status_code == 200 + + _request_id, data = toolbar.storage.get_all()[0] + panel_stats = data["panel_data"]["DependencyInjectionPanel"] + + resolved = panel_stats["resolved_dependencies"] + assert resolved != [] + + names = {dep["name"] for dep in resolved} + assert "get_current_user" in names + assert "get_settings" in names + assert panel_stats["total_count"] == len(resolved) diff --git a/tests/unit/fastapi/test_middleware.py b/tests/unit/fastapi/test_middleware.py index a78249b..4e202e9 100644 --- a/tests/unit/fastapi/test_middleware.py +++ b/tests/unit/fastapi/test_middleware.py @@ -2,7 +2,7 @@ from __future__ import annotations -from unittest.mock import AsyncMock, MagicMock +from unittest.mock import AsyncMock import pytest @@ -166,21 +166,22 @@ async def test_call_non_http(self) -> None: await middleware(scope, receive, send) - def test_populate_dependency_metadata(self) -> None: - """Should populate dependency metadata into context.""" + def test_record_dependency_resolution_syncs_live_context(self) -> None: + """record_dependency_resolution must sync into the active request context immediately.""" + from debug_toolbar.core import RequestContext, set_request_context from debug_toolbar.fastapi.middleware import _dependency_cache_stats, _dependency_tracking - _dependency_tracking.set([{"name": "get_db", "type": "function", "cached": False, "duration_ms": 1.0}]) - _dependency_cache_stats.set({"hits": 0, "misses": 1, "total": 1}) - - app = AsyncMock() - middleware = DebugToolbarMiddleware(app) - - context = MagicMock() - context.metadata = {} + _dependency_tracking.set([]) + _dependency_cache_stats.set({"hits": 0, "misses": 0, "total": 0}) - middleware._populate_dependency_metadata(context) + context = RequestContext() + set_request_context(context) + try: + record_dependency_resolution("get_db", "function", cached=False, duration_ms=1.0) + finally: + set_request_context(None) assert "dependencies" in context.metadata assert len(context.metadata["dependencies"]["resolved"]) == 1 + assert context.metadata["dependencies"]["resolved"][0]["name"] == "get_db" assert context.metadata["dependencies"]["cache_stats"]["total"] == 1 From f8ac528d47cf550ee91598a178212ff0fc94f928 Mon Sep 17 00:00:00 2001 From: Jacob Coffee Date: Sat, 10 Oct 2026 19:47:43 -0500 Subject: [PATCH 2/4] fix: measure real dependency execution time, not resolution of its own sub-deps The previous duration_ms only timed solving each dependency's OWN sub-dependencies (the recursive solve_dependencies call), not the actual invocation of the dependency itself, which FastAPI runs afterwards in the parent's loop. Time the real call instead, per dependency kind: - sync functions/classes: wrap run_in_threadpool, the only place FastAPI invokes them from within solve_dependencies. - generator dependencies (e.g. yield-based DB sessions): wrap _solve_generator, which performs the actual context-manager enter. - cached resolutions: report duration_ms=0.0 directly, since FastAPI never re-invokes them. - coroutine-function dependencies: FastAPI awaits them inline with no interceptable call site, so duration_ms is reported as None rather than measuring the wrong thing. These internals changed shape across FastAPI releases (cache_key moved from a Dependant property to a module-level _get_cache_key() helper, and the is_*_callable attributes were later dropped entirely), so instrumentation now probes for the exact attributes it needs and no-ops safely when they are absent, instead of crashing requests. Verified: - New tests assert sync/generator dependencies report real elapsed time (>= a 50ms sleep) and coroutine dependencies report None. - Manually checked fastapi==0.100.0 (declared floor) and fastapi==0.143.0 (latest release): both run requests successfully with the panel gracefully empty, since neither matches the instrumented shape. fastapi==0.123.0 (this repo's pinned version) gets full, accurate per-dependency timing. - make ci passes; verified in browser against examples/fastapi_basic. --- src/debug_toolbar/fastapi/middleware.py | 150 +++++++++++++++--- .../fastapi/panels/dependencies.py | 2 +- .../test_fastapi_dependencies_panel.py | 67 ++++++++ 3 files changed, 194 insertions(+), 25 deletions(-) diff --git a/src/debug_toolbar/fastapi/middleware.py b/src/debug_toolbar/fastapi/middleware.py index 1dcc530..8f02393 100644 --- a/src/debug_toolbar/fastapi/middleware.py +++ b/src/debug_toolbar/fastapi/middleware.py @@ -23,46 +23,146 @@ _dependency_cache_stats: ContextVar[dict[str, int] | None] = ContextVar("dependency_cache_stats", default=None) -def _install_dependency_instrumentation() -> None: - """Monkeypatch FastAPI's dependency solver to record each resolved dependency. - - FastAPI resolves ``Depends()`` callables internally with no public hook for - observing resolutions, so this wraps ``solve_dependencies`` (both where it is - defined and where ``fastapi.routing`` imported it) to capture each dependency - resolution into the request-scoped tracking contextvars. +def _dependency_internals_supported(fastapi_dependency_utils: Any, dependant_cls: Any) -> bool: + """Check whether the FastAPI internals this instrumentation relies on are present. + + FastAPI has reshaped these internals more than once (e.g. moving + ``Dependant.cache_key`` to a module-level ``_get_cache_key()`` helper and + dropping ``is_coroutine_callable``/``is_gen_callable``/``is_async_gen_callable`` + in later releases); both the older and newer ``cache_key`` shapes are accepted, + but the callable-kind attributes must still be present. """ - import time as time_module - - from fastapi.dependencies import utils as fastapi_dependency_utils + has_cache_key_support = hasattr(dependant_cls, "cache_key") or hasattr(fastapi_dependency_utils, "_get_cache_key") + has_callable_kind_support = all( + hasattr(dependant_cls, attr) + for attr in ("is_coroutine_callable", "is_gen_callable", "is_async_gen_callable", "use_cache") + ) + return has_cache_key_support and has_callable_kind_support and hasattr(fastapi_dependency_utils, "_solve_generator") - from fastapi import routing as fastapi_routing - if fastapi_dependency_utils.solve_dependencies.__name__ == "instrumented_solve_dependencies": - return - - original_solve_dependencies = fastapi_dependency_utils.solve_dependencies +def _make_instrumented_solve_dependencies(original: Any, dependant_cache_key: Any) -> Any: + """Build the ``solve_dependencies`` wrapper: tracks tree depth, and records + cached/coroutine-function resolutions directly since they have no other + interceptable call site. + """ async def instrumented_solve_dependencies(*, request: Any, dependant: Any, **kwargs: Any) -> Any: depth_key = "_debug_toolbar_dependency_depth" depth = request.scope.get(depth_key, 0) + 1 request.scope[depth_key] = depth dependency_cache = kwargs.get("dependency_cache") or {} - already_cached = dependant.cache_key in dependency_cache - start = time_module.perf_counter() + already_cached = bool(dependant.use_cache) and dependant_cache_key(dependant) in dependency_cache try: - result = await original_solve_dependencies(request=request, dependant=dependant, **kwargs) + result = await original(request=request, dependant=dependant, **kwargs) finally: request.scope[depth_key] = depth - 1 # depth == 1 is the route handler's own top-level dependant, not a Depends(). if depth > 1 and dependant.call is not None and _dependency_tracking.get() is not None: - duration_ms = (time_module.perf_counter() - start) * 1000 - track_dependency(dependant.call, cached=already_cached, duration_ms=duration_ms) + if already_cached: + track_dependency(dependant.call, cached=True, duration_ms=0.0) + elif dependant.is_coroutine_callable: + track_dependency(dependant.call, cached=False, duration_ms=None) + # Sync functions/classes are timed via run_in_threadpool; generator + # dependencies are timed via _solve_generator. return result + return instrumented_solve_dependencies + + +def _make_instrumented_run_in_threadpool(original: Any, time_module: Any) -> Any: + """Build the ``run_in_threadpool`` wrapper that times sync function/class dependencies.""" + + async def instrumented_run_in_threadpool(func: Any, *args: Any, **kwargs: Any) -> Any: + start = time_module.perf_counter() + try: + return await original(func, *args, **kwargs) + finally: + if _dependency_tracking.get() is not None: + duration_ms = (time_module.perf_counter() - start) * 1000 + track_dependency(func, cached=False, duration_ms=duration_ms) + + return instrumented_run_in_threadpool + + +def _make_instrumented_solve_generator(original: Any, time_module: Any) -> Any: + """Build the ``_solve_generator`` wrapper that times generator-based dependencies.""" + + async def instrumented_solve_generator(*, dependant: Any, stack: Any, sub_values: Any) -> Any: + start = time_module.perf_counter() + try: + return await original(dependant=dependant, stack=stack, sub_values=sub_values) + finally: + if dependant.call is not None and _dependency_tracking.get() is not None: + duration_ms = (time_module.perf_counter() - start) * 1000 + track_dependency(dependant.call, cached=False, duration_ms=duration_ms) + + return instrumented_solve_generator + + +def _install_dependency_instrumentation() -> None: + """Monkeypatch FastAPI's dependency solver to record each resolved dependency. + + FastAPI resolves ``Depends()`` callables internally with no public hook for + observing resolutions, so this wraps three of its internals: + + - ``solve_dependencies`` (both where it is defined and where ``fastapi.routing`` + imported it): tracks tree depth and records cached resolutions directly, since + cached dependencies are never actually re-invoked. + - ``run_in_threadpool``: times plain sync function/class dependencies, which + FastAPI invokes through it. + - ``_solve_generator``: times generator-based dependencies (e.g. ``yield`` based + session managers), which FastAPI invokes through it. + + Coroutine-function dependencies are awaited inline inside ``solve_dependencies`` + with no interceptable call site, so their duration is reported as ``None`` + rather than measuring the wrong thing. + + These internals only exist in this shape between FastAPI 0.121 and some later + releases that reshaped them again; see ``_dependency_internals_supported``. On + unsupported versions this is a no-op and the panel stays empty, same as before + this fix. + """ + import time as time_module + + from fastapi.dependencies import utils as fastapi_dependency_utils + from fastapi.dependencies.models import Dependant as FastAPIDependant + + from fastapi import routing as fastapi_routing + + if fastapi_dependency_utils.solve_dependencies.__name__ == "instrumented_solve_dependencies": + return + + if not _dependency_internals_supported(fastapi_dependency_utils, FastAPIDependant): + logger.debug( + "FastAPI dependency injection tracking requires internals introduced in " + "FastAPI 0.121; skipping instrumentation for this FastAPI version." + ) + return + + get_cache_key = getattr(fastapi_dependency_utils, "_get_cache_key", None) + + def dependant_cache_key(dependant: Any) -> Any: + if get_cache_key is not None: + return get_cache_key(dependant=dependant) + return dependant.cache_key + + instrumented_solve_dependencies = _make_instrumented_solve_dependencies( + fastapi_dependency_utils.solve_dependencies, dependant_cache_key + ) + instrumented_run_in_threadpool = _make_instrumented_run_in_threadpool( + fastapi_dependency_utils.run_in_threadpool, time_module + ) + instrumented_solve_generator = _make_instrumented_solve_generator( + fastapi_dependency_utils._solve_generator, # noqa: SLF001 + time_module, + ) + fastapi_dependency_utils.solve_dependencies = instrumented_solve_dependencies # type: ignore[invalid-assignment] fastapi_routing.solve_dependencies = instrumented_solve_dependencies # type: ignore[invalid-assignment] + fastapi_dependency_utils.run_in_threadpool = instrumented_run_in_threadpool # type: ignore[invalid-assignment] + fastapi_dependency_utils._solve_generator = instrumented_solve_generator # type: ignore[invalid-assignment] # noqa: SLF001 def get_dependency_tracking() -> list[dict[str, Any]]: @@ -88,7 +188,7 @@ def record_dependency_resolution( dependency_type: str, *, cached: bool, - duration_ms: float, + duration_ms: float | None, module: str | None = None, cache_key: str | None = None, params: dict[str, Any] | None = None, @@ -99,7 +199,9 @@ def record_dependency_resolution( name: Name of the dependency function/class. dependency_type: Type of dependency (function, class, generator). cached: Whether the result came from cache. - duration_ms: Resolution time in milliseconds. + duration_ms: Resolution time in milliseconds, or ``None`` if it could not + be measured (e.g. coroutine-function dependencies, which FastAPI + invokes with no interceptable call site). module: Module where the dependency is defined. cache_key: Cache key used by FastAPI. params: Parameters passed to the dependency. @@ -176,7 +278,7 @@ def track_dependency( dependency_callable: Any, *, cached: bool = False, - duration_ms: float = 0.0, + duration_ms: float | None = 0.0, ) -> None: """Helper function to track a dependency resolution. @@ -185,7 +287,7 @@ def track_dependency( Args: dependency_callable: The dependency function/class being resolved. cached: Whether the result came from cache. - duration_ms: Resolution time in milliseconds. + duration_ms: Resolution time in milliseconds, or ``None`` if unknown. """ name = getattr(dependency_callable, "__name__", str(dependency_callable)) module = getattr(dependency_callable, "__module__", None) diff --git a/src/debug_toolbar/fastapi/panels/dependencies.py b/src/debug_toolbar/fastapi/panels/dependencies.py index ba892e5..73b3196 100644 --- a/src/debug_toolbar/fastapi/panels/dependencies.py +++ b/src/debug_toolbar/fastapi/panels/dependencies.py @@ -42,7 +42,7 @@ async def generate_stats(self, context: RequestContext) -> dict[str, Any]: dependency_tree = dependencies_data.get("tree", {}) cache_stats = dependencies_data.get("cache_stats", {}) - total_time_ms = sum(d.get("duration_ms", 0) for d in resolved) + total_time_ms = sum(d.get("duration_ms") or 0 for d in resolved) cached_count = sum(1 for d in resolved if d.get("cached", False)) total_count = len(resolved) diff --git a/tests/integration/test_fastapi_dependencies_panel.py b/tests/integration/test_fastapi_dependencies_panel.py index ccc43c6..a9ce6f5 100644 --- a/tests/integration/test_fastapi_dependencies_panel.py +++ b/tests/integration/test_fastapi_dependencies_panel.py @@ -2,6 +2,7 @@ from __future__ import annotations +import time from typing import Annotated from fastapi.testclient import TestClient @@ -9,6 +10,9 @@ from debug_toolbar.fastapi import FastAPIDebugToolbarConfig, setup_debug_toolbar from fastapi import Depends, FastAPI +SLEEP_SECONDS = 0.05 +SLEEP_MS = SLEEP_SECONDS * 1000 + def get_settings() -> dict: return {"debug": True} @@ -30,6 +34,39 @@ def read_current_user(user: Annotated[dict, Depends(get_current_user)]) -> dict: return app, toolbar +def slow_sync_dependency() -> str: + time.sleep(SLEEP_SECONDS) + return "sync" + + +def slow_generator_dependency(): + time.sleep(SLEEP_SECONDS) + yield "generator" + + +async def slow_coroutine_dependency() -> str: + import asyncio + + await asyncio.sleep(SLEEP_SECONDS) + return "coroutine" + + +def make_timed_app() -> tuple[FastAPI, object]: + app = FastAPI() + config = FastAPIDebugToolbarConfig(enabled=True, track_dependency_injection=True) + toolbar = setup_debug_toolbar(app, config) + + @app.get("/timed") + def timed_route( + sync_dep: Annotated[str, Depends(slow_sync_dependency)], + gen_dep: Annotated[str, Depends(slow_generator_dependency)], + coro_dep: Annotated[str, Depends(slow_coroutine_dependency)], + ) -> dict: + return {"sync": sync_dep, "gen": gen_dep, "coro": coro_dep} + + return app, toolbar + + class TestDependenciesPanelIntegration: def test_resolved_dependencies_populated_for_depends_route(self) -> None: """A route using Depends() must report non-empty resolved_dependencies.""" @@ -49,3 +86,33 @@ def test_resolved_dependencies_populated_for_depends_route(self) -> None: assert "get_current_user" in names assert "get_settings" in names assert panel_stats["total_count"] == len(resolved) + + def test_sync_and_generator_dependency_durations_are_measured(self) -> None: + """Sync-function and generator dependencies must report their real execution time.""" + app, toolbar = make_timed_app() + client = TestClient(app) + + response = client.get("/timed") + assert response.status_code == 200 + + _request_id, data = toolbar.storage.get_all()[0] + resolved = data["panel_data"]["DependencyInjectionPanel"]["resolved_dependencies"] + by_name = {dep["name"]: dep for dep in resolved} + + assert by_name["slow_sync_dependency"]["duration_ms"] >= SLEEP_MS + assert by_name["slow_generator_dependency"]["duration_ms"] >= SLEEP_MS + assert by_name["slow_generator_dependency"]["type"] == "generator" + + def test_coroutine_dependency_duration_is_none(self) -> None: + """Coroutine-function dependencies have no interceptable call site, so duration is None.""" + app, toolbar = make_timed_app() + client = TestClient(app) + + response = client.get("/timed") + assert response.status_code == 200 + + _request_id, data = toolbar.storage.get_all()[0] + resolved = data["panel_data"]["DependencyInjectionPanel"]["resolved_dependencies"] + by_name = {dep["name"]: dep for dep in resolved} + + assert by_name["slow_coroutine_dependency"]["duration_ms"] is None From 6ed7bc08e1e5f39077451f6d646930a57819e1fe Mon Sep 17 00:00:00 2001 From: Jacob Coffee Date: Sat, 10 Oct 2026 19:52:59 -0500 Subject: [PATCH 3/4] fix: simplify dependency tracking to name/cached only, defensive across FastAPI versions Per review: per-kind duration timing (run_in_threadpool / _solve_generator patches) was too fragile and version-coupled, and still ended up a no-op on latest FastAPI. Replaced with a single, defensive patch of solve_dependencies only (both the fastapi.dependencies.utils and fastapi.routing bindings): - Records each resolved sub-dependency's call name and cached flag. duration_ms is always None now: FastAPI invokes dependencies from different internal call sites across versions, and resolving a sub-dependant's own params (all this hook can time) isn't the same as running the dependency itself. - Cache-key lookup now tries dependant.cache_key first (present as an instance attribute even on FastAPI 0.100.0), falling back to the module-level _get_cache_key() helper FastAPI introduced later. - The original solve_dependencies call always runs and its result or exception passes through untouched; all of our own bookkeeping is wrapped in try/except so it can never fail a real request. - Dropped the version-gate/capability-probing that skipped instrumentation outright; the defensive try/except plus the dual cache-key lookup is enough on its own. - toolbar.js renders null values as an em dash instead of the literal text "null". Verified end-to-end (names present, cached=True on second use of a shared dependency) against: - fastapi==0.100.0 (declared floor) - fastapi==0.123.0 (this repo's pinned version) - fastapi==0.143.0 (latest release) all via throwaway venvs with debug_toolbar's src on sys.path, uv.lock untouched. Replaced the duration-based tests with a cached-detection test. make ci passes; re-verified in browser against examples/fastapi_basic on port 8981. --- src/debug_toolbar/core/assets.py | 2 +- src/debug_toolbar/fastapi/middleware.py | 169 ++++++------------ .../test_fastapi_dependencies_panel.py | 66 ++----- 3 files changed, 68 insertions(+), 169 deletions(-) diff --git a/src/debug_toolbar/core/assets.py b/src/debug_toolbar/core/assets.py index 4ee7c41..203be4f 100644 --- a/src/debug_toolbar/core/assets.py +++ b/src/debug_toolbar/core/assets.py @@ -2750,7 +2750,7 @@ class DebugToolbar { const maxStringLen = 1000; if (value === null || value === undefined) { - return 'null'; + return '\u2014'; } if (typeof value === 'boolean') { return '' + value + ''; diff --git a/src/debug_toolbar/fastapi/middleware.py b/src/debug_toolbar/fastapi/middleware.py index 8f02393..2e75336 100644 --- a/src/debug_toolbar/fastapi/middleware.py +++ b/src/debug_toolbar/fastapi/middleware.py @@ -23,146 +23,79 @@ _dependency_cache_stats: ContextVar[dict[str, int] | None] = ContextVar("dependency_cache_stats", default=None) -def _dependency_internals_supported(fastapi_dependency_utils: Any, dependant_cls: Any) -> bool: - """Check whether the FastAPI internals this instrumentation relies on are present. - - FastAPI has reshaped these internals more than once (e.g. moving - ``Dependant.cache_key`` to a module-level ``_get_cache_key()`` helper and - dropping ``is_coroutine_callable``/``is_gen_callable``/``is_async_gen_callable`` - in later releases); both the older and newer ``cache_key`` shapes are accepted, - but the callable-kind attributes must still be present. - """ - has_cache_key_support = hasattr(dependant_cls, "cache_key") or hasattr(fastapi_dependency_utils, "_get_cache_key") - has_callable_kind_support = all( - hasattr(dependant_cls, attr) - for attr in ("is_coroutine_callable", "is_gen_callable", "is_async_gen_callable", "use_cache") - ) - return has_cache_key_support and has_callable_kind_support and hasattr(fastapi_dependency_utils, "_solve_generator") - +def _dependant_cache_key(fastapi_dependency_utils: Any, dependant: Any) -> Any: + """Get a dependant's cache key across FastAPI versions. -def _make_instrumented_solve_dependencies(original: Any, dependant_cache_key: Any) -> Any: - """Build the ``solve_dependencies`` wrapper: tracks tree depth, and records - cached/coroutine-function resolutions directly since they have no other - interceptable call site. + FastAPI historically exposed this as a ``Dependant.cache_key`` attribute + (instance attribute on old releases, ``cached_property`` on newer ones) and + later moved it to a module-level ``_get_cache_key()`` helper. Try both. """ + cache_key = getattr(dependant, "cache_key", None) + if cache_key is not None: + return cache_key + get_cache_key = getattr(fastapi_dependency_utils, "_get_cache_key", None) + if get_cache_key is not None: + return get_cache_key(dependant=dependant) + return None - async def instrumented_solve_dependencies(*, request: Any, dependant: Any, **kwargs: Any) -> Any: - depth_key = "_debug_toolbar_dependency_depth" - depth = request.scope.get(depth_key, 0) + 1 - request.scope[depth_key] = depth - dependency_cache = kwargs.get("dependency_cache") or {} - already_cached = bool(dependant.use_cache) and dependant_cache_key(dependant) in dependency_cache - try: - result = await original(request=request, dependant=dependant, **kwargs) - finally: - request.scope[depth_key] = depth - 1 - - # depth == 1 is the route handler's own top-level dependant, not a Depends(). - if depth > 1 and dependant.call is not None and _dependency_tracking.get() is not None: - if already_cached: - track_dependency(dependant.call, cached=True, duration_ms=0.0) - elif dependant.is_coroutine_callable: - track_dependency(dependant.call, cached=False, duration_ms=None) - # Sync functions/classes are timed via run_in_threadpool; generator - # dependencies are timed via _solve_generator. - - return result - - return instrumented_solve_dependencies - - -def _make_instrumented_run_in_threadpool(original: Any, time_module: Any) -> Any: - """Build the ``run_in_threadpool`` wrapper that times sync function/class dependencies.""" - - async def instrumented_run_in_threadpool(func: Any, *args: Any, **kwargs: Any) -> Any: - start = time_module.perf_counter() - try: - return await original(func, *args, **kwargs) - finally: - if _dependency_tracking.get() is not None: - duration_ms = (time_module.perf_counter() - start) * 1000 - track_dependency(func, cached=False, duration_ms=duration_ms) - - return instrumented_run_in_threadpool - - -def _make_instrumented_solve_generator(original: Any, time_module: Any) -> Any: - """Build the ``_solve_generator`` wrapper that times generator-based dependencies.""" - - async def instrumented_solve_generator(*, dependant: Any, stack: Any, sub_values: Any) -> Any: - start = time_module.perf_counter() - try: - return await original(dependant=dependant, stack=stack, sub_values=sub_values) - finally: - if dependant.call is not None and _dependency_tracking.get() is not None: - duration_ms = (time_module.perf_counter() - start) * 1000 - track_dependency(dependant.call, cached=False, duration_ms=duration_ms) - return instrumented_solve_generator +def _record_dependency_node(fastapi_dependency_utils: Any, dependant: Any, depth: int, **kwargs: Any) -> None: + """Record one resolved sub-dependency, if tracking is active for this request.""" + if depth <= 1 or dependant.call is None: + return + if _dependency_tracking.get() is None: + return + dependency_cache = kwargs.get("dependency_cache") or {} + cache_key = _dependant_cache_key(fastapi_dependency_utils, dependant) + already_cached = bool(getattr(dependant, "use_cache", True)) and cache_key in dependency_cache + track_dependency(dependant.call, cached=already_cached, duration_ms=None) def _install_dependency_instrumentation() -> None: - """Monkeypatch FastAPI's dependency solver to record each resolved dependency. + """Monkeypatch FastAPI's ``solve_dependencies`` to record each resolved dependency. FastAPI resolves ``Depends()`` callables internally with no public hook for - observing resolutions, so this wraps three of its internals: - - - ``solve_dependencies`` (both where it is defined and where ``fastapi.routing`` - imported it): tracks tree depth and records cached resolutions directly, since - cached dependencies are never actually re-invoked. - - ``run_in_threadpool``: times plain sync function/class dependencies, which - FastAPI invokes through it. - - ``_solve_generator``: times generator-based dependencies (e.g. ``yield`` based - session managers), which FastAPI invokes through it. - - Coroutine-function dependencies are awaited inline inside ``solve_dependencies`` - with no interceptable call site, so their duration is reported as ``None`` - rather than measuring the wrong thing. - - These internals only exist in this shape between FastAPI 0.121 and some later - releases that reshaped them again; see ``_dependency_internals_supported``. On - unsupported versions this is a no-op and the panel stays empty, same as before - this fix. + observing resolutions. This wraps ``solve_dependencies`` (both where it is + defined and where ``fastapi.routing`` imported it) to record each sub-dependency + node's call and cache status as the dependency tree is solved. Durations are + not measured: FastAPI invokes most dependency kinds from different internal + call sites across versions, and resolving a sub-dependant's own params (which + is all this hook can time) is not the same as running the dependency itself. + + The original ``solve_dependencies`` call always runs and its result or + exception is returned/raised untouched; any error in our own bookkeeping is + swallowed so a request never fails because of the toolbar. """ - import time as time_module - from fastapi.dependencies import utils as fastapi_dependency_utils - from fastapi.dependencies.models import Dependant as FastAPIDependant from fastapi import routing as fastapi_routing if fastapi_dependency_utils.solve_dependencies.__name__ == "instrumented_solve_dependencies": return - if not _dependency_internals_supported(fastapi_dependency_utils, FastAPIDependant): - logger.debug( - "FastAPI dependency injection tracking requires internals introduced in " - "FastAPI 0.121; skipping instrumentation for this FastAPI version." - ) - return - - get_cache_key = getattr(fastapi_dependency_utils, "_get_cache_key", None) + original_solve_dependencies = fastapi_dependency_utils.solve_dependencies - def dependant_cache_key(dependant: Any) -> Any: - if get_cache_key is not None: - return get_cache_key(dependant=dependant) - return dependant.cache_key + async def instrumented_solve_dependencies(*, request: Any, dependant: Any, **kwargs: Any) -> Any: + depth_key = "_debug_toolbar_dependency_depth" + depth = None + try: + depth = request.scope.get(depth_key, 0) + 1 + request.scope[depth_key] = depth + except Exception: + logger.debug("Dependency tracking depth bookkeeping failed", exc_info=True) - instrumented_solve_dependencies = _make_instrumented_solve_dependencies( - fastapi_dependency_utils.solve_dependencies, dependant_cache_key - ) - instrumented_run_in_threadpool = _make_instrumented_run_in_threadpool( - fastapi_dependency_utils.run_in_threadpool, time_module - ) - instrumented_solve_generator = _make_instrumented_solve_generator( - fastapi_dependency_utils._solve_generator, # noqa: SLF001 - time_module, - ) + try: + return await original_solve_dependencies(request=request, dependant=dependant, **kwargs) + finally: + try: + if depth is not None: + request.scope[depth_key] = depth - 1 + _record_dependency_node(fastapi_dependency_utils, dependant, depth, **kwargs) + except Exception: + logger.debug("Dependency tracking bookkeeping failed", exc_info=True) fastapi_dependency_utils.solve_dependencies = instrumented_solve_dependencies # type: ignore[invalid-assignment] fastapi_routing.solve_dependencies = instrumented_solve_dependencies # type: ignore[invalid-assignment] - fastapi_dependency_utils.run_in_threadpool = instrumented_run_in_threadpool # type: ignore[invalid-assignment] - fastapi_dependency_utils._solve_generator = instrumented_solve_generator # type: ignore[invalid-assignment] # noqa: SLF001 def get_dependency_tracking() -> list[dict[str, Any]]: diff --git a/tests/integration/test_fastapi_dependencies_panel.py b/tests/integration/test_fastapi_dependencies_panel.py index a9ce6f5..566103e 100644 --- a/tests/integration/test_fastapi_dependencies_panel.py +++ b/tests/integration/test_fastapi_dependencies_panel.py @@ -2,7 +2,6 @@ from __future__ import annotations -import time from typing import Annotated from fastapi.testclient import TestClient @@ -10,9 +9,6 @@ from debug_toolbar.fastapi import FastAPIDebugToolbarConfig, setup_debug_toolbar from fastapi import Depends, FastAPI -SLEEP_SECONDS = 0.05 -SLEEP_MS = SLEEP_SECONDS * 1000 - def get_settings() -> dict: return {"debug": True} @@ -34,35 +30,18 @@ def read_current_user(user: Annotated[dict, Depends(get_current_user)]) -> dict: return app, toolbar -def slow_sync_dependency() -> str: - time.sleep(SLEEP_SECONDS) - return "sync" - - -def slow_generator_dependency(): - time.sleep(SLEEP_SECONDS) - yield "generator" - - -async def slow_coroutine_dependency() -> str: - import asyncio - - await asyncio.sleep(SLEEP_SECONDS) - return "coroutine" - - -def make_timed_app() -> tuple[FastAPI, object]: +def make_shared_dependency_app() -> tuple[FastAPI, object]: + """A route that uses the same dependency twice, directly and via another dependency.""" app = FastAPI() config = FastAPIDebugToolbarConfig(enabled=True, track_dependency_injection=True) toolbar = setup_debug_toolbar(app, config) - @app.get("/timed") - def timed_route( - sync_dep: Annotated[str, Depends(slow_sync_dependency)], - gen_dep: Annotated[str, Depends(slow_generator_dependency)], - coro_dep: Annotated[str, Depends(slow_coroutine_dependency)], + @app.get("/shared") + def read_shared( + settings: Annotated[dict, Depends(get_settings)], + user: Annotated[dict, Depends(get_current_user)], ) -> dict: - return {"sync": sync_dep, "gen": gen_dep, "coro": coro_dep} + return {"settings": settings, "user": user} return app, toolbar @@ -87,32 +66,19 @@ def test_resolved_dependencies_populated_for_depends_route(self) -> None: assert "get_settings" in names assert panel_stats["total_count"] == len(resolved) - def test_sync_and_generator_dependency_durations_are_measured(self) -> None: - """Sync-function and generator dependencies must report their real execution time.""" - app, toolbar = make_timed_app() - client = TestClient(app) - - response = client.get("/timed") - assert response.status_code == 200 - - _request_id, data = toolbar.storage.get_all()[0] - resolved = data["panel_data"]["DependencyInjectionPanel"]["resolved_dependencies"] - by_name = {dep["name"]: dep for dep in resolved} - - assert by_name["slow_sync_dependency"]["duration_ms"] >= SLEEP_MS - assert by_name["slow_generator_dependency"]["duration_ms"] >= SLEEP_MS - assert by_name["slow_generator_dependency"]["type"] == "generator" - - def test_coroutine_dependency_duration_is_none(self) -> None: - """Coroutine-function dependencies have no interceptable call site, so duration is None.""" - app, toolbar = make_timed_app() + def test_shared_dependency_is_marked_cached_on_second_use(self) -> None: + """A dependency used twice in the same route is only resolved once; the + second (shared) use is reported as cached. + """ + app, toolbar = make_shared_dependency_app() client = TestClient(app) - response = client.get("/timed") + response = client.get("/shared") assert response.status_code == 200 _request_id, data = toolbar.storage.get_all()[0] resolved = data["panel_data"]["DependencyInjectionPanel"]["resolved_dependencies"] - by_name = {dep["name"]: dep for dep in resolved} - assert by_name["slow_coroutine_dependency"]["duration_ms"] is None + settings_entries = [dep for dep in resolved if dep["name"] == "get_settings"] + assert len(settings_entries) == 2 + assert sorted(dep["cached"] for dep in settings_entries) == [False, True] From 7d657fb970ee21f665f62efb685d8426452c286a Mon Sep 17 00:00:00 2001 From: Jacob Coffee Date: Sat, 10 Oct 2026 20:11:57 -0500 Subject: [PATCH 4/4] fix: report unknown dependency timing as unknown, not zero --- src/debug_toolbar/core/assets.py | 2 +- src/debug_toolbar/fastapi/middleware.py | 4 +--- src/debug_toolbar/fastapi/panels/dependencies.py | 3 ++- tests/unit/fastapi/test_dependencies_panel.py | 2 +- 4 files changed, 5 insertions(+), 6 deletions(-) diff --git a/src/debug_toolbar/core/assets.py b/src/debug_toolbar/core/assets.py index 203be4f..4ee7c41 100644 --- a/src/debug_toolbar/core/assets.py +++ b/src/debug_toolbar/core/assets.py @@ -2750,7 +2750,7 @@ class DebugToolbar { const maxStringLen = 1000; if (value === null || value === undefined) { - return '\u2014'; + return 'null'; } if (typeof value === 'boolean') { return '' + value + ''; diff --git a/src/debug_toolbar/fastapi/middleware.py b/src/debug_toolbar/fastapi/middleware.py index 2e75336..d0b0ac6 100644 --- a/src/debug_toolbar/fastapi/middleware.py +++ b/src/debug_toolbar/fastapi/middleware.py @@ -132,9 +132,7 @@ def record_dependency_resolution( name: Name of the dependency function/class. dependency_type: Type of dependency (function, class, generator). cached: Whether the result came from cache. - duration_ms: Resolution time in milliseconds, or ``None`` if it could not - be measured (e.g. coroutine-function dependencies, which FastAPI - invokes with no interceptable call site). + duration_ms: Resolution time in milliseconds, or ``None`` if unknown. module: Module where the dependency is defined. cache_key: Cache key used by FastAPI. params: Parameters passed to the dependency. diff --git a/src/debug_toolbar/fastapi/panels/dependencies.py b/src/debug_toolbar/fastapi/panels/dependencies.py index 73b3196..c71c7dd 100644 --- a/src/debug_toolbar/fastapi/panels/dependencies.py +++ b/src/debug_toolbar/fastapi/panels/dependencies.py @@ -42,7 +42,8 @@ async def generate_stats(self, context: RequestContext) -> dict[str, Any]: dependency_tree = dependencies_data.get("tree", {}) cache_stats = dependencies_data.get("cache_stats", {}) - total_time_ms = sum(d.get("duration_ms") or 0 for d in resolved) + durations = [d["duration_ms"] for d in resolved if d.get("duration_ms") is not None] + total_time_ms = sum(durations) if durations else None cached_count = sum(1 for d in resolved if d.get("cached", False)) total_count = len(resolved) diff --git a/tests/unit/fastapi/test_dependencies_panel.py b/tests/unit/fastapi/test_dependencies_panel.py index 3d4c0b4..7073e7c 100644 --- a/tests/unit/fastapi/test_dependencies_panel.py +++ b/tests/unit/fastapi/test_dependencies_panel.py @@ -52,7 +52,7 @@ async def test_generate_stats_empty(self, mock_toolbar: MagicMock, context: Requ assert stats["cached_count"] == 0 assert stats["fresh_count"] == 0 assert stats["cache_hit_rate"] == 0 - assert stats["total_time_ms"] == 0 + assert stats["total_time_ms"] is None @pytest.mark.asyncio async def test_generate_stats_with_dependencies(self, mock_toolbar: MagicMock, context: RequestContext) -> None: