Skip to content

Fix timing output for unittest subtests#14453

Closed
Criseda wants to merge 1 commit intopytest-dev:mainfrom
Criseda:fix-subtest-timing
Closed

Fix timing output for unittest subtests#14453
Criseda wants to merge 1 commit intopytest-dev:mainfrom
Criseda:fix-subtest-timing

Conversation

@Criseda
Copy link
Copy Markdown

@Criseda Criseda commented May 9, 2026

Fixes #14412.

When console_output_style = times was used with unittest subtests, subtest rows could display 0.000us.

There turned out to be two separate issues behind this:

  • terminal timing aggregation tracked displayed timing by nodeid, but unittest subtest reports all share the same parent test nodeid
  • unittest SubtestReport instances were created with duration=0

This PR changes terminal timing so that SubtestReport rows display their own report duration directly, while normal test reports continue using the existing node-level aggregation logic.

On the unittest side the problem was that stdlib unittest only calls addSubTest() after a subtest has already completed, so pytest does not receive a start timestamp for the subtest body. My approach measures the public subTest() context manager boundary during TestCaseFunction.runtest() and restores the original method in finally.

This seemed like the narrowest approach that could provide accurate per-subtest durations while staying within the public unittest API surface.

A regression test was added using duplicate subTest() contexts so the fix does not rely on subtest context text being unique.

Tests run locally:

.\.venv\Scripts\pytest.exe testing/test_terminal.py testing/test_subtests.py -q -p no:cacheprovider --basetemp=C:\tmp\pytest-14412-final

Result:

254 passed, 9 skipped

I also ran pre-commit on the changed files during commit.

Copilot AI review requested due to automatic review settings May 9, 2026 13:46
@psf-chronographer psf-chronographer Bot added the bot:chronographer:provided (automation) changelog entry is part of PR label May 9, 2026
Copy link
Copy Markdown

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Fixes incorrect console_output_style = times output for unittest subtests by ensuring subtest rows show their own measured duration (instead of collapsing to 0.000us due to shared parent nodeid and previously-zero subtest CallInfo timing).

Changes:

  • Measure per-unittest-subTest durations by temporarily wrapping TestCase.subTest() during TestCaseFunction.runtest(), and use those timings when building SubtestReport CallInfo.
  • Update terminal “times” progress rendering to display SubtestReport.duration directly while keeping existing node-level aggregation for normal reports.
  • Add a regression test and a changelog entry.

Reviewed changes

Copilot reviewed 5 out of 5 changed files in this pull request and generated 1 comment.

Show a summary per file
File Description
testing/test_terminal.py Adds regression coverage for duplicate unittest subtests under console_output_style=times.
src/_pytest/unittest.py Captures per-subtest durations and propagates them into CallInfo for SubtestReport creation.
src/_pytest/terminal.py Prints subtest timing directly for console_output_style=times while preserving existing aggregation for non-subtests.
changelog/14412.bugfix.rst Documents the bugfix in the changelog.
AUTHORS Adds contributor attribution.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment thread testing/test_terminal.py Outdated
@Criseda Criseda force-pushed the fix-subtest-timing branch from 7420eb7 to b384d56 Compare May 9, 2026 14:16
@nicoddemus
Copy link
Copy Markdown
Member

Thanks, but I think the solution, as is, is too complex and hard to maintain, not being worth the cost.

@nicoddemus nicoddemus closed this May 9, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

bot:chronographer:provided (automation) changelog entry is part of PR

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Incorrect timing info when using subtests and console_output_style='times'

3 participants