From 946c9f68daaa7b4418aaaa638a3ee36ca2f44b59 Mon Sep 17 00:00:00 2001 From: Emil Hjelm Date: Mon, 6 Jan 2025 00:00:15 +0100 Subject: [PATCH 01/11] Added console_output_style 'timer' --- AUTHORS | 1 + doc/en/reference/reference.rst | 1 + src/_pytest/terminal.py | 67 ++++++++++++++++++++++++++++++---- testing/test_terminal.py | 67 ++++++++++++++++++++++++++++++++++ 4 files changed, 129 insertions(+), 7 deletions(-) diff --git a/AUTHORS b/AUTHORS index 9629e00bcfb..b9b55b53461 100644 --- a/AUTHORS +++ b/AUTHORS @@ -142,6 +142,7 @@ Eero Vaher Eli Boyarski Elizaveta Shashkova Éloi Rivard +Emil Hjelm Endre Galaczi Eric Hunsberger Eric Liu diff --git a/doc/en/reference/reference.rst b/doc/en/reference/reference.rst index 26572174ad4..ccf1521dedd 100644 --- a/doc/en/reference/reference.rst +++ b/doc/en/reference/reference.rst @@ -1355,6 +1355,7 @@ passed multiple times. The expected format is ``name=value``. For example:: * ``progress``: like classic pytest output, but with a progress indicator. * ``progress-even-when-capture-no``: allows the use of the progress indicator even when ``capture=no``. * ``count``: like progress, but shows progress as the number of tests completed instead of a percent. + * ``timer``: show tests duration. The default is ``progress``, but you can fallback to ``classic`` if you prefer or the new mode is causing unexpected problems: diff --git a/src/_pytest/terminal.py b/src/_pytest/terminal.py index 348a78af9f5..c446e5f0bd3 100644 --- a/src/_pytest/terminal.py +++ b/src/_pytest/terminal.py @@ -382,12 +382,13 @@ def __init__(self, config: Config, file: TextIO | None = None) -> None: self.hasmarkup = self._tw.hasmarkup self.isatty = file.isatty() self._progress_nodeids_reported: set[str] = set() + self._timing_nodeids_reported: set[str] = set() self._show_progress_info = self._determine_show_progress_info() self._collect_report_last_write: float | None = None self._already_displayed_warnings: int | None = None self._keyboardinterrupt_memo: ExceptionRepr | None = None - def _determine_show_progress_info(self) -> Literal["progress", "count", False]: + def _determine_show_progress_info(self) -> Literal["progress", "count", "timer", False]: """Return whether we should display progress information based on the current config.""" # do not show progress if we are not capturing output (#3038) unless explicitly # overridden by progress-even-when-capture-no @@ -405,6 +406,8 @@ def _determine_show_progress_info(self) -> Literal["progress", "count", False]: return "progress" elif cfg == "count": return "count" + elif cfg == "timer": + return "timer" else: return False @@ -692,12 +695,37 @@ def _get_progress_information_message(self) -> str: format_string = f" [{counter_format}/{{}}]" return format_string.format(progress, collected) return f" [ {collected} / {collected} ]" - else: - if collected: - return ( - f" [{len(self._progress_nodeids_reported) * 100 // collected:3d}%]" - ) - return " [100%]" + if self._show_progress_info == "timer": + if not collected: + return "" + all_reports = self._get_reports_to_display("passed") \ + + self._get_reports_to_display("xpassed") \ + + self._get_reports_to_display("failed") \ + + self._get_reports_to_display("xfailed") \ + + self._get_reports_to_display("skipped") \ + + self._get_reports_to_display("error") \ + + self._get_reports_to_display("") + current_location = all_reports[-1].location[0] + not_reported = [ + r for r in all_reports + if r.nodeid not in self._timing_nodeids_reported + ] + tests_in_module = sum( + i.location[0] == current_location for i in self._session.items + ) + tests_completed = sum( + r.when == "setup" for r in not_reported if r.location[0] == current_location + ) + last_in_module = tests_completed == tests_in_module + if self.showlongtestinfo or last_in_module: + self._timing_nodeids_reported.update(r.nodeid for r in not_reported) + return format_node_duration(sum(r.duration for r in not_reported)) + return "" + if collected: + return ( + f" [{len(self._progress_nodeids_reported) * 100 // collected:3d}%]" + ) + return " [100%]" def _write_progress_information_if_past_edge(self) -> None: w = self._width_of_current_line @@ -705,6 +733,8 @@ def _write_progress_information_if_past_edge(self) -> None: assert self._session num_tests = self._session.testscollected progress_length = len(f" [{num_tests}/{num_tests}]") + elif self._show_progress_info == "timer": + progress_length = len(" 99h 59m") else: progress_length = len(" [100%]") past_edge = w + progress_length + 1 >= self._screen_width @@ -1554,6 +1584,29 @@ def format_session_duration(seconds: float) -> str: return f"{seconds:.2f}s ({dt})" +def format_node_duration(seconds: float) -> str: + """Format the given seconds in a human readable manner to show in the test progress.""" + # The formatting is designed to be compact and readable, with at most 7 characters + # for durations below 100 hours. + if seconds < 0.00001: + return f"{seconds*1000000:.3f}us" + if seconds < 0.0001: + return f"{seconds*1000000:.2f}us" + if seconds < 0.001: + return f"{seconds*1000000:.1f}us" + if seconds < 0.01: + return f"{seconds*1000:.3f}ms" + if seconds < 0.1: + return f"{seconds*1000:.2f}ms" + if seconds < 1: + return f"{seconds*1000:.1f}ms" + if seconds < 60: + return f"{seconds:.3f}s" + if seconds < 3600: + return f"{seconds//60:.0f}m {seconds%60:.0f}s" + return f"{seconds//3600:.0f}h {(seconds%3600)//60:.0f}m" + + def _get_raw_skip_reason(report: TestReport) -> str: """Get the reason string of a skip/xfail/xpass test report. diff --git a/testing/test_terminal.py b/testing/test_terminal.py index 6fa04be28b1..9b5d0fd23e3 100644 --- a/testing/test_terminal.py +++ b/testing/test_terminal.py @@ -2169,6 +2169,29 @@ def test_count(self, many_tests_files, pytester: Pytester) -> None: ] ) + def test_timer(self, many_tests_files, pytester: Pytester) -> None: + from _pytest.terminal import format_node_duration + + pytester.makeini( + """ + [pytest] + console_output_style = timer + """ + ) + output = pytester.runpytest() + reporter = output.reprec.getcall("pytest_terminal_summary").terminalreporter + reports = reporter.getreports("") + reporter.getreports("passed") + bar_time = format_node_duration(sum(r.duration for r in reports if r.fspath == "test_bar.py")) + foo_time = format_node_duration(sum(r.duration for r in reports if r.fspath == "test_foo.py")) + foobar_time = format_node_duration(sum(r.duration for r in reports if r.fspath == "test_foobar.py")) + output.stdout.re_match_lines( + [ + r"test_bar.py \.{10} \s+" + bar_time, + r"test_foo.py \.{5} \s+ " + foo_time, + r"test_foobar.py \.{5} \s+ " + foobar_time, + ] + ) + def test_verbose(self, many_tests_files, pytester: Pytester) -> None: output = pytester.runpytest("-v") output.stdout.re_match_lines( @@ -2195,6 +2218,29 @@ def test_verbose_count(self, many_tests_files, pytester: Pytester) -> None: ] ) + def test_verbose_timer(self, many_tests_files, pytester: Pytester) -> None: + from _pytest.terminal import format_node_duration + + pytester.makeini( + """ + [pytest] + console_output_style = timer + """ + ) + output = pytester.runpytest("-v") + reporter = output.reprec.getcall("pytest_terminal_summary").terminalreporter + reports = reporter.getreports("") + reporter.getreports("passed") + bar_time = format_node_duration(sum(r.duration for r in reports if r.head_line == "test_bar[0]" and r.when != "teardown")) + foo_time = format_node_duration(sum(r.duration for r in reports if r.head_line == "test_foo[4]" and r.when != "teardown")) + foobar_time = format_node_duration(sum(r.duration for r in reports if r.head_line == "test_foobar[4]" and r.when != "teardown")) + output.stdout.re_match_lines( + [ + r"test_bar.py::test_bar\[0\] PASSED \s+ " + bar_time, + r"test_foo.py::test_foo\[4\] PASSED \s+ " + foo_time, + r"test_foobar.py::test_foobar\[4\] PASSED \s+ " + foobar_time, + ] + ) + def test_xdist_normal( self, many_tests_files, pytester: Pytester, monkeypatch ) -> None: @@ -2537,6 +2583,27 @@ def test_format_session_duration(seconds, expected): assert format_session_duration(seconds) == expected +@pytest.mark.parametrize( + "seconds, expected", + [ + (3600 * 100 - 60, "99h 59m"), + (31 * 60 - 1, "30m 59s"), + (10.1236, "10.124s"), + (9.1236, "9.124s"), + (0.1236, "123.6ms"), + (0.01236, "12.36ms"), + (0.001236, "1.236ms"), + (0.0001236, "123.6us"), + (0.00001236, "12.36us"), + (0.000001236, "1.236us"), + ], +) +def test_format_node_duration(seconds, expected): + from _pytest.terminal import format_node_duration + + assert format_node_duration(seconds) == expected + + def test_collecterror(pytester: Pytester) -> None: p1 = pytester.makepyfile("raise SyntaxError()") result = pytester.runpytest("-ra", str(p1)) From 8adec2c2912089393371be4b946ffa37f7db0a0d Mon Sep 17 00:00:00 2001 From: Emil Hjelm Date: Mon, 6 Jan 2025 00:32:17 +0100 Subject: [PATCH 02/11] Lint fixes --- src/_pytest/terminal.py | 29 ++++++++++++++++------------- testing/test_terminal.py | 26 ++++++-------------------- 2 files changed, 22 insertions(+), 33 deletions(-) diff --git a/src/_pytest/terminal.py b/src/_pytest/terminal.py index c446e5f0bd3..27c1c369eae 100644 --- a/src/_pytest/terminal.py +++ b/src/_pytest/terminal.py @@ -388,7 +388,9 @@ def __init__(self, config: Config, file: TextIO | None = None) -> None: self._already_displayed_warnings: int | None = None self._keyboardinterrupt_memo: ExceptionRepr | None = None - def _determine_show_progress_info(self) -> Literal["progress", "count", "timer", False]: + def _determine_show_progress_info( + self, + ) -> Literal["progress", "count", "timer", False]: """Return whether we should display progress information based on the current config.""" # do not show progress if we are not capturing output (#3038) unless explicitly # overridden by progress-even-when-capture-no @@ -698,23 +700,26 @@ def _get_progress_information_message(self) -> str: if self._show_progress_info == "timer": if not collected: return "" - all_reports = self._get_reports_to_display("passed") \ - + self._get_reports_to_display("xpassed") \ - + self._get_reports_to_display("failed") \ - + self._get_reports_to_display("xfailed") \ - + self._get_reports_to_display("skipped") \ - + self._get_reports_to_display("error") \ + all_reports = ( + self._get_reports_to_display("passed") + + self._get_reports_to_display("xpassed") + + self._get_reports_to_display("failed") + + self._get_reports_to_display("xfailed") + + self._get_reports_to_display("skipped") + + self._get_reports_to_display("error") + self._get_reports_to_display("") + ) current_location = all_reports[-1].location[0] not_reported = [ - r for r in all_reports - if r.nodeid not in self._timing_nodeids_reported + r for r in all_reports if r.nodeid not in self._timing_nodeids_reported ] tests_in_module = sum( i.location[0] == current_location for i in self._session.items ) tests_completed = sum( - r.when == "setup" for r in not_reported if r.location[0] == current_location + r.when == "setup" + for r in not_reported + if r.location[0] == current_location ) last_in_module = tests_completed == tests_in_module if self.showlongtestinfo or last_in_module: @@ -722,9 +727,7 @@ def _get_progress_information_message(self) -> str: return format_node_duration(sum(r.duration for r in not_reported)) return "" if collected: - return ( - f" [{len(self._progress_nodeids_reported) * 100 // collected:3d}%]" - ) + return f" [{len(self._progress_nodeids_reported) * 100 // collected:3d}%]" return " [100%]" def _write_progress_information_if_past_edge(self) -> None: diff --git a/testing/test_terminal.py b/testing/test_terminal.py index 9b5d0fd23e3..f12c4f13965 100644 --- a/testing/test_terminal.py +++ b/testing/test_terminal.py @@ -2170,8 +2170,6 @@ def test_count(self, many_tests_files, pytester: Pytester) -> None: ) def test_timer(self, many_tests_files, pytester: Pytester) -> None: - from _pytest.terminal import format_node_duration - pytester.makeini( """ [pytest] @@ -2179,16 +2177,11 @@ def test_timer(self, many_tests_files, pytester: Pytester) -> None: """ ) output = pytester.runpytest() - reporter = output.reprec.getcall("pytest_terminal_summary").terminalreporter - reports = reporter.getreports("") + reporter.getreports("passed") - bar_time = format_node_duration(sum(r.duration for r in reports if r.fspath == "test_bar.py")) - foo_time = format_node_duration(sum(r.duration for r in reports if r.fspath == "test_foo.py")) - foobar_time = format_node_duration(sum(r.duration for r in reports if r.fspath == "test_foobar.py")) output.stdout.re_match_lines( [ - r"test_bar.py \.{10} \s+" + bar_time, - r"test_foo.py \.{5} \s+ " + foo_time, - r"test_foobar.py \.{5} \s+ " + foobar_time, + r"test_bar.py \.{10} \s+ \d{1,3}[\.[a-z\ ]{1,2}\d{0,3}\w{1,2}$", + r"test_foo.py \.{5} \s+ \d{1,3}[\.[a-z\ ]{1,2}\d{0,3}\w{1,2}$", + r"test_foobar.py \.{5} \s+ \d{1,3}[\.[a-z\ ]{1,2}\d{0,3}\w{1,2}$", ] ) @@ -2219,8 +2212,6 @@ def test_verbose_count(self, many_tests_files, pytester: Pytester) -> None: ) def test_verbose_timer(self, many_tests_files, pytester: Pytester) -> None: - from _pytest.terminal import format_node_duration - pytester.makeini( """ [pytest] @@ -2228,16 +2219,11 @@ def test_verbose_timer(self, many_tests_files, pytester: Pytester) -> None: """ ) output = pytester.runpytest("-v") - reporter = output.reprec.getcall("pytest_terminal_summary").terminalreporter - reports = reporter.getreports("") + reporter.getreports("passed") - bar_time = format_node_duration(sum(r.duration for r in reports if r.head_line == "test_bar[0]" and r.when != "teardown")) - foo_time = format_node_duration(sum(r.duration for r in reports if r.head_line == "test_foo[4]" and r.when != "teardown")) - foobar_time = format_node_duration(sum(r.duration for r in reports if r.head_line == "test_foobar[4]" and r.when != "teardown")) output.stdout.re_match_lines( [ - r"test_bar.py::test_bar\[0\] PASSED \s+ " + bar_time, - r"test_foo.py::test_foo\[4\] PASSED \s+ " + foo_time, - r"test_foobar.py::test_foobar\[4\] PASSED \s+ " + foobar_time, + r"test_bar.py::test_bar\[0\] PASSED \s+ \d{1,3}[\.[a-z\ ]{1,2}\d{0,3}\w{1,2}$", + r"test_foo.py::test_foo\[4\] PASSED \s+ \d{1,3}[\.[a-z\ ]{1,2}\d{0,3}\w{1,2}$", + r"test_foobar.py::test_foobar\[4\] PASSED \s+ \d{1,3}[\.[a-z\ ]{1,2}\d{0,3}\w{1,2}$", ] ) From 89943390c2f81b4f7fc5f36e9ef22930e8b22c3f Mon Sep 17 00:00:00 2001 From: Emil Hjelm Date: Sat, 11 Jan 2025 14:28:31 +0100 Subject: [PATCH 03/11] Added changelog entry --- changelog/13125.feature.rst | 1 + 1 file changed, 1 insertion(+) create mode 100644 changelog/13125.feature.rst diff --git a/changelog/13125.feature.rst b/changelog/13125.feature.rst new file mode 100644 index 00000000000..fb542b028cf --- /dev/null +++ b/changelog/13125.feature.rst @@ -0,0 +1 @@ +:confval:`console_output_style` now supports ``timer`` to show execution time of each test. From 425254bd1a1a35c6ed97e426ce6d6c3b30fd970a Mon Sep 17 00:00:00 2001 From: "pre-commit-ci[bot]" <66853113+pre-commit-ci[bot]@users.noreply.github.com> Date: Sat, 11 Jan 2025 14:13:52 +0000 Subject: [PATCH 04/11] [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci --- src/_pytest/terminal.py | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/src/_pytest/terminal.py b/src/_pytest/terminal.py index 27c1c369eae..598d5995083 100644 --- a/src/_pytest/terminal.py +++ b/src/_pytest/terminal.py @@ -1592,22 +1592,22 @@ def format_node_duration(seconds: float) -> str: # The formatting is designed to be compact and readable, with at most 7 characters # for durations below 100 hours. if seconds < 0.00001: - return f"{seconds*1000000:.3f}us" + return f"{seconds * 1000000:.3f}us" if seconds < 0.0001: - return f"{seconds*1000000:.2f}us" + return f"{seconds * 1000000:.2f}us" if seconds < 0.001: - return f"{seconds*1000000:.1f}us" + return f"{seconds * 1000000:.1f}us" if seconds < 0.01: - return f"{seconds*1000:.3f}ms" + return f"{seconds * 1000:.3f}ms" if seconds < 0.1: - return f"{seconds*1000:.2f}ms" + return f"{seconds * 1000:.2f}ms" if seconds < 1: - return f"{seconds*1000:.1f}ms" + return f"{seconds * 1000:.1f}ms" if seconds < 60: return f"{seconds:.3f}s" if seconds < 3600: - return f"{seconds//60:.0f}m {seconds%60:.0f}s" - return f"{seconds//3600:.0f}h {(seconds%3600)//60:.0f}m" + return f"{seconds // 60:.0f}m {seconds % 60:.0f}s" + return f"{seconds // 3600:.0f}h {(seconds % 3600) // 60:.0f}m" def _get_raw_skip_reason(report: TestReport) -> str: From 8169b6d63a30cb50e616647c30df1d95f33148c1 Mon Sep 17 00:00:00 2001 From: Emil Hjelm Date: Sat, 11 Jan 2025 15:15:27 +0100 Subject: [PATCH 05/11] Lint fixes --- src/_pytest/terminal.py | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/src/_pytest/terminal.py b/src/_pytest/terminal.py index 27c1c369eae..598d5995083 100644 --- a/src/_pytest/terminal.py +++ b/src/_pytest/terminal.py @@ -1592,22 +1592,22 @@ def format_node_duration(seconds: float) -> str: # The formatting is designed to be compact and readable, with at most 7 characters # for durations below 100 hours. if seconds < 0.00001: - return f"{seconds*1000000:.3f}us" + return f"{seconds * 1000000:.3f}us" if seconds < 0.0001: - return f"{seconds*1000000:.2f}us" + return f"{seconds * 1000000:.2f}us" if seconds < 0.001: - return f"{seconds*1000000:.1f}us" + return f"{seconds * 1000000:.1f}us" if seconds < 0.01: - return f"{seconds*1000:.3f}ms" + return f"{seconds * 1000:.3f}ms" if seconds < 0.1: - return f"{seconds*1000:.2f}ms" + return f"{seconds * 1000:.2f}ms" if seconds < 1: - return f"{seconds*1000:.1f}ms" + return f"{seconds * 1000:.1f}ms" if seconds < 60: return f"{seconds:.3f}s" if seconds < 3600: - return f"{seconds//60:.0f}m {seconds%60:.0f}s" - return f"{seconds//3600:.0f}h {(seconds%3600)//60:.0f}m" + return f"{seconds // 60:.0f}m {seconds % 60:.0f}s" + return f"{seconds // 3600:.0f}h {(seconds % 3600) // 60:.0f}m" def _get_raw_skip_reason(report: TestReport) -> str: From 9f666a4aa0cfb1bcc16f7fdeefe79edf5f8e1362 Mon Sep 17 00:00:00 2001 From: Emil Hjelm Date: Sat, 11 Jan 2025 17:35:02 +0100 Subject: [PATCH 06/11] Test multiline non-verbose timer --- testing/test_terminal.py | 35 +++++++++++++++++++++++++++++++++++ 1 file changed, 35 insertions(+) diff --git a/testing/test_terminal.py b/testing/test_terminal.py index 22c6ab2afc6..682cc82ea76 100644 --- a/testing/test_terminal.py +++ b/testing/test_terminal.py @@ -2073,6 +2073,21 @@ def test_foobar(i): pass """, ) + @pytest.fixture + def more_tests_files(self, pytester: Pytester) -> None: + pytester.makepyfile( + test_bar=""" + import pytest + @pytest.mark.parametrize('i', range(30)) + def test_bar(i): pass + """, + test_foo=""" + import pytest + @pytest.mark.parametrize('i', range(5)) + def test_foo(i): pass + """, + ) + def test_zero_tests_collected(self, pytester: Pytester) -> None: """Some plugins (testmon for example) might issue pytest_runtest_logreport without any tests being actually collected (#2971).""" @@ -2185,6 +2200,26 @@ def test_timer(self, many_tests_files, pytester: Pytester) -> None: ] ) + def test_timer_multiline( + self, more_tests_files, monkeypatch, pytester: Pytester + ) -> None: + monkeypatch.setenv("COLUMNS", "40") + pytester.makeini( + """ + [pytest] + console_output_style = timer + """ + ) + output = pytester.runpytest() + output.stdout.re_match_lines( + [ + r"test_bar.py ...................", + r"........... \s+ \d{1,3}[\.[a-z\ ]{1,2}\d{0,3}\w{1,2}$", + r"test_foo.py \.{5} \s+ \d{1,3}[\.[a-z\ ]{1,2}\d{0,3}\w{1,2}$", + ], + consecutive=True + ) + def test_verbose(self, many_tests_files, pytester: Pytester) -> None: output = pytester.runpytest("-v") output.stdout.re_match_lines( From 982498d52431f1750eace4a8b6cd2100095119bb Mon Sep 17 00:00:00 2001 From: "pre-commit-ci[bot]" <66853113+pre-commit-ci[bot]@users.noreply.github.com> Date: Sat, 11 Jan 2025 16:35:30 +0000 Subject: [PATCH 07/11] [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci --- testing/test_terminal.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/testing/test_terminal.py b/testing/test_terminal.py index 682cc82ea76..026673e1391 100644 --- a/testing/test_terminal.py +++ b/testing/test_terminal.py @@ -2217,7 +2217,7 @@ def test_timer_multiline( r"........... \s+ \d{1,3}[\.[a-z\ ]{1,2}\d{0,3}\w{1,2}$", r"test_foo.py \.{5} \s+ \d{1,3}[\.[a-z\ ]{1,2}\d{0,3}\w{1,2}$", ], - consecutive=True + consecutive=True, ) def test_verbose(self, many_tests_files, pytester: Pytester) -> None: From 9a26191f8789234cd1f2c669fe00b2f4a2be4669 Mon Sep 17 00:00:00 2001 From: Emil Hjelm Date: Sat, 11 Jan 2025 21:42:50 +0100 Subject: [PATCH 08/11] Increase test coverage --- testing/test_terminal.py | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/testing/test_terminal.py b/testing/test_terminal.py index 026673e1391..e19302fea12 100644 --- a/testing/test_terminal.py +++ b/testing/test_terminal.py @@ -2220,6 +2220,16 @@ def test_timer_multiline( consecutive=True, ) + def test_timer_none_collected(self, pytester: Pytester) -> None: + pytester.makeini( + """ + [pytest] + console_output_style = timer + """ + ) + output = pytester.runpytest() + assert output.ret == ExitCode.NO_TESTS_COLLECTED + def test_verbose(self, many_tests_files, pytester: Pytester) -> None: output = pytester.runpytest("-v") output.stdout.re_match_lines( From 5e1721c131543caa68f5503bd5a7d6d1c1de9cc3 Mon Sep 17 00:00:00 2001 From: Emil Hjelm Date: Fri, 17 Jan 2025 19:41:25 +0100 Subject: [PATCH 09/11] Update testing/test_terminal.py Co-authored-by: Bruno Oliveira --- testing/test_terminal.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/testing/test_terminal.py b/testing/test_terminal.py index e19302fea12..e0b6a111a6b 100644 --- a/testing/test_terminal.py +++ b/testing/test_terminal.py @@ -2629,7 +2629,7 @@ def test_format_session_duration(seconds, expected): (0.000001236, "1.236us"), ], ) -def test_format_node_duration(seconds, expected): +def test_format_node_duration(seconds: float, expected: str) -> None: from _pytest.terminal import format_node_duration assert format_node_duration(seconds) == expected From d98eee099afbe9cfdc070bd035a012892d31796f Mon Sep 17 00:00:00 2001 From: Emil Hjelm Date: Fri, 17 Jan 2025 20:13:47 +0100 Subject: [PATCH 10/11] timer -> times + fixed bad times format when used with xdist --- doc/en/reference/reference.rst | 2 +- src/_pytest/terminal.py | 28 ++++++++--------- testing/test_terminal.py | 56 +++++++++++++++++++++++----------- 3 files changed, 53 insertions(+), 33 deletions(-) diff --git a/doc/en/reference/reference.rst b/doc/en/reference/reference.rst index ccf1521dedd..809e97b4747 100644 --- a/doc/en/reference/reference.rst +++ b/doc/en/reference/reference.rst @@ -1355,7 +1355,7 @@ passed multiple times. The expected format is ``name=value``. For example:: * ``progress``: like classic pytest output, but with a progress indicator. * ``progress-even-when-capture-no``: allows the use of the progress indicator even when ``capture=no``. * ``count``: like progress, but shows progress as the number of tests completed instead of a percent. - * ``timer``: show tests duration. + * ``times``: show tests duration. The default is ``progress``, but you can fallback to ``classic`` if you prefer or the new mode is causing unexpected problems: diff --git a/src/_pytest/terminal.py b/src/_pytest/terminal.py index 598d5995083..1d58bb9c8e8 100644 --- a/src/_pytest/terminal.py +++ b/src/_pytest/terminal.py @@ -390,7 +390,7 @@ def __init__(self, config: Config, file: TextIO | None = None) -> None: def _determine_show_progress_info( self, - ) -> Literal["progress", "count", "timer", False]: + ) -> Literal["progress", "count", "times", False]: """Return whether we should display progress information based on the current config.""" # do not show progress if we are not capturing output (#3038) unless explicitly # overridden by progress-even-when-capture-no @@ -408,8 +408,8 @@ def _determine_show_progress_info( return "progress" elif cfg == "count": return "count" - elif cfg == "timer": - return "timer" + elif cfg == "times": + return "times" else: return False @@ -697,7 +697,7 @@ def _get_progress_information_message(self) -> str: format_string = f" [{counter_format}/{{}}]" return format_string.format(progress, collected) return f" [ {collected} / {collected} ]" - if self._show_progress_info == "timer": + if self._show_progress_info == "times": if not collected: return "" all_reports = ( @@ -736,7 +736,7 @@ def _write_progress_information_if_past_edge(self) -> None: assert self._session num_tests = self._session.testscollected progress_length = len(f" [{num_tests}/{num_tests}]") - elif self._show_progress_info == "timer": + elif self._show_progress_info == "times": progress_length = len(" 99h 59m") else: progress_length = len(" [100%]") @@ -1592,22 +1592,22 @@ def format_node_duration(seconds: float) -> str: # The formatting is designed to be compact and readable, with at most 7 characters # for durations below 100 hours. if seconds < 0.00001: - return f"{seconds * 1000000:.3f}us" + return f" {seconds * 1000000:.3f}us" if seconds < 0.0001: - return f"{seconds * 1000000:.2f}us" + return f" {seconds * 1000000:.2f}us" if seconds < 0.001: - return f"{seconds * 1000000:.1f}us" + return f" {seconds * 1000000:.1f}us" if seconds < 0.01: - return f"{seconds * 1000:.3f}ms" + return f" {seconds * 1000:.3f}ms" if seconds < 0.1: - return f"{seconds * 1000:.2f}ms" + return f" {seconds * 1000:.2f}ms" if seconds < 1: - return f"{seconds * 1000:.1f}ms" + return f" {seconds * 1000:.1f}ms" if seconds < 60: - return f"{seconds:.3f}s" + return f" {seconds:.3f}s" if seconds < 3600: - return f"{seconds // 60:.0f}m {seconds % 60:.0f}s" - return f"{seconds // 3600:.0f}h {(seconds % 3600) // 60:.0f}m" + return f" {seconds // 60:.0f}m {seconds % 60:.0f}s" + return f" {seconds // 3600:.0f}h {(seconds % 3600) // 60:.0f}m" def _get_raw_skip_reason(report: TestReport) -> str: diff --git a/testing/test_terminal.py b/testing/test_terminal.py index e0b6a111a6b..84c92753546 100644 --- a/testing/test_terminal.py +++ b/testing/test_terminal.py @@ -2184,11 +2184,11 @@ def test_count(self, many_tests_files, pytester: Pytester) -> None: ] ) - def test_timer(self, many_tests_files, pytester: Pytester) -> None: + def test_times(self, many_tests_files, pytester: Pytester) -> None: pytester.makeini( """ [pytest] - console_output_style = timer + console_output_style = times """ ) output = pytester.runpytest() @@ -2200,14 +2200,14 @@ def test_timer(self, many_tests_files, pytester: Pytester) -> None: ] ) - def test_timer_multiline( + def test_times_multiline( self, more_tests_files, monkeypatch, pytester: Pytester ) -> None: monkeypatch.setenv("COLUMNS", "40") pytester.makeini( """ [pytest] - console_output_style = timer + console_output_style = times """ ) output = pytester.runpytest() @@ -2220,11 +2220,11 @@ def test_timer_multiline( consecutive=True, ) - def test_timer_none_collected(self, pytester: Pytester) -> None: + def test_times_none_collected(self, pytester: Pytester) -> None: pytester.makeini( """ [pytest] - console_output_style = timer + console_output_style = times """ ) output = pytester.runpytest() @@ -2256,11 +2256,11 @@ def test_verbose_count(self, many_tests_files, pytester: Pytester) -> None: ] ) - def test_verbose_timer(self, many_tests_files, pytester: Pytester) -> None: + def test_verbose_times(self, many_tests_files, pytester: Pytester) -> None: pytester.makeini( """ [pytest] - console_output_style = timer + console_output_style = times """ ) output = pytester.runpytest("-v") @@ -2324,6 +2324,26 @@ def test_xdist_verbose( ] ) + def test_xdist_times( + self, many_tests_files, pytester: Pytester, monkeypatch + ) -> None: + pytest.importorskip("xdist") + monkeypatch.delenv("PYTEST_DISABLE_PLUGIN_AUTOLOAD", raising=False) + pytester.makeini( + """ + [pytest] + console_output_style = times + """ + ) + output = pytester.runpytest("-n2", "-v") + output.stdout.re_match_lines_random( + [ + r"\[gw\d\] \d{1,3}[\.[a-z\ ]{1,2}\d{0,3}\w{1,2} PASSED test_bar.py::test_bar\[1\]", + r"\[gw\d\] \d{1,3}[\.[a-z\ ]{1,2}\d{0,3}\w{1,2} PASSED test_foo.py::test_foo\[1\]", + r"\[gw\d\] \d{1,3}[\.[a-z\ ]{1,2}\d{0,3}\w{1,2} PASSED test_foobar.py::test_foobar\[1\]", + ] + ) + def test_capture_no(self, many_tests_files, pytester: Pytester) -> None: output = pytester.runpytest("-s") output.stdout.re_match_lines( @@ -2617,16 +2637,16 @@ def test_format_session_duration(seconds, expected): @pytest.mark.parametrize( "seconds, expected", [ - (3600 * 100 - 60, "99h 59m"), - (31 * 60 - 1, "30m 59s"), - (10.1236, "10.124s"), - (9.1236, "9.124s"), - (0.1236, "123.6ms"), - (0.01236, "12.36ms"), - (0.001236, "1.236ms"), - (0.0001236, "123.6us"), - (0.00001236, "12.36us"), - (0.000001236, "1.236us"), + (3600 * 100 - 60, " 99h 59m"), + (31 * 60 - 1, " 30m 59s"), + (10.1236, " 10.124s"), + (9.1236, " 9.124s"), + (0.1236, " 123.6ms"), + (0.01236, " 12.36ms"), + (0.001236, " 1.236ms"), + (0.0001236, " 123.6us"), + (0.00001236, " 12.36us"), + (0.000001236, " 1.236us"), ], ) def test_format_node_duration(seconds: float, expected: str) -> None: From e58c9e3a4d0396854dca2396675abb841e0e7fd4 Mon Sep 17 00:00:00 2001 From: Bruno Oliveira Date: Fri, 17 Jan 2025 16:17:14 -0300 Subject: [PATCH 11/11] Update changelog/13125.feature.rst --- changelog/13125.feature.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/changelog/13125.feature.rst b/changelog/13125.feature.rst index fb542b028cf..0c7d66c1169 100644 --- a/changelog/13125.feature.rst +++ b/changelog/13125.feature.rst @@ -1 +1 @@ -:confval:`console_output_style` now supports ``timer`` to show execution time of each test. +:confval:`console_output_style` now supports ``times`` to show execution time of each test.