Subtest durations become negative when `time` is mocked (subtests.py bypasses `_pytest.timing`)
维护者通常 1 天内回复
@RonnyPfannschmidt 已经在做这个了。
开始于 2026年10月18日。
评估
调研方向
从 src/_pytest/subtests.py 中报告的 time.time() 和 time.perf_counter() 调用处开始，然后比较 src/_pytest/runner.py 和 _pytest.timing 中的计时用法。根据复现代码添加一个回归测试，在 subtest 内模拟两个时钟；完成标准是，在时钟被模拟时，subtest 时长和停止时间戳仍然有效。
由索引模型根据 Issue 内容生成。
描述
- a detailed description of the bug or problem you are having
- output of
pip listfrom 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
- 主要语言
- Python
- 星标
- 14.6k
- 派生
- 3.5k
- 平均合并
- 1 天 17 小时
- 30 天内合并 PR
- 25
环境准备
- 没有 Dockerfile 或 Docker Compose 文件
- 有 Pull Request 模板
- 阅读贡献指南
从这里开始
- 先读完整个 Issue，再读项目的贡献指南。
- 在 Issue 下留言说明你要接手 —— 这能避免两个人做同样的事。
- Fork 仓库，在一个分支上完成修改。
- 提交 Pull Request，并在描述里引用这个 Issue 编号。
pytest-dev/pytest 的其他 Issue
-
`faulthandler_timeout` stops covering a test once setup, call or a subtest fails (`pytest_exception_interact` cancels the timer)可能已有人在做 @XXXXXQ-0206 于 4 天前认领。 未关闭
难度 2/5 1-3 小时 新手友好度 78/100
pytest-dev/pytest#15180 · 1 条评论 ·
维护者通常 1 天内回复
-
Assertion diff doesn't pretty-print the built-in frozen dict (Python 3.15)可能已有人在做 @HakeemTheEmperor 于 6 天前认领。 未关闭
难度 2/5 1-3 小时 新手友好度 78/100
pytest-dev/pytest#15172 ·
维护者通常 1 天内回复
-
monkeypatch.setattr fails to undo on objects with a custom __setattr__ (regression from #14969)可能已有人在做 @hardikkaurani 于 25 天前认领。 未关闭
难度 2/5 1-3 小时 新手友好度 78/100
pytest-dev/pytest#15099 · 6 条评论 ·
维护者通常 1 天内回复
-
Allow dotted test filenames (`*.test.py`) via one-line change to `compute_module_name`可能重新可做 @siddy-stack 于 62 天前认领，目前没有进行中的 PR。 未关闭
难度 2/5 1-3 小时 新手友好度 86/100
pytest-dev/pytest#14514 · 6 条评论 ·
维护者通常 1 天内回复
-
Expose CaptureManager as public API可能重新可做 @harsh21234i 于 200 天前认领，目前没有进行中的 PR。 未关闭type: enhancement type: feature-branch
难度 2/5 1-3 小时 新手友好度 68/100
pytest-dev/pytest#14186 · 2 条评论 ·
维护者通常 1 天内回复
查看 pytest-dev/pytest 的全部 Issue
相似的 Issue
-
难度 1/5 1-3 小时 新手友好度 66/100
AlexsLemonade/scpca-docs#518 ·
-
bug
难度 1/5 1 小时以内 新手友好度 95/100
rocketride-org/rocketride-server#2705 · 1 条评论 ·
维护者通常 1 天内回复
-
documentation
难度 2/5 1-3 小时 新手友好度 85/100
Metabuilder-Labs/tokenjam#786 ·
维护者通常 1 天内回复
-
prototype(verifier_token): map disallowed warning to contraindicated before composite precedence check可能已有人在做 @drk-ram 今天认领。 未关闭
难度 2/5 1-3 小时 新手友好度 88/100
agentrust-io/trace-spec#582 ·
维护者通常 1 天内回复
-
area:cli priority:low refactor size:small
难度 1/5 1 小时以内 新手友好度 88/100
RonaldHensbergen/composable-data-stack#906 ·
维护者通常 1 天内回复