Skip to content

Subtest durations become negative when time is mocked (subtests.py bypasses _pytest.timing) #15201

Open

Description

@PersuasivePost
  • a detailed description of the bug or problem you are having
  • output of pip list from the virtual environment you are using
  • pytest and operating system versions
  • minimal example if possible

Description

When a test mocks time.perf_counter / time.time (as clock-mocking libraries like freezegun and time-machine do), subtests report negative durations and a stop timestamp of 0.0 (January 1, 1970). Normal tests are unaffected by the same mocking.

Reproducer

# test_repro.py
import time

def test_normal(monkeypatch):
    real_sleep = time.sleep
    monkeypatch.setattr(time, "perf_counter", lambda: 0.0)
    monkeypatch.setattr(time, "time", lambda: 0.0)
    real_sleep(0.3)

def test_with_subtest(subtests, monkeypatch):
    real_sleep = time.sleep
    with subtests.test(msg="frozen clock"):
        monkeypatch.setattr(time, "perf_counter", lambda: 0.0)
        monkeypatch.setattr(time, "time", lambda: 0.0)
        real_sleep(0.3)
$ pytest -q --junitxml=out.xml
.u.                                                                      [100%]
2 passed, 1 subtests passed in 1.23s

$ grep -o 'name="[^"]*" time="[^"]*"' out.xml
name="test_normal" time="0.301"
name="test_with_subtest" time="-1194.217"

Both tests sleep 0.3s under a mocked clock. The normal test reports 0.301s; the subtest reports −1194s (the exact value depends on the machine's uptime).

Cause

Normal test execution and subtests handle timing differently.

In src/_pytest/runner.py, pytest uses timing.Instant() and instant.elapsed() from _pytest.timing. However, src/_pytest/subtests.py imports the time module directly and calls time.time() and time.perf_counter():

$ grep -n "time\." src/_pytest/subtests.py
219:        self._start = time.time()
220:        self._precise_start = time.perf_counter()
245:        precise_stop = time.perf_counter()
247:        stop = time.time()

_pytest.timing imports perf_counter directly using from time import perf_counter, so it keeps its original function reference even if time.perf_counter is patched later. subtests.py looks up the function on the time module whenever it is called, so it picks up the patched value.

So if a subtest starts on the real clock and the test then patches time.perf_counter to return 0.0, the subtest computes its duration from the real start time and the patched end time, giving a negative duration. The same happens with time.time(), giving a stop timestamp of 0.0.

This is the situation _pytest.timing exists to prevent. Its docstring says pytest grabs time functions internally "to avoid tests mocking "time" to affect pytest runtime information (issue #185)", and #7764 covered the freezegun case for --durations. The subtests module, merged later, doesn't follow that rule.

Proposed fix

Switch subtests.py to timing.Instant() / .elapsed(), matching runner.py. If this approach sounds right, I'd be happy to send a PR with a regression test.

Related

#14412 (fixed in #14670) addressed how subtest timings are aggregated in the terminal with console_output_style='times'. This is a separate problem: the timing values themselves are wrong when time is mocked, and it still reproduces on main after #14670.

Environment

  • pytest 9.2.0.dev388+g420cf37a3 (main, editable install)
  • Python 3.10.12
  • Ubuntu 22.04.5 LTS
pip list
Package            Version
------------------ -----------------------
argcomplete        3.6.3
asynctest          0.13.0
attrs              25.4.0
certifi            2026.1.4
charset-normalizer 3.4.4
coverage           7.13.1
elementpath        5.1.0
exceptiongroup     1.3.1
execnet            2.1.2
hypothesis         6.150.0
idna               3.11
iniconfig          2.3.0
mock               5.2.0
numpy              2.2.6
packaging          25.0
pexpect            4.9.0
pluggy             1.6.0
ptyprocess         0.7.0
pygments           2.19.2
pytest             9.2.0.dev388+g420cf37a3
pytest-xdist       3.8.0
pyyaml             6.0.3
requests           2.32.5
setuptools         80.9.0
sortedcontainers   2.4.0
tomli              2.3.0
typing-extensions  4.15.0
urllib3            2.6.3
xmlschema          4.3.0

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Labels

No labels
No labels

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions