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時間
- マージ済み PR(30日)
- 25
環境構築
- Dockerfile・Docker Compose ファイルなし
- プルリクエストのテンプレートあり
- コントリビューションガイドを読む
はじめの一歩
- issue を最後まで読み、次にプロジェクトのコントリビューションガイドを読みます。
- 着手することを issue にコメントします — 二人が同じ作業をするのを防げます。
- リポジトリをフォークし、ブランチを切って変更します。
- 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 日前に担当しましたが、オープン中のプルリクエストはありません。 オープン
難易度 2/5 1〜3時間 初心者へのやさしさ 86/100
pytest-dev/pytest#14514 · コメント 6 件 ·
メンテナーはふだん 1 日以内に返信
-
Expose CaptureManager as public API再び着手できるかも @harsh21234i が 200 日前に担当しましたが、オープン中のプルリクエストはありません。 オープンtype: enhancement type: feature-branch
難易度 2/5 1〜3時間 初心者へのやさしさ 68/100
pytest-dev/pytest#14186 · コメント 2 件 ·
メンテナーはふだん 1 日以内に返信
pytest-dev/pytest の issue をすべて見る
似ている issue
-
bug
難易度 2/5 1〜3時間 初心者へのやさしさ 79/100
メンテナーはふだん 1 日以内に返信
-
難易度 2/5 1〜3時間 初心者へのやさしさ 78/100
mohitmishra786/readprism#322 ·
メンテナーはふだん 1 日以内に返信
-
good first issue
難易度 2/5 1〜3時間 初心者へのやさしさ 76/100
-
難易度 1/5 1時間未満 初心者へのやさしさ 75/100
メンテナーはふだん 1 日以内に返信
-
API-key credentials accept a blank key: empty via the API, spaces-only via the builder's Add API key dialog対応中かも このイシューにリンクされたプルリクエストがオープン中、またはマージ済みです。 オープン
難易度 2/5 1〜3時間 初心者へのやさしさ 77/100
Significant-Gravitas/AutoGPT#15727 ·
メンテナーはふだん 1 日以内に返信