waterfall-log 0.1.2

Request waterfall tracing for Starlette-compatible ASGI applications

waterfall-log

waterfall-log is a small Python library for Starlette-compatible applications that prints a request waterfall to the console after every HTTP request.

It is designed for FastAPI and other ASGI apps built on Starlette, and it focuses on two things:

• capturing the Python call tree for one request
• making the slowest parts obvious in the console output

What it does

For each HTTP request, the middleware:

• profiles Python function calls in the active request task
• builds a nested call tree with timestamps
• prints a waterfall-style timeline to the configured output stream
• reports the hottest frames by inclusive and self time
• focuses on frames from your application code by default, not FastAPI, Starlette, or other helper libraries
• collapses repeated low-impact calls below 0.1% of total request time so the output stays readable

Install

poetry install --with dev,demo

Install the library into another project from a built artifact or directly from PyPI later with:

pip install waterfall-log

Quick start

from fastapi import FastAPI

from waterfall_log import WaterfallMiddleware

app = FastAPI()
app.add_middleware(WaterfallMiddleware)


@app.get("/hello")
async def hello() -> dict[str, str]:
    return {"message": "hello"}

By default, the middleware captures frames from the current working directory and skips framework and dependency code. You can override that with include_paths and exclude_paths if your application source lives elsewhere.

The consolidation threshold is also configurable. For example, to disable collapsing entirely:

app.add_middleware(
  WaterfallMiddleware,
  collapse_below_percent=0.0,
)

Run the sample app:

poetry run python sample_app.py

It prints a small startup banner with the request URL and a ready-to-run curl command.

Optional environment variables:

WATERFALL_DEMO_HOST=0.0.0.0 WATERFALL_DEMO_PORT=9000 WATERFALL_DEMO_RELOAD=1 WATERFALL_DEMO_COLLAPSE_BELOW_PERCENT=0.0 poetry run python sample_app.py

The sample app also prints the active collapse_below_percent value in its startup banner.

Then call:

curl http://127.0.0.1:8000/report/42

Example output:

Request 200 GET /report/42 took 86.54 ms
Hotspots
  38.12 ms total | 36.89 ms self  sample_app.py:24 load_line_items
  21.07 ms total | 20.81 ms self  sample_app.py:36 render_summary
Waterfall
    0.00 ms |############################################################|   86.54 ms 100.0% GET /report/42
    1.14 ms | ###                                                        |    4.93 ms   5.7% sample_app.py:51 compute_discount
    7.03 ms |     ##########################                             |   38.12 ms  44.0% sample_app.py:24 load_line_items  <<< hottest
   49.82 ms |                                  ###############          |   21.07 ms  24.3% sample_app.py:36 render_summary

Notes

• The profiler automatically isolates the active asyncio task, so overlapping requests handled on the same event loop do not share one trace.
• Work executed in background threads or native extensions is not profiled directly. Time spent there is still visible in the waiting parent frame.
• The middleware only traces HTTP requests. WebSocket and lifespan scopes pass through unchanged.

Poetry workflow

Install dependencies for local work:

poetry install --with dev,demo

Run tests:

poetry run pytest

Build publishable artifacts:

poetry build

Check package metadata:

poetry check

Publish to PyPI:

poetry config pypi-token.pypi <token>
poetry publish --build

If you want to publish to TestPyPI first:

poetry config repositories.testpypi https://test.pypi.org/legacy/
poetry publish --build --repository testpypi

Files

• src/waterfall_log: library package
• sample_app.py: runnable FastAPI demo
• tests/test_middleware.py: smoke test for middleware output