Repository navigation
CallInfo: store a timing.Duration, keep start/stop/duration as aliases - #15205
RonnyPfannschmidt wants to merge 4 commits into
Conversation
Add CallInfo._from_duration() so internal construction sites take their start/stop/duration from one _pytest.timing.Duration instead of passing three loose floats. from_call, subtests and unittest subtests now all go through it. Subtests measured time with time.time()/time.perf_counter() directly, so a test mocking time under subtests.test() produced negative or bogus durations (#15201, same class of bug as #185). unittest subtests reported start=stop=0 (the epoch); they now report a zero-length call at the current time. Fixes #15201. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
pyba-chronographer
Bot
added
the
bot:chronographer:provided
CallInfo now keeps the measured timing.Duration and exposes start, stop and duration as properties derived from it, instead of three loose floats that could disagree. External code still constructs CallInfo from floats (pytest-subtests, pytest-asyncio-concurrent) and assigns the timing attributes (pytest-asyncio-cooperative, pytest-velo), so the float constructor and the attribute setters keep working on top of the stored Duration. timing.Instant fields become init-able to support that. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
RonnyPfannschmidt
changed the title
unittest reports subtests after the fact without timing. Keep the start=stop=duration=0 values inherited from pytest-subtests, but spell them as a named timing.UNMEASURED Duration instead of literal zeros. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
|
I reported #15201 and tested this branch (claude/callinfo-duration-8dkzw2) against my original reproducer, which patches time.time and time.perf_counter to lambda: 0.0 inside the test and inside a subtest, and sleeps 0.3s. main @ 420cf37: test_with_subtest reported −1194.217s The negative duration is gone. Thanks for the quick fix. |
Store the Duration directly instead of splitting it into floats for __init__ and then overwriting the rebuilt Duration. __init__ remains only as the legacy float entry point. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
bluetech
left a comment
bluetech
left a comment
There was a problem hiding this comment.
-
The commit author is
Claude <noreply@anthropic.com>(and the Co-author isClaude Opus 5.5 (1M context) <noreply@anthropic.com>). I don't think we can accept changes which such authorship. There needs to be a human taking responsibility... -
The change is a bit complicated by the desire to keep
__init__unchanged, but I don't see why. The ctor is private and that's guaranteed by the_ispytestprotection. So we are free to change it. -
Related to previous, I dislike the name
_from_durationfor the factory method. It makes it sound like the duration is the main component of theCallInfobut it's a minor detail compared to the result. So it's strange to give it such an emphasis. -
The commits have some back-and-forth among themselves, like it adds "
unittestsubtests are now reported..." changelog in one commit and then removes it in another commit. Since I review commit-by-commit it's a bit confusing. If the change is difficult to separate logically then a squashed commit will be easier to review.
|
|
||
| def test_callinfo_timing_from_floats() -> None: | ||
| """Plugins construct CallInfo from plain floats and assign the timing | ||
| attributes; both keep working on top of the stored Duration.""" |
There was a problem hiding this comment.
"both keep working on top of the stored Duration" I would remove this, as it refers to an implementation detail that can get out of sync if something changes.
|
|
||
|
|
||
| def test_timing_unaffected_by_mocked_time(pytester: pytest.Pytester) -> None: | ||
| """Subtest timing uses _pytest.timing, so tests mocking ``time`` do not |
There was a problem hiding this comment.
Would remove "Subtest timing uses _pytest.timing, so", same reason as previous comment
| assert len(reports) == 1 | ||
| [report] = reports | ||
| assert report.failed | ||
| assert report.start == timing.UNMEASURED.start.time |
There was a problem hiding this comment.
I think the test would be stronger if it doesn't refer to UNMEASURED directly but hardcodes the 0. Since the idea is to see if something changes from a user's perspective, which doesn't know about UNMEASURED. If we hardcode, then if someone changes UNMEASURED, they will have to explicitly "acknowledge" the behavior change by updating the test.
|
🤖 Written by Claude Opus 5.5 via Claude Code for the pytest maintainers; I prompted it, it did the work, I read it. Closing this. The commits on this branch were authored by Claude, not me. I'll redo the change from a local Claude Code session, incorporating @bluetech's review: one squashed commit with me as author, Generated by Claude Code |
Requested by Ronny · project thread
🤖 Written by Claude Opus 5.5 via Claude Code for the pytest maintainers; I prompted it, it did the work, I read it.
Closes #15201. Supersedes #15204.
Before:
CallInfostoresstart,stopanddurationas three independent floats, and its three construction sites fill them differently.from_callusestiming.Instant.subtests.test()callstime.time()/time.perf_counter()directly, so a test that mockstimeinside a subtest gets negative or bogus durations (the #185 class of bug). unittestsubTestpasses literalstart=stop=duration=0.After:
CallInfostores one privatetiming.Duration, andstart/stop/durationare properties derived from it. All internal construction goes throughCallInfo._from_duration(result, excinfo, duration, when). The pattern for any new site is to take atiming.Instant()when the phase begins and passinstant.elapsed(). Where there is nothing to measure, the site passes the namedtiming.UNMEASUREDplaceholder (all zeros). unittest subtests are the one such site: unittest reports them after the fact, without timing. Their reported values are unchanged frommain; the zeros, inherited from pytest-subtests in #13738, are now just named.Backward compatibility: external code still uses the float API, so it is kept.
CallInfo(result, excinfo, start, stop, duration, when, _ispytest=True)is used by pytest-subtests (still widely installed, plus Debian/deepin packaging), pytest-asyncio-concurrent and NVIDIA's isvtest. It now builds theDurationfrom the floats.call.start = ...,call.stop = ...,call.duration = ...) is used by pytest-asyncio-cooperative and pytest-velo. Setters update the storedDurationindependently, so each field keeps its old meaning.timing.Instantfields becomeinit-able (still defaulting to "now") so aDurationcan represent externally supplied floats.Visible change:
dataclasses.fields(CallInfo)now lists_durationinstead ofstart/stop/duration, and==compares the storedDuration.Tests: a subtest regression test for mocked
time(fails onmain), a unittest subtest test assertingtiming.UNMEASURED, andtest_runner.pycoverage for_from_durationand for the float constructor and setters.