From 604d22a4e3cb33b3e8fc7e27cc1248f9be0a7954 Mon Sep 17 00:00:00 2001 From: RivTech <50204868+RivTechProjects@users.noreply.github.com> Date: Fri, 25 Apr 2025 00:49:22 -0400 Subject: [PATCH 1/9] Replace time.time() with _pytest.timing.perf_counter() for reliable timing --- testing/_py/test_local.py | 8 ++++---- testing/test_pytester.py | 6 +++--- 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/testing/_py/test_local.py b/testing/_py/test_local.py index 03a828c64f0..c8a2c25fff1 100644 --- a/testing/_py/test_local.py +++ b/testing/_py/test_local.py @@ -12,6 +12,7 @@ from py import error from py.path import local +from _pytest.timing import perf_counter import pytest @@ -738,7 +739,6 @@ def test_dump(self, tmpdir, bin): def test_setmtime(self): import tempfile - import time try: fd, name = tempfile.mkstemp() @@ -747,7 +747,7 @@ def test_setmtime(self): name = tempfile.mktemp() open(name, "w").close() try: - mtime = int(time.time()) - 100 + mtime = int(perf_counter()) - 100 path = local(name) assert path.mtime() != mtime path.setmtime(mtime) @@ -1405,7 +1405,7 @@ def test_atime(self, tmpdir): import time path = tmpdir.ensure("samplefile") - now = time.time() + now = perf_counter() 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 = time.time() - now + duration = perf_counter() - now assert (atime2 - atime1) <= duration def test_commondir(self, path1): diff --git a/testing/test_pytester.py b/testing/test_pytester.py index 87714b4708f..9e0a669ddcf 100644 --- a/testing/test_pytester.py +++ b/testing/test_pytester.py @@ -4,7 +4,6 @@ import os import subprocess import sys -import time from types import ModuleType from _pytest.config import ExitCode @@ -16,6 +15,7 @@ from _pytest.pytester import Pytester from _pytest.pytester import SysModulesSnapshot from _pytest.pytester import SysPathsSnapshot +from _pytest.timing import perf_counter import pytest @@ -451,9 +451,9 @@ def test_pytester_run_with_timeout(pytester: Pytester) -> None: timeout = 120 - start = time.time() + start = perf_counter() result = pytester.runpytest_subprocess(testfile, timeout=timeout) - end = time.time() + end = perf_counter() duration = end - start assert result.ret == ExitCode.OK From a61de97dc978bbd0f6776c586d118ba740e5d214 Mon Sep 17 00:00:00 2001 From: RivTech <50204868+RivTechProjects@users.noreply.github.com> Date: Fri, 25 Apr 2025 00:49:47 -0400 Subject: [PATCH 2/9] Add changelog entry for issue #13384 --- changelog/13384.bugfix.rst | 2 ++ 1 file changed, 2 insertions(+) create mode 100644 changelog/13384.bugfix.rst diff --git a/changelog/13384.bugfix.rst b/changelog/13384.bugfix.rst new file mode 100644 index 00000000000..5898547def2 --- /dev/null +++ b/changelog/13384.bugfix.rst @@ -0,0 +1,2 @@ +Fixed an issue where pytest could report negative durations due to the use of `time.time()`. +Replaced `time.time()` with `_pytest.timing.perf_counter()` for more reliable timing. \ No newline at end of file From c2aef9a434954d940a329ef41665ea8680f56915 Mon Sep 17 00:00:00 2001 From: RivTech <50204868+RivTechProjects@users.noreply.github.com> Date: Fri, 25 Apr 2025 00:50:03 -0400 Subject: [PATCH 3/9] Add Deysha Rivera to AUTHORS file --- AUTHORS | 1 + 1 file changed, 1 insertion(+) diff --git a/AUTHORS b/AUTHORS index e19a0ae5871..7f742fb4083 100644 --- a/AUTHORS +++ b/AUTHORS @@ -130,6 +130,7 @@ Daw-Ran Liou Debi Mishra Denis Kirisov Denivy Braiam Rück +Deysha Rivera Dheeraj C K Dhiren Serai Diego Russo From 120d4c19d93ac48a0af2ea7883edc26b01d0128d Mon Sep 17 00:00:00 2001 From: "pre-commit-ci[bot]" <66853113+pre-commit-ci[bot]@users.noreply.github.com> Date: Fri, 25 Apr 2025 05:00:00 +0000 Subject: [PATCH 4/9] [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci --- changelog/13384.bugfix.rst | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/changelog/13384.bugfix.rst b/changelog/13384.bugfix.rst index 5898547def2..e1c7ff7a181 100644 --- a/changelog/13384.bugfix.rst +++ b/changelog/13384.bugfix.rst @@ -1,2 +1,2 @@ -Fixed an issue where pytest could report negative durations due to the use of `time.time()`. -Replaced `time.time()` with `_pytest.timing.perf_counter()` for more reliable timing. \ No newline at end of file +Fixed an issue where pytest could report negative durations due to the use of `time.time()`. +Replaced `time.time()` with `_pytest.timing.perf_counter()` for more reliable timing. From c1670164e78850b63910531e22e38c9ccf34cdd8 Mon Sep 17 00:00:00 2001 From: RivTech <50204868+RivTechProjects@users.noreply.github.com> Date: Fri, 25 Apr 2025 01:29:27 -0400 Subject: [PATCH 5/9] Use module-levle imports for _pytest.timing to support mocking --- testing/_py/test_local.py | 8 ++++---- testing/test_pytester.py | 6 +++--- 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/testing/_py/test_local.py b/testing/_py/test_local.py index c8a2c25fff1..b158778c4fa 100644 --- a/testing/_py/test_local.py +++ b/testing/_py/test_local.py @@ -12,7 +12,7 @@ from py import error from py.path import local -from _pytest.timing import perf_counter +import _pytest.timing import pytest @@ -747,7 +747,7 @@ def test_setmtime(self): name = tempfile.mktemp() open(name, "w").close() try: - mtime = int(perf_counter()) - 100 + mtime = int(_pytest.timing.perf_counter()) - 100 path = local(name) assert path.mtime() != mtime path.setmtime(mtime) @@ -1405,7 +1405,7 @@ def test_atime(self, tmpdir): import time path = tmpdir.ensure("samplefile") - now = perf_counter() + now = _pytest.timing.perf_counter() 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 = perf_counter() - now + duration = _pytest.timing.perf_counter() - now assert (atime2 - atime1) <= duration def test_commondir(self, path1): diff --git a/testing/test_pytester.py b/testing/test_pytester.py index 9e0a669ddcf..555d73f9eaa 100644 --- a/testing/test_pytester.py +++ b/testing/test_pytester.py @@ -15,7 +15,7 @@ from _pytest.pytester import Pytester from _pytest.pytester import SysModulesSnapshot from _pytest.pytester import SysPathsSnapshot -from _pytest.timing import perf_counter +import _pytest.timing import pytest @@ -451,9 +451,9 @@ def test_pytester_run_with_timeout(pytester: Pytester) -> None: timeout = 120 - start = perf_counter() + start = _pytest.timing.perf_counter() result = pytester.runpytest_subprocess(testfile, timeout=timeout) - end = perf_counter() + end = _pytest.timing.perf_counter() duration = end - start assert result.ret == ExitCode.OK From 76c0cd6190b541c8a7f47b099209b8dd00acf8a9 Mon Sep 17 00:00:00 2001 From: Deysha Rivera <50204868+rivtechprojects@users.noreply.github.com> Date: Fri, 25 Apr 2025 11:03:16 -0400 Subject: [PATCH 6/9] Update changelog/13384.bugfix.rst Co-authored-by: Bruno Oliveira --- changelog/13384.bugfix.rst | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/changelog/13384.bugfix.rst b/changelog/13384.bugfix.rst index e1c7ff7a181..e93d01dcab0 100644 --- a/changelog/13384.bugfix.rst +++ b/changelog/13384.bugfix.rst @@ -1,2 +1 @@ -Fixed an issue where pytest could report negative durations due to the use of `time.time()`. -Replaced `time.time()` with `_pytest.timing.perf_counter()` for more reliable timing. +Fixed an issue where pytest could report negative durations. From e5b29418b70313e0c9de67e0e4b8e03fc82c91f7 Mon Sep 17 00:00:00 2001 From: RivTech <50204868+RivTechProjects@users.noreply.github.com> Date: Fri, 25 Apr 2025 14:38:56 -0400 Subject: [PATCH 7/9] Change production level code to use timing.perf_counter --- src/_pytest/junitxml.py | 4 ++-- src/_pytest/pytester.py | 8 ++++---- src/_pytest/terminal.py | 8 ++++---- 3 files changed, 10 insertions(+), 10 deletions(-) diff --git a/src/_pytest/junitxml.py b/src/_pytest/junitxml.py index d129cd295e7..9f256552ce8 100644 --- a/src/_pytest/junitxml.py +++ b/src/_pytest/junitxml.py @@ -636,7 +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_time = timing.perf_counter() def pytest_sessionfinish(self) -> None: dirname = os.path.dirname(os.path.abspath(self.logfile)) @@ -644,7 +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_time = timing.time() + suite_stop_time = timing.perf_counter() suite_time_delta = suite_stop_time - self.suite_start_time numtests = ( diff --git a/src/_pytest/pytester.py b/src/_pytest/pytester.py index 59839562031..bb5f6a5787e 100644 --- a/src/_pytest/pytester.py +++ b/src/_pytest/pytester.py @@ -1150,7 +1150,7 @@ def runpytest_inprocess( if syspathinsert: self.syspathinsert() - now = timing.time() + now = timing.perf_counter() capture = _get_multicapture("sys") capture.start_capturing() try: @@ -1180,7 +1180,7 @@ class reprec: # type: ignore assert reprec.ret is not None res = RunResult( - reprec.ret, out.splitlines(), err.splitlines(), timing.time() - now + reprec.ret, out.splitlines(), err.splitlines(), timing.perf_counter() - now ) res.reprec = reprec # type: ignore return res @@ -1408,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.time() + now = timing.perf_counter() popen = self.popen( cmdargs, stdin=stdin, @@ -1445,7 +1445,7 @@ def handle_timeout() -> None: with contextlib.suppress(ValueError): ret = ExitCode(ret) - return RunResult(ret, out, err, timing.time() - now) + return RunResult(ret, out, err, timing.perf_counter() - now) def _dump_lines(self, lines, fp): try: diff --git a/src/_pytest/terminal.py b/src/_pytest/terminal.py index 3297c38e848..8415912e9ac 100644 --- a/src/_pytest/terminal.py +++ b/src/_pytest/terminal.py @@ -769,7 +769,7 @@ 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.time() + self._collect_report_last_write = timing.perf_counter() elif self.config.option.verbose >= 1: self.write("collecting ... ", flush=True, bold=True) @@ -789,7 +789,7 @@ def report_collect(self, final: bool = False) -> None: if not final: # Only write "collecting" report every 0.5s. - t = timing.time() + t = timing.perf_counter() if ( self._collect_report_last_write is not None and self._collect_report_last_write > t - REPORT_COLLECTING_RESOLUTION @@ -823,7 +823,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.time() + self._sessionstarttime = timing.perf_counter() if not self.showheader: return self.write_sep("=", "test session starts", bold=True) @@ -1202,7 +1202,7 @@ def summary_stats(self) -> None: if self.verbosity < -1: return - session_duration = timing.time() - self._sessionstarttime + session_duration = timing.perf_counter() - self._sessionstarttime (parts, main_color) = self.build_summary_stats_line() line_parts = [] From 730e62bb647f7d836a56c80c556f707d43c288f4 Mon Sep 17 00:00:00 2001 From: RivTech <50204868+RivTechProjects@users.noreply.github.com> Date: Fri, 25 Apr 2025 15:13:56 -0400 Subject: [PATCH 8/9] Fix Junit XML timestamp and duration handling. Use timing.time for suite start time, but retain perf_counter to measure suite_time_delta for precise calculations. --- src/_pytest/junitxml.py | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/src/_pytest/junitxml.py b/src/_pytest/junitxml.py index 9f256552ce8..06cab961ef5 100644 --- a/src/_pytest/junitxml.py +++ b/src/_pytest/junitxml.py @@ -636,7 +636,8 @@ 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.perf_counter() + self.suite_start_time = timing.time() + self.suite_start_perf = timing.perf_counter() def pytest_sessionfinish(self) -> None: dirname = os.path.dirname(os.path.abspath(self.logfile)) @@ -644,8 +645,8 @@ def pytest_sessionfinish(self) -> None: os.makedirs(dirname, exist_ok=True) with open(self.logfile, "w", encoding="utf-8") as logfile: - suite_stop_time = timing.perf_counter() - suite_time_delta = suite_stop_time - self.suite_start_time + suite_stop_perf = timing.perf_counter() + suite_time_delta = suite_stop_perf - self.suite_start_perf numtests = ( self.stats["passed"] From 068da8df267d36739a80753f897e3b4b4c0a3381 Mon Sep 17 00:00:00 2001 From: Bruno Oliveira Date: Sat, 26 Apr 2025 10:17:09 -0300 Subject: [PATCH 9/9] Update testing/_py/test_local.py --- testing/_py/test_local.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/testing/_py/test_local.py b/testing/_py/test_local.py index b158778c4fa..e4b011a9727 100644 --- a/testing/_py/test_local.py +++ b/testing/_py/test_local.py @@ -747,7 +747,7 @@ def test_setmtime(self): name = tempfile.mktemp() open(name, "w").close() try: - mtime = int(_pytest.timing.perf_counter()) - 100 + mtime = int(_pytest.timing.time()) - 100 path = local(name) assert path.mtime() != mtime path.setmtime(mtime)