Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion .github/ISSUE_TEMPLATE/bug_report.yml
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@ body:
id: version
attributes:
label: executiontimer version
placeholder: "1.1.0"
placeholder: "1.1.1"
validations:
required: true

Expand Down
20 changes: 19 additions & 1 deletion CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,23 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0

## [Unreleased]

## [1.1.1] - 2026-10-01

### Documentation

- The threads section of the concurrency guide was wrong for free-threaded Python 3.14.
There, a new thread starts in a copy of the context that started it, so its sections
nest under the section that was open at that moment. A thread pool reuses its workers,
so each worker keeps the section it started under: work submitted later from another
section was reported under the first one. The guide said pool work is always reported at
the top level, and that free-threaded builds nest thread work correctly with no extra
work. Neither was true on every build. The guide now explains the difference and shows
how to get the same report on every build: run each call in
`contextvars.copy_context().run` to nest it under the current section, or in
`contextvars.Context().run` to keep it at the top level. Behaviour is unchanged.
- Tests cover how threads and reused pool workers nest on each kind of build, and both
recipes. The guide's examples assert their results on every build.

## [1.1.0] - 2026-09-30

### Changed
Expand Down Expand Up @@ -206,7 +223,8 @@ First public release on PyPI.
`py.typed` marker so type checkers use the inline annotations.
- `__version__` attribute on the package.

[Unreleased]: https://github.com/seba2390/ExecutionTimer/compare/v1.1.0...HEAD
[Unreleased]: https://github.com/seba2390/ExecutionTimer/compare/v1.1.1...HEAD
[1.1.1]: https://github.com/seba2390/ExecutionTimer/compare/v1.1.0...v1.1.1
[1.1.0]: https://github.com/seba2390/ExecutionTimer/compare/v1.0.3...v1.1.0
[1.0.3]: https://github.com/seba2390/ExecutionTimer/compare/v1.0.2...v1.0.3
[1.0.2]: https://github.com/seba2390/ExecutionTimer/compare/v1.0.1...v1.0.2
Expand Down
64 changes: 48 additions & 16 deletions docs/guide/concurrency.md
Original file line number Diff line number Diff line change
Expand Up @@ -57,11 +57,33 @@ the same.

## Threads

New threads do **not** inherit the active stack. Sections recorded in a thread appear at the
top level of the report, and their time is added to the total alongside the section that
started the thread:
Whether a new thread starts inside the section that started it depends on the Python build:

- **Regular builds**, including Python 3.14, start each new thread with an empty stack.
Sections recorded in the thread appear at the top level of the report, and their time
is added to the total alongside the section that started the thread.
- **Free-threaded builds of Python 3.14** start each new thread with a copy of the context
of the code that called {meth}`~threading.Thread.start`. Sections recorded in the thread
nest under the section that was open at that moment.

Python's `-X thread_inherit_context` option switches between the two on any 3.14 build,
and `sys.flags.thread_inherit_context` reports which one is in effect.

### Thread pools

The difference matters most for thread pools, because a pool reuses its threads.
{class}`~concurrent.futures.ThreadPoolExecutor` starts a worker thread when work is
submitted and keeps it for later work. On a free-threaded build, the worker keeps the
stack it started with for as long as it lives, so work submitted later, from a different
section or from none, still nests under the section that was open when the worker started.
On a regular build, the same work is recorded at the top level.

To get the same report on every build, pick the context for each call yourself. To nest
thread work under the current section, run each call in a fresh copy of the current
context from {func}`contextvars.copy_context`:

```python
import contextvars
from concurrent.futures import ThreadPoolExecutor

from execution_timer import clear_execution_timings
Expand All @@ -74,28 +96,38 @@ def download(n: int) -> int:
return n


with TimerContext("batch"), ThreadPoolExecutor() as pool:
list(pool.map(download, range(4))) # recorded as ("download",), not ("batch", "download")
with ThreadPoolExecutor(max_workers=2) as pool:
with TimerContext("batch"):
futures = [pool.submit(contextvars.copy_context().run, download, n) for n in range(4)]
results = [future.result() for future in futures]
with TimerContext("retry"):
pool.submit(contextvars.copy_context().run, download, 0).result()

timings = get_execution_timings()
assert ("batch", "download") in timings
assert ("retry", "download") in timings
assert ("download",) not in timings
```

