From a79e1b72c60b8916cac34fd3461bf175dcf763fc Mon Sep 17 00:00:00 2001 From: Bruno Oliveira Date: Sat, 26 Apr 2025 10:56:36 -0300 Subject: [PATCH 1/4] Add `Instant` class to conveniently track elapsed and start/end times Throughout the codebase we often need to track elapsed times, using a performance clock, and also start/end times that given seconds since epoch (via `time.time()`). `Instant` encapsulates both functionalities to simplify the code and ensure we are using the correct functions from `_pytest.timing`, which we can mock in tests for reliability. --- src/_pytest/junitxml.py | 10 +++++----- src/_pytest/pytester.py | 10 ++++------ src/_pytest/runner.py | 9 +++------ src/_pytest/terminal.py | 16 +++++++--------- src/_pytest/timing.py | 32 ++++++++++++++++++++++++++++++++ testing/_py/test_local.py | 4 ++-- testing/test_pytester.py | 5 ++--- 7 files changed, 55 insertions(+), 31 deletions(-) diff --git a/src/_pytest/junitxml.py b/src/_pytest/junitxml.py index 06cab961ef5..62bc68d4ad8 100644 --- a/src/_pytest/junitxml.py +++ b/src/_pytest/junitxml.py @@ -636,8 +636,7 @@ def pytest_internalerror(self, excrepr: ExceptionRepr) -> None: reporter._add_simple("error", "internal error", str(excrepr)) def pytest_sessionstart(self) -> None: - self.suite_start_time = timing.time() - self.suite_start_perf = timing.perf_counter() + self.suite_start_instant = timing.Instant() def pytest_sessionfinish(self) -> None: dirname = os.path.dirname(os.path.abspath(self.logfile)) @@ -645,8 +644,7 @@ def pytest_sessionfinish(self) -> None: os.makedirs(dirname, exist_ok=True) with open(self.logfile, "w", encoding="utf-8") as logfile: - suite_stop_perf = timing.perf_counter() - suite_time_delta = suite_stop_perf - self.suite_start_perf + suite_time_delta = self.suite_start_instant.elapsed_s() numtests = ( self.stats["passed"] @@ -665,7 +663,9 @@ def pytest_sessionfinish(self) -> None: skipped=str(self.stats["skipped"]), tests=str(numtests), time=f"{suite_time_delta:.3f}", - timestamp=datetime.fromtimestamp(self.suite_start_time, timezone.utc) + timestamp=datetime.fromtimestamp( + self.suite_start_instant.interval()[0], timezone.utc + ) .astimezone() .isoformat(), hostname=platform.node(), diff --git a/src/_pytest/pytester.py b/src/_pytest/pytester.py index bb5f6a5787e..5c457acbdc3 100644 --- a/src/_pytest/pytester.py +++ b/src/_pytest/pytester.py @@ -1150,7 +1150,7 @@ def runpytest_inprocess( if syspathinsert: self.syspathinsert() - now = timing.perf_counter() + now = timing.Instant() capture = _get_multicapture("sys") capture.start_capturing() try: @@ -1179,9 +1179,7 @@ class reprec: # type: ignore sys.stderr.write(err) assert reprec.ret is not None - res = RunResult( - reprec.ret, out.splitlines(), err.splitlines(), timing.perf_counter() - now - ) + res = RunResult(reprec.ret, out.splitlines(), err.splitlines(), now.elapsed_s()) res.reprec = reprec # type: ignore return res @@ -1408,7 +1406,7 @@ def run( print(" in:", Path.cwd()) with p1.open("w", encoding="utf8") as f1, p2.open("w", encoding="utf8") as f2: - now = timing.perf_counter() + now = timing.Instant() popen = self.popen( cmdargs, stdin=stdin, @@ -1445,7 +1443,7 @@ def handle_timeout() -> None: with contextlib.suppress(ValueError): ret = ExitCode(ret) - return RunResult(ret, out, err, timing.perf_counter() - now) + return RunResult(ret, out, err, now.elapsed_s()) def _dump_lines(self, lines, fp): try: diff --git a/src/_pytest/runner.py b/src/_pytest/runner.py index f0543289267..74561b0ed31 100644 --- a/src/_pytest/runner.py +++ b/src/_pytest/runner.py @@ -339,8 +339,7 @@ def from_call( function, instead of being wrapped in the CallInfo. """ excinfo = None - start = timing.time() - precise_start = timing.perf_counter() + instant = timing.Instant() try: result: TResult | None = func() except BaseException: @@ -348,10 +347,8 @@ def from_call( if reraise is not None and isinstance(excinfo.value, reraise): raise result = None - # use the perf counter - precise_stop = timing.perf_counter() - duration = precise_stop - precise_start - stop = timing.time() + duration = instant.elapsed_s() + start, stop = instant.interval() return cls( start=start, stop=stop, diff --git a/src/_pytest/terminal.py b/src/_pytest/terminal.py index 8415912e9ac..180eeb0c32c 100644 --- a/src/_pytest/terminal.py +++ b/src/_pytest/terminal.py @@ -391,7 +391,7 @@ def __init__(self, config: Config, file: TextIO | None = None) -> None: 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._collect_report_last_instant = timing.Instant() self._already_displayed_warnings: int | None = None self._keyboardinterrupt_memo: ExceptionRepr | None = None @@ -769,7 +769,6 @@ def pytest_collection(self) -> None: if self.isatty: if self.config.option.verbose >= 0: self.write("collecting ... ", flush=True, bold=True) - self._collect_report_last_write = timing.perf_counter() elif self.config.option.verbose >= 1: self.write("collecting ... ", flush=True, bold=True) @@ -788,14 +787,13 @@ def report_collect(self, final: bool = False) -> None: return if not final: - # Only write "collecting" report every 0.5s. - t = timing.perf_counter() + # Only write the "collecting" report every `REPORT_COLLECTING_RESOLUTION`. if ( - self._collect_report_last_write is not None - and self._collect_report_last_write > t - REPORT_COLLECTING_RESOLUTION + self._collect_report_last_instant.elapsed_s() + < REPORT_COLLECTING_RESOLUTION ): return - self._collect_report_last_write = t + self._collect_report_last_instant = timing.Instant() errors = len(self.stats.get("error", [])) skipped = len(self.stats.get("skipped", [])) @@ -823,7 +821,7 @@ def report_collect(self, final: bool = False) -> None: @hookimpl(trylast=True) def pytest_sessionstart(self, session: Session) -> None: self._session = session - self._sessionstarttime = timing.perf_counter() + self._session_start_instant = timing.Instant() if not self.showheader: return self.write_sep("=", "test session starts", bold=True) @@ -1202,7 +1200,7 @@ def summary_stats(self) -> None: if self.verbosity < -1: return - session_duration = timing.perf_counter() - self._sessionstarttime + session_duration = self._session_start_instant.elapsed_s() (parts, main_color) = self.build_summary_stats_line() line_parts = [] diff --git a/src/_pytest/timing.py b/src/_pytest/timing.py index 4422037a9d9..e14dc8d157b 100644 --- a/src/_pytest/timing.py +++ b/src/_pytest/timing.py @@ -20,6 +20,38 @@ from pytest import MonkeyPatch +class Instant: + """ + Provides a measurement of timing between different points in the code. + + Useful to compute the elapsed time between two points in time, + using a performance counter, and the beginning/end in actual times (as seconds since epoch). + + Inspired by Rust's `std::time::Instant`. + """ + + def __init__(self) -> None: + import _pytest.timing # noqa: PLW0406 + + self._start_perf = _pytest.timing.perf_counter() + self._start_time = _pytest.timing.time() + + def elapsed_s(self) -> float: + """Return the elapsed time (in seconds) since this Instant was created, using a precise clock.""" + import _pytest.timing # noqa: PLW0406 + + return _pytest.timing.perf_counter() - self._start_perf + + def interval(self) -> tuple[float, float]: + """Return the beginning and end times of this instant, in seconds since epoch, as provided by time.time().""" + import _pytest.timing # noqa: PLW0406 + + return self._start_time, _pytest.timing.time() + + def __repr__(self) -> str: # pragma: no cover + return f"Instant(start_time={self._start_time}, elapsed_s={self.elapsed_s()})" + + @dataclasses.dataclass class MockTiming: """Mocks _pytest.timing with a known object that can be used to control timing in tests diff --git a/testing/_py/test_local.py b/testing/_py/test_local.py index e4b011a9727..1d1cd02015d 100644 --- a/testing/_py/test_local.py +++ b/testing/_py/test_local.py @@ -1405,7 +1405,7 @@ def test_atime(self, tmpdir): import time path = tmpdir.ensure("samplefile") - now = _pytest.timing.perf_counter() + now = _pytest.timing.Instant() atime1 = path.atime() # we could wait here but timer resolution is very # system dependent @@ -1413,7 +1413,7 @@ def test_atime(self, tmpdir): time.sleep(ATIME_RESOLUTION) atime2 = path.atime() time.sleep(ATIME_RESOLUTION) - duration = _pytest.timing.perf_counter() - now + duration = now.elapsed_s() assert (atime2 - atime1) <= duration def test_commondir(self, path1): diff --git a/testing/test_pytester.py b/testing/test_pytester.py index 555d73f9eaa..6d1791d433d 100644 --- a/testing/test_pytester.py +++ b/testing/test_pytester.py @@ -451,10 +451,9 @@ def test_pytester_run_with_timeout(pytester: Pytester) -> None: timeout = 120 - start = _pytest.timing.perf_counter() + instant = _pytest.timing.Instant() result = pytester.runpytest_subprocess(testfile, timeout=timeout) - end = _pytest.timing.perf_counter() - duration = end - start + duration = instant.elapsed_s() assert result.ret == ExitCode.OK assert duration < timeout From 65395b902939d4c481d035c48b4f30cf89958fe6 Mon Sep 17 00:00:00 2001 From: Bruno Oliveira Date: Sun, 27 Apr 2025 09:07:51 -0300 Subject: [PATCH 2/4] Code review requests --- src/_pytest/junitxml.py | 14 +++------ src/_pytest/pytester.py | 10 +++--- src/_pytest/runner.py | 9 +++--- src/_pytest/terminal.py | 8 ++--- src/_pytest/timing.py | 64 ++++++++++++++++++++++++--------------- testing/_py/test_local.py | 9 +++--- testing/test_pytester.py | 4 +-- 7 files changed, 65 insertions(+), 53 deletions(-) diff --git a/src/_pytest/junitxml.py b/src/_pytest/junitxml.py index 62bc68d4ad8..4c05699a1a0 100644 --- a/src/_pytest/junitxml.py +++ b/src/_pytest/junitxml.py @@ -11,8 +11,6 @@ from __future__ import annotations from collections.abc import Callable -from datetime import datetime -from datetime import timezone import functools import os import platform @@ -636,7 +634,7 @@ def pytest_internalerror(self, excrepr: ExceptionRepr) -> None: reporter._add_simple("error", "internal error", str(excrepr)) def pytest_sessionstart(self) -> None: - self.suite_start_instant = timing.Instant() + self.suite_start = timing.Instant() def pytest_sessionfinish(self) -> None: dirname = os.path.dirname(os.path.abspath(self.logfile)) @@ -644,7 +642,7 @@ def pytest_sessionfinish(self) -> None: os.makedirs(dirname, exist_ok=True) with open(self.logfile, "w", encoding="utf-8") as logfile: - suite_time_delta = self.suite_start_instant.elapsed_s() + duration = self.suite_start.duration() numtests = ( self.stats["passed"] @@ -662,12 +660,8 @@ def pytest_sessionfinish(self) -> None: failures=str(self.stats["failure"]), skipped=str(self.stats["skipped"]), tests=str(numtests), - time=f"{suite_time_delta:.3f}", - timestamp=datetime.fromtimestamp( - self.suite_start_instant.interval()[0], timezone.utc - ) - .astimezone() - .isoformat(), + time=f"{duration.elapsed_s:.3f}", + timestamp=duration.start_utc().astimezone().isoformat(), hostname=platform.node(), ) global_properties = self._get_global_properties_node() diff --git a/src/_pytest/pytester.py b/src/_pytest/pytester.py index 5c457acbdc3..e78e6a5f71d 100644 --- a/src/_pytest/pytester.py +++ b/src/_pytest/pytester.py @@ -1150,7 +1150,7 @@ def runpytest_inprocess( if syspathinsert: self.syspathinsert() - now = timing.Instant() + instant = timing.Instant() capture = _get_multicapture("sys") capture.start_capturing() try: @@ -1179,7 +1179,9 @@ class reprec: # type: ignore sys.stderr.write(err) assert reprec.ret is not None - res = RunResult(reprec.ret, out.splitlines(), err.splitlines(), now.elapsed_s()) + res = RunResult( + reprec.ret, out.splitlines(), err.splitlines(), instant.duration().elapsed_s + ) res.reprec = reprec # type: ignore return res @@ -1406,7 +1408,7 @@ def run( print(" in:", Path.cwd()) with p1.open("w", encoding="utf8") as f1, p2.open("w", encoding="utf8") as f2: - now = timing.Instant() + instant = timing.Instant() popen = self.popen( cmdargs, stdin=stdin, @@ -1443,7 +1445,7 @@ def handle_timeout() -> None: with contextlib.suppress(ValueError): ret = ExitCode(ret) - return RunResult(ret, out, err, now.elapsed_s()) + return RunResult(ret, out, err, instant.duration().elapsed_s) def _dump_lines(self, lines, fp): try: diff --git a/src/_pytest/runner.py b/src/_pytest/runner.py index 74561b0ed31..7c35de3fcd9 100644 --- a/src/_pytest/runner.py +++ b/src/_pytest/runner.py @@ -347,12 +347,11 @@ def from_call( if reraise is not None and isinstance(excinfo.value, reraise): raise result = None - duration = instant.elapsed_s() - start, stop = instant.interval() + duration = instant.duration() return cls( - start=start, - stop=stop, - duration=duration, + start=duration.start, + stop=duration.stop, + duration=duration.elapsed_s, when=when, result=result, excinfo=excinfo, diff --git a/src/_pytest/terminal.py b/src/_pytest/terminal.py index 180eeb0c32c..6303738b1dc 100644 --- a/src/_pytest/terminal.py +++ b/src/_pytest/terminal.py @@ -789,7 +789,7 @@ def report_collect(self, final: bool = False) -> None: if not final: # Only write the "collecting" report every `REPORT_COLLECTING_RESOLUTION`. if ( - self._collect_report_last_instant.elapsed_s() + self._collect_report_last_instant.duration().elapsed_s < REPORT_COLLECTING_RESOLUTION ): return @@ -821,7 +821,7 @@ def report_collect(self, final: bool = False) -> None: @hookimpl(trylast=True) def pytest_sessionstart(self, session: Session) -> None: self._session = session - self._session_start_instant = timing.Instant() + self._session_start = timing.Instant() if not self.showheader: return self.write_sep("=", "test session starts", bold=True) @@ -1200,7 +1200,7 @@ def summary_stats(self) -> None: if self.verbosity < -1: return - session_duration = self._session_start_instant.elapsed_s() + session_duration = self._session_start.duration() (parts, main_color) = self.build_summary_stats_line() line_parts = [] @@ -1215,7 +1215,7 @@ def summary_stats(self) -> None: msg = ", ".join(line_parts) main_markup = {main_color: True} - duration = f" in {format_session_duration(session_duration)}" + duration = f" in {format_session_duration(session_duration.elapsed_s)}" duration_with_markup = self._tw.markup(duration, **main_markup) if display_sep: fullwidth += len(duration_with_markup) - len(duration) diff --git a/src/_pytest/timing.py b/src/_pytest/timing.py index e14dc8d157b..2ebb803e225 100644 --- a/src/_pytest/timing.py +++ b/src/_pytest/timing.py @@ -10,6 +10,7 @@ import dataclasses from datetime import datetime +from datetime import timezone from time import perf_counter from time import sleep from time import time @@ -20,36 +21,51 @@ from pytest import MonkeyPatch +@dataclasses.dataclass(frozen=True) class Instant: """ - Provides a measurement of timing between different points in the code. - - Useful to compute the elapsed time between two points in time, - using a performance counter, and the beginning/end in actual times (as seconds since epoch). + Measures a span of time between different points in the code. Inspired by Rust's `std::time::Instant`. """ - def __init__(self) -> None: - import _pytest.timing # noqa: PLW0406 - - self._start_perf = _pytest.timing.perf_counter() - self._start_time = _pytest.timing.time() - - def elapsed_s(self) -> float: - """Return the elapsed time (in seconds) since this Instant was created, using a precise clock.""" - import _pytest.timing # noqa: PLW0406 - - return _pytest.timing.perf_counter() - self._start_perf - - def interval(self) -> tuple[float, float]: - """Return the beginning and end times of this instant, in seconds since epoch, as provided by time.time().""" - import _pytest.timing # noqa: PLW0406 - - return self._start_time, _pytest.timing.time() - - def __repr__(self) -> str: # pragma: no cover - return f"Instant(start_time={self._start_time}, elapsed_s={self.elapsed_s()})" + # Creation time of this instant, using time.time(), to measure actual time. + # Use a `lambda` to initialize the default to correctly get the mocked time via `MockTiming`. + _start_time: float = dataclasses.field(default_factory=lambda: time(), init=False) + + # Initial "tick" of the performance counter to measure precise elapsed time. + # Use a `lambda` to initialize the default to correctly get the mocked time via `MockTiming`. + _start_perf: float = dataclasses.field( + default_factory=lambda: perf_counter(), init=False + ) + + def duration(self) -> Duration: + """Measure the duration since `Instant` was created.""" + return Duration( + start=self._start_time, + elapsed_s=perf_counter() - self._start_perf, + stop=time(), + ) + + +@dataclasses.dataclass(frozen=True) +class Duration: + """A span of time as measured by `Instant.duration()`.""" + + # Start time of the duration, as seconds since epoch. + start: float + # Stop time of the duration, as seconds since epoch. + stop: float + # Elapsed time of the duration, in seconds, measured using a performance counter for precise timing. + elapsed_s: float + + def start_utc(self) -> datetime: + """Start time of the duration, as a datetime in UTC.""" + return datetime.fromtimestamp(self.start, timezone.utc) + + def stop_utc(self) -> datetime: # pragma: no cover + """Stop time of the duration, as a datetime in UTC.""" + return datetime.fromtimestamp(self.stop, timezone.utc) @dataclasses.dataclass diff --git a/testing/_py/test_local.py b/testing/_py/test_local.py index 1d1cd02015d..7064d1daa9b 100644 --- a/testing/_py/test_local.py +++ b/testing/_py/test_local.py @@ -12,7 +12,6 @@ from py import error from py.path import local -import _pytest.timing import pytest @@ -747,7 +746,8 @@ def test_setmtime(self): name = tempfile.mktemp() open(name, "w").close() try: - mtime = int(_pytest.timing.time()) - 100 + # Do not use _pytest.timing here, as we do not want time mocking to affect this test. + mtime = int(time.time()) - 100 path = local(name) assert path.mtime() != mtime path.setmtime(mtime) @@ -1405,7 +1405,8 @@ def test_atime(self, tmpdir): import time path = tmpdir.ensure("samplefile") - now = _pytest.timing.Instant() + # Do not use _pytest.timing here, as we do not want time mocking to affect this test. + now = time.time() atime1 = path.atime() # we could wait here but timer resolution is very # system dependent @@ -1413,7 +1414,7 @@ def test_atime(self, tmpdir): time.sleep(ATIME_RESOLUTION) atime2 = path.atime() time.sleep(ATIME_RESOLUTION) - duration = now.elapsed_s() + duration = time.time() - now assert (atime2 - atime1) <= duration def test_commondir(self, path1): diff --git a/testing/test_pytester.py b/testing/test_pytester.py index 6d1791d433d..6902535c797 100644 --- a/testing/test_pytester.py +++ b/testing/test_pytester.py @@ -453,10 +453,10 @@ def test_pytester_run_with_timeout(pytester: Pytester) -> None: instant = _pytest.timing.Instant() result = pytester.runpytest_subprocess(testfile, timeout=timeout) - duration = instant.elapsed_s() + duration = instant.duration() assert result.ret == ExitCode.OK - assert duration < timeout + assert duration.elapsed_s < timeout def test_pytester_run_timeout_expires(pytester: Pytester) -> None: From 2923b0237974882b64cb4f3c8e3880a7aa5952ad Mon Sep 17 00:00:00 2001 From: Bruno Oliveira Date: Sun, 27 Apr 2025 15:05:00 -0300 Subject: [PATCH 3/4] New API --- src/_pytest/junitxml.py | 2 +- src/_pytest/runner.py | 4 ++-- src/_pytest/terminal.py | 6 +++--- src/_pytest/timing.py | 38 ++++++++++++++++---------------------- 4 files changed, 22 insertions(+), 28 deletions(-) diff --git a/src/_pytest/junitxml.py b/src/_pytest/junitxml.py index 4c05699a1a0..648b306f3aa 100644 --- a/src/_pytest/junitxml.py +++ b/src/_pytest/junitxml.py @@ -661,7 +661,7 @@ def pytest_sessionfinish(self) -> None: skipped=str(self.stats["skipped"]), tests=str(numtests), time=f"{duration.elapsed_s:.3f}", - timestamp=duration.start_utc().astimezone().isoformat(), + timestamp=self.suite_start.as_utc().astimezone().isoformat(), hostname=platform.node(), ) global_properties = self._get_global_properties_node() diff --git a/src/_pytest/runner.py b/src/_pytest/runner.py index 7c35de3fcd9..cff55ed89d9 100644 --- a/src/_pytest/runner.py +++ b/src/_pytest/runner.py @@ -349,8 +349,8 @@ def from_call( result = None duration = instant.duration() return cls( - start=duration.start, - stop=duration.stop, + start=duration.start.time, + stop=duration.stop.time, duration=duration.elapsed_s, when=when, result=result, diff --git a/src/_pytest/terminal.py b/src/_pytest/terminal.py index 6303738b1dc..be931f3964d 100644 --- a/src/_pytest/terminal.py +++ b/src/_pytest/terminal.py @@ -391,7 +391,7 @@ def __init__(self, config: Config, file: TextIO | None = None) -> None: 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_instant = timing.Instant() + self._collect_report_last_write = timing.Instant() self._already_displayed_warnings: int | None = None self._keyboardinterrupt_memo: ExceptionRepr | None = None @@ -789,11 +789,11 @@ def report_collect(self, final: bool = False) -> None: if not final: # Only write the "collecting" report every `REPORT_COLLECTING_RESOLUTION`. if ( - self._collect_report_last_instant.duration().elapsed_s + self._collect_report_last_write.duration().elapsed_s < REPORT_COLLECTING_RESOLUTION ): return - self._collect_report_last_instant = timing.Instant() + self._collect_report_last_write = timing.Instant() errors = len(self.stats.get("error", [])) skipped = len(self.stats.get("skipped", [])) diff --git a/src/_pytest/timing.py b/src/_pytest/timing.py index 2ebb803e225..751b84755d9 100644 --- a/src/_pytest/timing.py +++ b/src/_pytest/timing.py @@ -24,48 +24,42 @@ @dataclasses.dataclass(frozen=True) class Instant: """ - Measures a span of time between different points in the code. + Represents an instant in time, used to both get the timestamp value and to measure + the duration of a time span. Inspired by Rust's `std::time::Instant`. """ # Creation time of this instant, using time.time(), to measure actual time. # Use a `lambda` to initialize the default to correctly get the mocked time via `MockTiming`. - _start_time: float = dataclasses.field(default_factory=lambda: time(), init=False) + time: float = dataclasses.field(default_factory=lambda: time(), init=False) - # Initial "tick" of the performance counter to measure precise elapsed time. + # Performance counter tick of the instant, used to measure precise elapsed time. # Use a `lambda` to initialize the default to correctly get the mocked time via `MockTiming`. - _start_perf: float = dataclasses.field( + perf_count: float = dataclasses.field( default_factory=lambda: perf_counter(), init=False ) def duration(self) -> Duration: """Measure the duration since `Instant` was created.""" - return Duration( - start=self._start_time, - elapsed_s=perf_counter() - self._start_perf, - stop=time(), - ) + return Duration(start=self, stop=Instant()) + + def as_utc(self) -> datetime: + """Instant as UTC datetime.""" + return datetime.fromtimestamp(self.time, timezone.utc) @dataclasses.dataclass(frozen=True) class Duration: """A span of time as measured by `Instant.duration()`.""" - # Start time of the duration, as seconds since epoch. - start: float - # Stop time of the duration, as seconds since epoch. - stop: float - # Elapsed time of the duration, in seconds, measured using a performance counter for precise timing. - elapsed_s: float - - def start_utc(self) -> datetime: - """Start time of the duration, as a datetime in UTC.""" - return datetime.fromtimestamp(self.start, timezone.utc) + start: Instant + stop: Instant - def stop_utc(self) -> datetime: # pragma: no cover - """Stop time of the duration, as a datetime in UTC.""" - return datetime.fromtimestamp(self.stop, timezone.utc) + @property + def elapsed_s(self) -> float: + """Elapsed time of the duration, in seconds, measured using a performance counter for precise timing.""" + return self.stop.perf_count - self.start.perf_count @dataclasses.dataclass From e4810d2a678d7697af63dbe40a1aa714e6e0d3e5 Mon Sep 17 00:00:00 2001 From: Bruno Oliveira Date: Mon, 28 Apr 2025 09:05:28 -0300 Subject: [PATCH 4/4] Rename `Instant.duration()` to `Instant.elapsed()` While at it, noticed that `Duration.seconds` reads much better than `Duration.elapsed_s`. --- src/_pytest/junitxml.py | 4 ++-- src/_pytest/pytester.py | 4 ++-- src/_pytest/runner.py | 4 ++-- src/_pytest/terminal.py | 6 +++--- src/_pytest/timing.py | 12 ++++++------ testing/test_pytester.py | 4 ++-- 6 files changed, 17 insertions(+), 17 deletions(-) diff --git a/src/_pytest/junitxml.py b/src/_pytest/junitxml.py index 648b306f3aa..ec9922ee7bd 100644 --- a/src/_pytest/junitxml.py +++ b/src/_pytest/junitxml.py @@ -642,7 +642,7 @@ def pytest_sessionfinish(self) -> None: os.makedirs(dirname, exist_ok=True) with open(self.logfile, "w", encoding="utf-8") as logfile: - duration = self.suite_start.duration() + duration = self.suite_start.elapsed() numtests = ( self.stats["passed"] @@ -660,7 +660,7 @@ def pytest_sessionfinish(self) -> None: failures=str(self.stats["failure"]), skipped=str(self.stats["skipped"]), tests=str(numtests), - time=f"{duration.elapsed_s:.3f}", + time=f"{duration.seconds:.3f}", timestamp=self.suite_start.as_utc().astimezone().isoformat(), hostname=platform.node(), ) diff --git a/src/_pytest/pytester.py b/src/_pytest/pytester.py index e78e6a5f71d..11127a88bb8 100644 --- a/src/_pytest/pytester.py +++ b/src/_pytest/pytester.py @@ -1180,7 +1180,7 @@ class reprec: # type: ignore assert reprec.ret is not None res = RunResult( - reprec.ret, out.splitlines(), err.splitlines(), instant.duration().elapsed_s + reprec.ret, out.splitlines(), err.splitlines(), instant.elapsed().seconds ) res.reprec = reprec # type: ignore return res @@ -1445,7 +1445,7 @@ def handle_timeout() -> None: with contextlib.suppress(ValueError): ret = ExitCode(ret) - return RunResult(ret, out, err, instant.duration().elapsed_s) + return RunResult(ret, out, err, instant.elapsed().seconds) def _dump_lines(self, lines, fp): try: diff --git a/src/_pytest/runner.py b/src/_pytest/runner.py index cff55ed89d9..26e4e838b77 100644 --- a/src/_pytest/runner.py +++ b/src/_pytest/runner.py @@ -347,11 +347,11 @@ def from_call( if reraise is not None and isinstance(excinfo.value, reraise): raise result = None - duration = instant.duration() + duration = instant.elapsed() return cls( start=duration.start.time, stop=duration.stop.time, - duration=duration.elapsed_s, + duration=duration.seconds, when=when, result=result, excinfo=excinfo, diff --git a/src/_pytest/terminal.py b/src/_pytest/terminal.py index be931f3964d..d5ccc4e4900 100644 --- a/src/_pytest/terminal.py +++ b/src/_pytest/terminal.py @@ -789,7 +789,7 @@ def report_collect(self, final: bool = False) -> None: if not final: # Only write the "collecting" report every `REPORT_COLLECTING_RESOLUTION`. if ( - self._collect_report_last_write.duration().elapsed_s + self._collect_report_last_write.elapsed().seconds < REPORT_COLLECTING_RESOLUTION ): return @@ -1200,7 +1200,7 @@ def summary_stats(self) -> None: if self.verbosity < -1: return - session_duration = self._session_start.duration() + session_duration = self._session_start.elapsed() (parts, main_color) = self.build_summary_stats_line() line_parts = [] @@ -1215,7 +1215,7 @@ def summary_stats(self) -> None: msg = ", ".join(line_parts) main_markup = {main_color: True} - duration = f" in {format_session_duration(session_duration.elapsed_s)}" + duration = f" in {format_session_duration(session_duration.seconds)}" duration_with_markup = self._tw.markup(duration, **main_markup) if display_sep: fullwidth += len(duration_with_markup) - len(duration) diff --git a/src/_pytest/timing.py b/src/_pytest/timing.py index 751b84755d9..221eeffc4fd 100644 --- a/src/_pytest/timing.py +++ b/src/_pytest/timing.py @@ -31,16 +31,16 @@ class Instant: """ # Creation time of this instant, using time.time(), to measure actual time. - # Use a `lambda` to initialize the default to correctly get the mocked time via `MockTiming`. + # Note: using a `lambda` to correctly get the mocked time via `MockTiming`. time: float = dataclasses.field(default_factory=lambda: time(), init=False) # Performance counter tick of the instant, used to measure precise elapsed time. - # Use a `lambda` to initialize the default to correctly get the mocked time via `MockTiming`. + # Note: using a `lambda` to correctly get the mocked time via `MockTiming`. perf_count: float = dataclasses.field( default_factory=lambda: perf_counter(), init=False ) - def duration(self) -> Duration: + def elapsed(self) -> Duration: """Measure the duration since `Instant` was created.""" return Duration(start=self, stop=Instant()) @@ -51,14 +51,14 @@ def as_utc(self) -> datetime: @dataclasses.dataclass(frozen=True) class Duration: - """A span of time as measured by `Instant.duration()`.""" + """A span of time as measured by `Instant.elapsed()`.""" start: Instant stop: Instant @property - def elapsed_s(self) -> float: - """Elapsed time of the duration, in seconds, measured using a performance counter for precise timing.""" + def seconds(self) -> float: + """Elapsed time of the duration in seconds, measured using a performance counter for precise timing.""" return self.stop.perf_count - self.start.perf_count diff --git a/testing/test_pytester.py b/testing/test_pytester.py index 6902535c797..721e8c19d8b 100644 --- a/testing/test_pytester.py +++ b/testing/test_pytester.py @@ -453,10 +453,10 @@ def test_pytester_run_with_timeout(pytester: Pytester) -> None: instant = _pytest.timing.Instant() result = pytester.runpytest_subprocess(testfile, timeout=timeout) - duration = instant.duration() + duration = instant.elapsed() assert result.ret == ExitCode.OK - assert duration.elapsed_s < timeout + assert duration.seconds < timeout def test_pytester_run_timeout_expires(pytester: Pytester) -> None: