Skip to content

pytest can report negative duration due to usage of time.time() #13384

@asottile

Description

@asottile

cutting most of the details here -- I'm using pytest 8.3.5 and just got this surprising result:

$ pytest tests/check_merge_conflict_test.py 
============================= test session starts ==============================
platform linux -- Python 3.12.3, pytest-8.3.5, pluggy-1.5.0
rootdir: /home/asottile/workspace/pre-commit-hooks
collected 12 items                                                             

tests/check_merge_conflict_test.py ............                          [100%]

============================= 12 passed in -0.94s ==============================

my tests are pretty fast but definitely not time-travelling fast.

it seems the root cause is usage of time.time() which is subject to smear seconds, etc. and should instead be using time.monotonic() or perf_counter()

seems there's a bunch of places we should adjust:

$ git grep '\btime\(\)' -- '*.py'
src/_pytest/junitxml.py:        self.suite_start_time = timing.time()
src/_pytest/junitxml.py:            suite_stop_time = timing.time()
src/_pytest/pytester.py:        now = timing.time()
src/_pytest/pytester.py:            reprec.ret, out.splitlines(), err.splitlines(), timing.time() - now
src/_pytest/pytester.py:            now = timing.time()
src/_pytest/pytester.py:        return RunResult(ret, out, err, timing.time() - now)
src/_pytest/runner.py:        start = timing.time()
src/_pytest/runner.py:        stop = timing.time()
src/_pytest/terminal.py:                self._collect_report_last_write = timing.time()
src/_pytest/terminal.py:            t = timing.time()
src/_pytest/terminal.py:        self._sessionstarttime = timing.time()
src/_pytest/terminal.py:        session_duration = timing.time() - self._sessionstarttime
src/_pytest/timing.py:    numbers and obtain accurate time() calls at the end, making tests reliable and instant."""
testing/_py/test_local.py:            mtime = int(time.time()) - 100
testing/_py/test_local.py:        now = time.time()
testing/_py/test_local.py:        duration = time.time() - now
testing/conftest.py:    numbers and obtain accurate time() calls at the end, making tests reliable and instant.
testing/test_pytester.py:    start = time.time()
testing/test_pytester.py:    end = time.time()

Metadata

Metadata

Assignees

No one assigned

    Labels

    good first issueeasy issue that is friendly to new contributorneeds backportapplied to PRs, indicates that it should be ported to the current bug-fix branchtopic: reportingrelated to terminal output and user-facing messages and errorstype: bugproblem that needs to be addressedtype: performanceperformance or memory problem/improvementtype: proposalproposal for a new feature, often to gather opinions or design the API around the new featuretype: refactoringinternal improvements to the code

    Type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions