Skip to content

Commit 22d2244

Browse files
committed
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.
1 parent 730e62b commit 22d2244

File tree

7 files changed

+56
-32
lines changed

7 files changed

+56
-32
lines changed

src/_pytest/junitxml.py

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -636,17 +636,15 @@ def pytest_internalerror(self, excrepr: ExceptionRepr) -> None:
636636
reporter._add_simple("error", "internal error", str(excrepr))
637637

638638
def pytest_sessionstart(self) -> None:
639-
self.suite_start_time = timing.time()
640-
self.suite_start_perf = timing.perf_counter()
639+
self.suite_start_instant = timing.Instant()
641640

642641
def pytest_sessionfinish(self) -> None:
643642
dirname = os.path.dirname(os.path.abspath(self.logfile))
644643
# exist_ok avoids filesystem race conditions between checking path existence and requesting creation
645644
os.makedirs(dirname, exist_ok=True)
646645

647646
with open(self.logfile, "w", encoding="utf-8") as logfile:
648-
suite_stop_perf = timing.perf_counter()
649-
suite_time_delta = suite_stop_perf - self.suite_start_perf
647+
suite_time_delta = self.suite_start_instant.elapsed_s()
650648

651649
numtests = (
652650
self.stats["passed"]
@@ -665,7 +663,9 @@ def pytest_sessionfinish(self) -> None:
665663
skipped=str(self.stats["skipped"]),
666664
tests=str(numtests),
667665
time=f"{suite_time_delta:.3f}",
668-
timestamp=datetime.fromtimestamp(self.suite_start_time, timezone.utc)
666+
timestamp=datetime.fromtimestamp(
667+
self.suite_start_instant.interval()[0], timezone.utc
668+
)
669669
.astimezone()
670670
.isoformat(),
671671
hostname=platform.node(),

src/_pytest/pytester.py

Lines changed: 4 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1150,7 +1150,7 @@ def runpytest_inprocess(
11501150

11511151
if syspathinsert:
11521152
self.syspathinsert()
1153-
now = timing.perf_counter()
1153+
now = timing.Instant()
11541154
capture = _get_multicapture("sys")
11551155
capture.start_capturing()
11561156
try:
@@ -1179,9 +1179,7 @@ class reprec: # type: ignore
11791179
sys.stderr.write(err)
11801180

11811181
assert reprec.ret is not None
1182-
res = RunResult(
1183-
reprec.ret, out.splitlines(), err.splitlines(), timing.perf_counter() - now
1184-
)
1182+
res = RunResult(reprec.ret, out.splitlines(), err.splitlines(), now.elapsed_s())
11851183
res.reprec = reprec # type: ignore
11861184
return res
11871185

@@ -1408,7 +1406,7 @@ def run(
14081406
print(" in:", Path.cwd())
14091407

14101408
with p1.open("w", encoding="utf8") as f1, p2.open("w", encoding="utf8") as f2:
1411-
now = timing.perf_counter()
1409+
now = timing.Instant()
14121410
popen = self.popen(
14131411
cmdargs,
14141412
stdin=stdin,
@@ -1445,7 +1443,7 @@ def handle_timeout() -> None:
14451443

14461444
with contextlib.suppress(ValueError):
14471445
ret = ExitCode(ret)
1448-
return RunResult(ret, out, err, timing.perf_counter() - now)
1446+
return RunResult(ret, out, err, now.elapsed_s())
14491447

14501448
def _dump_lines(self, lines, fp):
14511449
try:

src/_pytest/runner.py

Lines changed: 3 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -339,19 +339,16 @@ def from_call(
339339
function, instead of being wrapped in the CallInfo.
340340
"""
341341
excinfo = None
342-
start = timing.time()
343-
precise_start = timing.perf_counter()
342+
instant = timing.Instant()
344343
try:
345344
result: TResult | None = func()
346345
except BaseException:
347346
excinfo = ExceptionInfo.from_current()
348347
if reraise is not None and isinstance(excinfo.value, reraise):
349348
raise
350349
result = None
351-
# use the perf counter
352-
precise_stop = timing.perf_counter()
353-
duration = precise_stop - precise_start
354-
stop = timing.time()
350+
duration = instant.elapsed_s()
351+
start, stop = instant.interval()
355352
return cls(
356353
start=start,
357354
stop=stop,

src/_pytest/terminal.py

Lines changed: 7 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -391,7 +391,7 @@ def __init__(self, config: Config, file: TextIO | None = None) -> None:
391391
self._progress_nodeids_reported: set[str] = set()
392392
self._timing_nodeids_reported: set[str] = set()
393393
self._show_progress_info = self._determine_show_progress_info()
394-
self._collect_report_last_write: float | None = None
394+
self._collect_report_last_instant = timing.Instant()
395395
self._already_displayed_warnings: int | None = None
396396
self._keyboardinterrupt_memo: ExceptionRepr | None = None
397397

@@ -769,7 +769,6 @@ def pytest_collection(self) -> None:
769769
if self.isatty:
770770
if self.config.option.verbose >= 0:
771771
self.write("collecting ... ", flush=True, bold=True)
772-
self._collect_report_last_write = timing.perf_counter()
773772
elif self.config.option.verbose >= 1:
774773
self.write("collecting ... ", flush=True, bold=True)
775774

@@ -788,14 +787,13 @@ def report_collect(self, final: bool = False) -> None:
788787
return
789788

790789
if not final:
791-
# Only write "collecting" report every 0.5s.
792-
t = timing.perf_counter()
790+
# Only write the "collecting" report every `REPORT_COLLECTING_RESOLUTION`.
793791
if (
794-
self._collect_report_last_write is not None
795-
and self._collect_report_last_write > t - REPORT_COLLECTING_RESOLUTION
792+
self._collect_report_last_instant.elapsed_s()
793+
< REPORT_COLLECTING_RESOLUTION
796794
):
797795
return
798-
self._collect_report_last_write = t
796+
self._collect_report_last_instant = timing.Instant()
799797

800798
errors = len(self.stats.get("error", []))
801799
skipped = len(self.stats.get("skipped", []))
@@ -823,7 +821,7 @@ def report_collect(self, final: bool = False) -> None:
823821
@hookimpl(trylast=True)
824822
def pytest_sessionstart(self, session: Session) -> None:
825823
self._session = session
826-
self._sessionstarttime = timing.perf_counter()
824+
self._session_start_instant = timing.Instant()
827825
if not self.showheader:
828826
return
829827
self.write_sep("=", "test session starts", bold=True)
@@ -1202,7 +1200,7 @@ def summary_stats(self) -> None:
12021200
if self.verbosity < -1:
12031201
return
12041202

1205-
session_duration = timing.perf_counter() - self._sessionstarttime
1203+
session_duration = self._session_start_instant.elapsed_s()
12061204
(parts, main_color) = self.build_summary_stats_line()
12071205
line_parts = []
12081206

src/_pytest/timing.py

Lines changed: 32 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,38 @@
2020
from pytest import MonkeyPatch
2121

2222

23+
class Instant:
24+
"""
25+
Provides a measurement of timing between different points in the code.
26+
27+
Useful to compute the elapsed time between two points in time,
28+
using a performance counter, and the beginning/end in actual times (as seconds since epoch).
29+
30+
Inspired by Rust's `std::time::Instant`.
31+
"""
32+
33+
def __init__(self) -> None:
34+
import _pytest.timing # noqa: PLW0406
35+
36+
self._start_perf = _pytest.timing.perf_counter()
37+
self._start_time = _pytest.timing.time()
38+
39+
def elapsed_s(self) -> float:
40+
"""Return the elapsed time (in seconds) since this Instant was created, using a precise clock."""
41+
import _pytest.timing # noqa: PLW0406
42+
43+
return _pytest.timing.perf_counter() - self._start_perf
44+
45+
def interval(self) -> tuple[float, float]:
46+
"""Return the beginning and end times of this instant, in seconds since epoch, as provided by time.time()."""
47+
import _pytest.timing # noqa: PLW0406
48+
49+
return self._start_time, _pytest.timing.time()
50+
51+
def __repr__(self) -> str: # pragma: no cover
52+
return f"Instant(start_time={self._start_time})"
53+
54+
2355
@dataclasses.dataclass
2456
class MockTiming:
2557
"""Mocks _pytest.timing with a known object that can be used to control timing in tests

testing/_py/test_local.py

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -747,7 +747,7 @@ def test_setmtime(self):
747747
name = tempfile.mktemp()
748748
open(name, "w").close()
749749
try:
750-
mtime = int(_pytest.timing.perf_counter()) - 100
750+
mtime = int(_pytest.timing.time()) - 100
751751
path = local(name)
752752
assert path.mtime() != mtime
753753
path.setmtime(mtime)
@@ -1405,15 +1405,15 @@ def test_atime(self, tmpdir):
14051405
import time
14061406

14071407
path = tmpdir.ensure("samplefile")
1408-
now = _pytest.timing.perf_counter()
1408+
now = _pytest.timing.Instant()
14091409
atime1 = path.atime()
14101410
# we could wait here but timer resolution is very
14111411
# system dependent
14121412
path.read_binary()
14131413
time.sleep(ATIME_RESOLUTION)
14141414
atime2 = path.atime()
14151415
time.sleep(ATIME_RESOLUTION)
1416-
duration = _pytest.timing.perf_counter() - now
1416+
duration = now.elapsed_s()
14171417
assert (atime2 - atime1) <= duration
14181418

14191419
def test_commondir(self, path1):

testing/test_pytester.py

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -451,10 +451,9 @@ def test_pytester_run_with_timeout(pytester: Pytester) -> None:
451451

452452
timeout = 120
453453

454-
start = _pytest.timing.perf_counter()
454+
instant = _pytest.timing.Instant()
455455
result = pytester.runpytest_subprocess(testfile, timeout=timeout)
456-
end = _pytest.timing.perf_counter()
457-
duration = end - start
456+
duration = instant.elapsed_s()
458457

459458
assert result.ret == ExitCode.OK
460459
assert duration < timeout

0 commit comments

Comments
 (0)