To nest thread work under the current section, run it in a copy of the current context
with {func}`contextvars.copy_context`, or use {func}`asyncio.to_thread`, which does that for
you:
Copy the context for every call rather than once per section: a context can't be entered
by two threads at the same time. {func}`asyncio.to_thread` copies the context for you.

```python
import contextvars
To keep thread work at the top level on every build, run each call in a new, empty
{class}`~contextvars.Context` instead:

```python
clear_execution_timings()

with TimerContext("batch"), ThreadPoolExecutor() as pool:
context = contextvars.copy_context()
pool.submit(context.run, download, 1).result()
with ThreadPoolExecutor(max_workers=2) as pool, TimerContext("batch"):
pool.submit(contextvars.Context().run, download, 1).result()

assert ("batch", "download") in get_execution_timings()
timings = get_execution_timings()
assert ("download",) in timings
assert ("batch", "download") not in timings
```

On free-threaded builds of Python 3.14, new threads inherit the context by default, so
thread sections nest without extra work.
The same works for a plain thread: pass `target=contextvars.copy_context().run` or
`target=contextvars.Context().run`, followed by the function and its arguments in `args`.

## Overlapping calls add up

Expand Down
2 changes: 1 addition & 1 deletion src/execution_timer/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,7 @@
save_execution_timings_json,
)

__version__ = "1.1.0"
__version__ = "1.1.1"

__all__ = [
"DEFAULT_CATEGORY",
Expand Down
47 changes: 47 additions & 0 deletions tests/execution_timer_test.py
Original file line number Diff line number Diff line change
Expand Up @@ -2,10 +2,12 @@

import asyncio
import builtins
import contextvars
import functools
import inspect
import json
import logging
import sys
import threading
import time
import warnings
Expand Down Expand Up @@ -38,6 +40,10 @@
P = ParamSpec("P")
R = TypeVar("R")

# New threads start in a copy of the starting thread's context. The default on free-threaded
# Python 3.14; the flag does not exist before 3.14.
THREADS_INHERIT_CONTEXT = bool(getattr(sys.flags, "thread_inherit_context", False))


@pytest.fixture(autouse=True)
def reset_timer() -> Iterator[None]:
Expand Down Expand Up @@ -590,6 +596,47 @@ def worker(root: str, child: str) -> None:
assert ("t0", "c1") not in timings
assert ("t1", "c0") not in timings

def test_new_thread_nests_under_the_starting_section_only_where_threads_inherit_context(self) -> None:
thread = threading.Thread(target=TimerContext("work")(lambda: None))
with TimerContext("outer"):
thread.start()
thread.join()

expected = ("outer", "work") if THREADS_INHERIT_CONTEXT else ("work",)
assert set(raw_timings()) == {("outer",), expected}

def test_reused_pool_worker_keeps_the_section_it_started_in_where_threads_inherit_context(self) -> None:
"""A pool worker inherits the context once, when it starts, and keeps it for later work."""
work = TimerContext("work")(lambda: None)
with ThreadPoolExecutor(max_workers=1) as pool:
with TimerContext("phase_a"):
pool.submit(work).result()
with TimerContext("phase_b"):
pool.submit(work).result()

# Where threads inherit context, phase_b's call is misfiled under phase_a.
expected = {("phase_a", "work")} if THREADS_INHERIT_CONTEXT else {("work",)}
assert set(raw_timings()) == {("phase_a",), ("phase_b",), *expected}

def test_copying_the_context_per_call_nests_pool_work_on_every_build(self) -> None:
work = TimerContext("work")(lambda: None)
with ThreadPoolExecutor(max_workers=2) as pool:
with TimerContext("phase_a"):
futures = [pool.submit(contextvars.copy_context().run, work) for _ in range(4)]
_ = [future.result() for future in futures]
with TimerContext("phase_b"):
pool.submit(contextvars.copy_context().run, work).result()
pool.submit(contextvars.copy_context().run, work).result()

assert set(raw_timings()) == {("phase_a",), ("phase_a", "work"), ("phase_b",), ("phase_b", "work"), ("work",)}

def test_an_empty_context_per_call_keeps_pool_work_top_level_on_every_build(self) -> None:
work = TimerContext("work")(lambda: None)
with ThreadPoolExecutor(max_workers=1) as pool, TimerContext("outer"):
pool.submit(contextvars.Context().run, work).result()

assert set(raw_timings()) == {("outer",), ("work",)}


class TestAsyncDecorator:
def test_async_decorator_times_the_await_not_coroutine_creation(self) -> None:
Expand Down
Loading