Add confval `console_output_style` option `times` #13126

afcmrp · 2025-01-11T14:13:32Z

Adds an additional confval times to console_output_style.

Design decisions

Duration format

The duration format should be as short, detailed and human readable as possible. It also needs to predictable in terms of character length to know how much space to allocate to the right in the console output.

I landed on this:

00:30:59.1236 -> 30m 59s
00:00:10.1236 -> 10.124s
00:00:09.1236 -> 9.124s
00:00:00.1236 -> 123.6ms
00:00:00.01236 -> 12.36ms

This maintains relatively high resolution for all duration lengths, keeps the string maximum 7 characters long (for durations below 100 hours) and is pleasant to look at.

Verbose vs non-verbose

For the non-verbose case I decided to sum up the durations for all tests per file to keep things as consistent with the other console_output_style's as possible. Additionally, teardown is currently only counted for the non-verbose case.

Example output

Non-verbose

test_bar.py ..........                                                  4.094ms
test_foo.py .....                                                       2.013ms
test_foobar.py .....                                                    1.837ms

Verbose

test_bar.py::test_bar[0] PASSED                                         320.8us
test_bar.py::test_bar[1] PASSED                                         260.9us
test_bar.py::test_bar[2] PASSED                                         236.9us
test_bar.py::test_bar[3] PASSED                                         234.2us
test_bar.py::test_bar[4] PASSED                                         241.9us
test_bar.py::test_bar[5] PASSED                                         230.3us
test_bar.py::test_bar[6] PASSED                                         230.7us
test_bar.py::test_bar[7] PASSED                                         248.6us
test_bar.py::test_bar[8] PASSED                                         245.6us
test_bar.py::test_bar[9] PASSED                                         231.0us
test_foo.py::test_foo[0] PASSED                                         269.7us
test_foo.py::test_foo[1] PASSED                                         250.6us
test_foo.py::test_foo[2] PASSED                                         241.2us
test_foo.py::test_foo[3] PASSED                                         243.0us
test_foo.py::test_foo[4] PASSED                                         242.3us
test_foobar.py::test_foobar[0] PASSED                                   236.1us
test_foobar.py::test_foobar[1] PASSED                                   253.7us
test_foobar.py::test_foobar[2] PASSED                                   264.8us
test_foobar.py::test_foobar[3] PASSED                                   246.1us
test_foobar.py::test_foobar[4] PASSED                                   243.9us

Closes #13125

for more information, see https://pre-commit.ci

nicoddemus · 2025-01-11T14:25:14Z

@afcmrp can you add a sample output using the new option to the PR description?

afcmrp · 2025-01-11T14:31:11Z

@afcmrp can you add a sample output using the new option to the PR description?

@nicoddemus Yes of course.

Non-verbose:

test_bar.py ..........                                                  4.094ms
test_foo.py .....                                                       2.013ms
test_foobar.py .....                                                    1.837ms

Verbose:

test_bar.py::test_bar[0] PASSED                                         320.8us
test_bar.py::test_bar[1] PASSED                                         260.9us
test_bar.py::test_bar[2] PASSED                                         236.9us
test_bar.py::test_bar[3] PASSED                                         234.2us
test_bar.py::test_bar[4] PASSED                                         241.9us
test_bar.py::test_bar[5] PASSED                                         230.3us
test_bar.py::test_bar[6] PASSED                                         230.7us
test_bar.py::test_bar[7] PASSED                                         248.6us
test_bar.py::test_bar[8] PASSED                                         245.6us
test_bar.py::test_bar[9] PASSED                                         231.0us
test_foo.py::test_foo[0] PASSED                                         269.7us
test_foo.py::test_foo[1] PASSED                                         250.6us
test_foo.py::test_foo[2] PASSED                                         241.2us
test_foo.py::test_foo[3] PASSED                                         243.0us
test_foo.py::test_foo[4] PASSED                                         242.3us
test_foobar.py::test_foobar[0] PASSED                                   236.1us
test_foobar.py::test_foobar[1] PASSED                                   253.7us
test_foobar.py::test_foobar[2] PASSED                                   264.8us
test_foobar.py::test_foobar[3] PASSED                                   246.1us
test_foobar.py::test_foobar[4] PASSED                                   243.9us

for more information, see https://pre-commit.ci

nicoddemus · 2025-01-12T11:32:48Z

I like the output, thanks!

I will review the code ASAP.

nicoddemus

Overall this all looks great!

Playing around with it with xdist:

[gw0]101.1ms PASSED .tmp/test_bar.py::test_bar[0]
.tmp/test_bar.py::test_bar[1]
[gw0]541.1ms PASSED .tmp/test_bar.py::test_bar[1]
.tmp/test_bar.py::test_bar[6]
[gw2]179.7us PASSED .tmp/test_bar.py::test_bar[4]
.tmp/test_bar.py::test_bar[5]
[gw1]188.4us PASSED .tmp/test_bar.py::test_bar[2]

And without the option:

[gw2] [  6%] PASSED .tmp/test_bar.py::test_bar[4]
.tmp/test_bar.py::test_bar[5]
[gw0] [ 12%] PASSED .tmp/test_bar.py::test_bar[0]
.tmp/test_bar.py::test_bar[1]
[gw2] [ 18%] PASSED .tmp/test_bar.py::test_bar[5]
.tmp/test_bar.py::test_bar[6]
[gw1] [ 25%] PASSED .tmp/test_bar.py::test_bar[2]

The timing is "glued" to the gateway name ([gw0]101.1ms PASSED), I think it would look better if it was separated by a space ([gw0] 101.1ms PASSED).

Can you fix that and add a test for it?

testing/test_terminal.py

nicoddemus · 2025-01-16T10:55:33Z

Some final bikeshedding: perhaps the option should be timings or times, meaning what the user sees rather than the mechanism used to compute the times? But this is really minor.

afcmrp · 2025-01-17T14:18:14Z

Some final bikeshedding: perhaps the option should be timings or times, meaning what the user sees rather than the mechanism used to compute the times? But this is really minor.

Yes, agreed. Of those two I prefer times, shorter and closer to "base" form of the word. Do you think anyone else have a good idea for what to name it?

nicoddemus · 2025-01-17T14:31:55Z

Of those two I prefer times, shorter and closer to "base" form of the word. Do you think anyone else have a good idea for what to name it?

To me times sounds good. 👍

Co-authored-by: Bruno Oliveira <[email protected]>

nicoddemus

Awesome, thanks, excellent contribution!

I will leave this open for a few more days to give others a chance to chime in.

changelog/13125.feature.rst

afcmrp and others added 5 commits January 6, 2025 00:00

Added console_output_style 'timer'

946c9f6

Lint fixes

8adec2c

Merge branch 'pytest-dev:main' into main

Verified

This commit was created on GitHub.com and signed with GitHub’s verified signature.

GPG key ID: B5690EEEBB952194

Verified
Learn about vigilant mode

4747566

Added changelog entry

8994339

Merge branch 'main' of https://github.com/afcmrp/pytest

Loading
Loading status checks…

ba67685

psf-chronographer bot added the bot:chronographer:provided label Jan 11, 2025

pre-commit-ci bot and others added 3 commits January 11, 2025 14:13

[pre-commit.ci] auto fixes from pre-commit.com hooks

Loading
Loading status checks…

425254b

for more information, see https://pre-commit.ci

Lint fixes

8169b6d

Merge branch 'main' of https://github.com/afcmrp/pytest

Loading
Loading status checks…

bfde3f0

afcmrp and others added 5 commits January 11, 2025 17:35

Test multiline non-verbose timer

Loading
Loading status checks…

9f666a4

[pre-commit.ci] auto fixes from pre-commit.com hooks

Loading
Loading status checks…

982498d

for more information, see https://pre-commit.ci

Merge branch 'main' into main

Verified

This commit was created on GitHub.com and signed with GitHub’s verified signature.

GPG key ID: B5690EEEBB952194

Verified
Learn about vigilant mode

Loading
Loading status checks…

899f02a

Increase test coverage

Loading
Loading status checks…

9a26191

Merge branch 'main' into main

Verified

This commit was created on GitHub.com and signed with GitHub’s verified signature.

GPG key ID: B5690EEEBB952194

Verified
Learn about vigilant mode

Loading
Loading status checks…

70bac53

nicoddemus requested changes Jan 16, 2025

View reviewed changes

testing/test_terminal.py Outdated Show resolved Hide resolved

afcmrp and others added 3 commits January 17, 2025 19:41

Update testing/test_terminal.py

Verified

This commit was created on GitHub.com and signed with GitHub’s verified signature.

GPG key ID: B5690EEEBB952194

Verified
Learn about vigilant mode

Loading
Loading status checks…

5e1721c

Co-authored-by: Bruno Oliveira <[email protected]>

Merge branch 'main' into main

Verified

This commit was created on GitHub.com and signed with GitHub’s verified signature.

GPG key ID: B5690EEEBB952194

Verified
Learn about vigilant mode

Loading
Loading status checks…

4f87263

timer -> times + fixed bad times format when used with xdist

Loading
Loading status checks…

d98eee0

afcmrp changed the title ~~Add confval console_output_style option timer~~ Add confval console_output_style option times Jan 17, 2025

nicoddemus approved these changes Jan 17, 2025

View reviewed changes

changelog/13125.feature.rst Outdated Show resolved Hide resolved

Update changelog/13125.feature.rst

Verified

This commit was created on GitHub.com and signed with GitHub’s verified signature.

GPG key ID: B5690EEEBB952194

Verified
Learn about vigilant mode

Loading
Loading status checks…

e58c9e3

nicoddemus merged commit b89c1ce into pytest-dev:main Jan 20, 2025
28 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add confval `console_output_style` option `times` #13126

Add confval `console_output_style` option `times` #13126

afcmrp commented Jan 11, 2025 •

edited

Loading

nicoddemus commented Jan 11, 2025

afcmrp commented Jan 11, 2025

nicoddemus commented Jan 12, 2025

nicoddemus left a comment •

edited

Loading

nicoddemus commented Jan 16, 2025

afcmrp commented Jan 17, 2025

nicoddemus commented Jan 17, 2025

nicoddemus left a comment

Add confval console_output_style option times #13126

Add confval console_output_style option times #13126

Conversation

afcmrp commented Jan 11, 2025 • edited Loading

Design decisions

Duration format

Verbose vs non-verbose

Example output

Non-verbose

Verbose

nicoddemus commented Jan 11, 2025

afcmrp commented Jan 11, 2025

nicoddemus commented Jan 12, 2025

nicoddemus left a comment • edited Loading

Choose a reason for hiding this comment

nicoddemus commented Jan 16, 2025

afcmrp commented Jan 17, 2025

nicoddemus commented Jan 17, 2025

nicoddemus left a comment

Choose a reason for hiding this comment

Add confval `console_output_style` option `times` #13126

Add confval `console_output_style` option `times` #13126

afcmrp commented Jan 11, 2025 •

edited

Loading

nicoddemus left a comment •

edited

Loading