Skip to content

Wrong times when mocking time with freezegun #432

@spaceship-zebra

Description

@spaceship-zebra

I wanted to use pyinstrument to profile my tests, however because the tests use freezegun to mock the time, pyinstrument gets confused with how long each function call took.

I'm not sure how one would work around this. Maybe getting the original references before freezegun patches them could work, depending on how freezegun patches the results. Using python3 -m cProfile -o profile -m pytest shows correct timings.

Steps to reproduce

Install pytest, pyinstrument and freezegun.

# tests/some_test.py
from freezegun import freeze_time
from datetime import datetime
import time


@freeze_time(datetime(2025, 1, 1))
def test_2025():
    time.sleep(0.1)
    assert datetime.now() == datetime(2025, 1, 1)


@freeze_time(datetime(2026, 1, 1))
def test_2026():
    time.sleep(0.1)
    assert datetime.now() == datetime(2026, 1, 1)


def test_multiple_times():
    with freeze_time(datetime(2000, 1, 1)):
        time.sleep(0.1)
        assert datetime.now() == datetime(2000, 1, 1)
    with freeze_time(datetime(2001, 1, 1)):
        time.sleep(0.1)
        assert datetime.now() == datetime(2001, 1, 1)

Run pyinstrument -m pytest

pyinstrument -m pytest
============================================================================================ test session starts ============================================================================================
platform darwin -- Python 3.14.0, pytest-9.0.2, pluggy-1.6.0
rootdir: /Users/lechneo1/repos/playground_pyinstrument
configfile: pyproject.toml
collected 3 items                                                                                                                                                                                           

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

============================================================================================= 3 passed in 0.46s =============================================================================================

  _     ._   __/__   _ _  _  _ _/_   Recorded: 08:20:02  Samples:  111
 /_//_/// /_\ / //_// / //_'/ //     Duration: 0.556     CPU time: 0.140
/   _/                      v5.1.2

Program: pytest

0.517 <module>  pytest/__main__.py:1
└─ 0.517 console_main  _pytest/config/__init__.py:216
      [59 frames hidden]  _pytest, pluggy, freezegun, contextli...
         4481215907.068 pytest_pyfunc_call  _pytest/python.py:159
         │  1767223435.685 dir  <built-in>
         │  1735687435.804 getattr  <built-in>
         └─ 978305035.576 test_multiple_times  some_test.py:18
            └─ 978305035.576 _freeze_time.__enter__  freezegun/api.py:737
                  [2 frames hidden]  freezegun
                     978305035.576 _get_module_attributes_hash  freezegun/api.py:130
                     ├─ 946682635.576 dir  <built-in>
                     └─ 31622400.000 [self]  freezegun/api.py

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions