executiontimer 0.1.1

Time named sections of your code with a with block or a decorator. Nested sections automatically form a hierarchy, so you get a breakdown of where time actually went — not just a single number.

Zero dependencies. Fully type annotated. Works with threads and asyncio.

Features

• ⏱️ One primitive — TimerContext is both a context manager and a decorator
• 🌳 Automatic hierarchy — nesting with blocks nests the report, no wiring required
• 🏷️ User-defined categories — tag sections with any string ("gpu", "io", "db") and get per-category totals
• ⚡ Native async — decorating an async def times the whole await, not the coroutine object
• 🧵 Thread and task safe — context stacks are isolated per thread and per asyncio task
• 🔢 Loop counters — time each iteration separately, then merge them back together
• 📤 JSON export — structured output for dashboards, CI, or an LLM
• 🚫 Nesting rules — optionally forbid one category inside another to catch mistakes early
• 📦 Zero dependencies

Installation

pip install executiontimer

uv add executiontimer

Requires Python 3.12+.

Note — the install name is executiontimer, the import name is execution_timer:

from execution_timer import TimerContext

Quick start

import time

from execution_timer import TimerContext, get_execution_times_report

with TimerContext("load_data"):
    time.sleep(0.12)

with TimerContext("solve"):
    for i in range(3):
        with TimerContext("step", category="gpu", counter=i):
            time.sleep(0.05)
    with TimerContext("postprocess", category="cpu"):
        time.sleep(0.03)

print(get_execution_times_report())

Total calculation time: 0.3156 s.

load_data: 0.1219 s (38.62%)
solve: 0.1937 s (61.38%)
..  step: 0.1585 s (50.24%)
..  postprocess: 0.0350 s (11.10%)

Indentation reflects nesting. Percentages are relative to the total of all top-level sections, so nested entries show their share of the whole run.

Usage

As a decorator

from execution_timer import TimerContext


@TimerContext("preprocess")
def preprocess(rows: list[str]) -> list[str]:
    return [row.strip() for row in rows]

Coroutine functions are supported natively — the timing spans the entire await:

@TimerContext("fetch", category="io")
async def fetch(url: str) -> bytes: ...

Counters

Pass counter=i to time loop iterations separately. The report merges them by default (flatten=True) and keeps them apart when you ask for it:

for i in range(3):
    with TimerContext("step", counter=i):
        ...

get_execution_timings(flatten=True)  # {("step",): {"time": 0.158, ...}}
get_execution_timings(flatten=False)  # {("step[0]",): ..., ("step[1]",): ..., ...}

Flattening removes the final integer suffix (including negative counters). Other bracketed names such as array[index] are preserved. If merged entries have different categories, the category from the most recently entered section is used.

Categories

Categories are plain strings — use whatever fits your domain:

from execution_timer import get_total_category_time

with TimerContext("matmul", category="gpu"):
    ...

get_total_category_time("gpu")

get_total_category_time counts only the top-most section of a category, so a gpu section nested inside another gpu section is not double-counted.

Repeated calls to the same path accumulate time. If its category changes, the latest category applies to that path's entire accumulated time. Use consistent categories per path when you need separate category totals.

You can also forbid a category from appearing inside another, which raises a ValueError as soon as the invalid nesting happens:

from execution_timer import register_forbidden_nesting

register_forbidden_nesting(outer="gpu", inner="cpu")

with TimerContext("kernel", category="gpu"):
    with TimerContext("reduce", category="cpu"):  # ValueError
        ...

JSON export

get_execution_times_json and save_execution_timings_json emit a structured snapshot — convenient for dashboards, CI artifacts, or handing to a language model:

from execution_timer import save_execution_timings_json

save_execution_timings_json("timings.json")

{
  "total_time": 0.31556,
  "total_category_time": { "cpu": 0.035024, "default": 0.31556, "gpu": 0.158528 },
  "sections": [
    { "name": "load_data", "path": ["load_data"], "time": 0.121869, "category": "default" },
    { "name": "solve", "path": ["solve"], "time": 0.193691, "category": "default" },
    { "name": "step", "path": ["solve", "step"], "time": 0.158528, "category": "gpu" },
    { "name": "postprocess", "path": ["solve", "postprocess"], "time": 0.035024, "category": "cpu" }
  ]
}

Sections and totals come from one snapshot. Category totals use the original paths, even when flattening merges sections with different categories.

Concurrency

The recorded timings live in one process-wide registry guarded by a lock. The active context stack is stored in a ContextVar, so it is isolated per thread and per asyncio task: concurrently recorded sections nest independently and merge into a single report.

async def worker(n: int) -> None:
    with TimerContext(f"task{n}"):
        await fetch(...)  # recorded as ("task{n}", "fetch")


await asyncio.gather(worker(0), worker(1))

Overlapping calls to the same section path are supported: each call keeps its own start time, and their durations are added together. These totals measure accumulated elapsed time and can exceed wall-clock duration. Use distinct names (or counter=) to report concurrent calls separately.

New asyncio tasks inherit the timing context in which they are created. Their sections nest under that parent; changes to each task's active stack remain independent. Await child tasks inside the parent section if you want the parent duration to include them.

Reusing contexts and clearing timings

A TimerContext can be reused, nested within itself, or shared by concurrent calls. For a tight loop, reuse a context to avoid constructing one on every iteration:

step_timer = TimerContext("step")
for item in items:
    with step_timer:
        process(item)

Timings accumulate until clear_execution_timings() is called. Clearing also discards samples from sections that were already active, without disturbing their nesting stack. Sections started after the clear are recorded normally. Reports include completed calls; an active section's current duration is added only when it exits.

Measuring overhead

Run the repeatable benchmark with uv run python benchmarks/overhead.py. It measures fresh and reused contexts, sync and async decorators, nesting, and reporting. Compare results using the same interpreter and machine; see benchmarks/README.md. log_execution_times() skips building a report when its logger has INFO disabled.

API

flatten=True merges counter variants of a section back together; flatten=False keeps each name[i] separate.

Exported types: TimingReport, SectionRecord, TimingsPayload, and DEFAULT_CATEGORY. The package ships a py.typed marker, so type checkers use the inline annotations.

Development

Requires uv.

uv sync
uv run pytest --cov
uv run ruff check --fix && uv run ruff format
uv run basedpyright

See CONTRIBUTING.md for the full workflow, and CHANGELOG.md for release notes.

License

MIT — see LICENSE.