Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
10 changes: 8 additions & 2 deletions .github/workflows/ci.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -24,8 +24,12 @@ jobs:
strategy:
fail-fast: false
matrix:
python-version: [ "3.9", "3.10", "3.11", "3.12", "3.13" ]
name: Python ${{ matrix.python-version }}
python-version: [ "3.9", "3.10", "3.11", "3.12" ]
include:
- python-version: "3.13"
- python-version: "3.13"
install-extras: "pytest-asyncio<1.0.0"
name: Python ${{ matrix.python-version }}${{ matrix.install-extras && ', ' || '' }}${{ matrix.install-extras }}
runs-on: ubuntu-24.04
timeout-minutes: 5
steps:
Expand All @@ -36,6 +40,8 @@ jobs:

- run: pip install -r requirements.txt
- run: pip install -e .
- run: pip install "${{ matrix.install-extras }}"
if: ${{ matrix.install-extras }}
- run: pytest --color=yes --cov=looptime --cov-branch

- name: Publish coverage to Coveralls.io
Expand Down
138 changes: 127 additions & 11 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -3,8 +3,6 @@
[![CI](https://github.com/nolar/looptime/workflows/Thorough%20tests/badge.svg)](https://github.com/nolar/looptime/actions/workflows/thorough.yaml)
[![codecov](https://codecov.io/gh/nolar/looptime/branch/main/graph/badge.svg)](https://codecov.io/gh/nolar/looptime)
[![Coverage Status](https://coveralls.io/repos/github/nolar/looptime/badge.svg?branch=main)](https://coveralls.io/github/nolar/looptime?branch=main)
[![Total alerts](https://img.shields.io/lgtm/alerts/g/nolar/looptime.svg?logo=lgtm&logoWidth=18)](https://lgtm.com/projects/g/nolar/looptime/alerts/)
[![Language grade: Python](https://img.shields.io/lgtm/grade/python/g/nolar/looptime.svg?logo=lgtm&logoWidth=18)](https://lgtm.com/projects/g/nolar/looptime/context:python)
[![pre-commit](https://img.shields.io/badge/pre--commit-enabled-brightgreen?logo=pre-commit&logoColor=white)](https://github.com/pre-commit/pre-commit)

## What?
Expand All @@ -19,10 +17,10 @@ The effects of time removal can be seen from both sides:
This hides the code overhead and network latencies from the time measurements,
making the loop time sharply and predictably advancing in configured steps.

* From the **observer's (i.e. your) point of view,**
* From the **observer's (i.e. your personal) point of view,**
all activities of the event loop, such as sleeps, events/conditions waits,
timeouts, "later" callbacks, happen in near-zero amount of the real time
(above the usual code overhead).
(due to the usual code execution overhead).
This speeds up the execution of tests without breaking the tests' time-based
design, even if they are designed to run in seconds or minutes.

Expand Down Expand Up @@ -59,28 +57,28 @@ at the same time:
* One is for the coroutine-under-test which moves between states
in the background.
* Another one is for the test itself, which controls the flow
of that coroutine-under-test: it sets events, injects data, etc.
of that coroutine-under-test: it schedules events, injects data, etc.

In textbook cases with simple coroutines that are more like regular functions,
it is possible to design a test so that it runs straight to the end in one hop
— with all the preconditions set and data prepared in advance in the test setup.

However, in real-world cases, the tests often must verify that
However, in the real-world cases, the tests often must verify that
the coroutine stops at some point, waits for a condition for some limited time,
and then passes or fails.

The problem is often "solved" by mocking the low-level coroutines of sleep/wait
that we expect the coroutine-under-test to call. But this violates the main
principle of good unit-tests: test the promise, not the implementation.
principle of good unit-tests: **test the promise, not the implementation.**
Mocking and checking the low-level coroutines is based on the assumptions
of how the coroutine is implemented internally, which can change over time.
Good tests do not change on refactoring if the protocol remains the same.

Another (straightforward) approach is to not mock the low-level routines, but
to spend the real-world time, just in short bursts as hard-coded in the test.
Not only it makes the whole test-suite slower, it also brings the execution
time close to the values where the code overhead affects the timing
and makes it difficult to assert on the coroutine's pure time.
time close to the values where the code overhead or measurement errors affect
the timing, which makes it difficult to assert on the coroutine's pure time.


## Solution
Expand Down Expand Up @@ -232,13 +230,26 @@ async def test_me():
`start` (`float` or `None`, or a no-argument callable that returns the same)
is the initial time of the event loop.

If it is callable, it is invoked once per event loop to get the value:
If it is a callable, it is invoked once per event loop to get the value:
e.g. `start=time.monotonic` to align with the true time,
or `start=lambda: random.random() * 100` to add some unpredictability.

`None` is treated the same as `0.0`.

The default is `0.0`.
The default is `0.0`. For reusable event loops, the default is to keep
the time untouched, which means `0.0` or the explicit value for the first test,
but then an ever-increasing value for the 2nd, 3rd, and further tests.

Note: pytest-asyncio 1.0.0+ introduced event loops with higher scopes,
e.g. class-, module-, packages-, session-scoped event loops used in tests.
Such event loops are reused, so their time continues growing through many tests.
However, if the test is explicitly configured with the start time,
that time is enforced to the event loop when the test function starts —
to satisfy the clearly declared intentions — even if the time moves backwards,
which goes against the nature of the time itself (monotonically growing).
This might lead to surprises in time measurements outside of the test,
e.g. in fixtures: the code durations can become negative, or the events can
happen (falsely) before they are scheduled (loop-clock-wise). Be careful.


### The end of time
Expand All @@ -255,6 +266,8 @@ e.g. with `asyncio.sleep(0)`, simple `await` statements, etc.

If set to `None`, there is no end of time, and the event loop runs
as long as needed. Note: `0` means ending the time immediately on start.
Be careful with the explicit ending time in higher-scoped event loops
of pytest-asyncio>=1.0.0, since they time increases through many tests.

If it is a callable, it is called once per event loop to get the value:
e.g. `end=lambda: time.monotonic() + 10`.
Expand Down Expand Up @@ -512,6 +525,63 @@ For example, with the resolution `0.001`, the time
everything smaller than `0.001` becomes `0` and probably misbehaves._


### Time magic coverage

The time compaction magic is enabled only for the duration of the test,
i.e. the test function — but not the fixtures.
The fixtures run in the real (wall-clock) time.

The options (including the force starting time) are applied at the test function
starting moment, not when it is setting up the fixtures (even function-scoped).

This is caused by a new concept of multiple co-existing event loops
in pytest-asyncio>=1.0.0:

- It is unclear which options to apply to higher-scoped fixtures
used by many tests, which themselves use higher-scoped event loops —
especially in selective partial runs. Technically, it is the 1st test,
with the options of 2nd and further tests simply ignored.
- It is impossible to guess which event loop will be the running loop
in the test until we reach the test itself, i.e. we do not know this
when setting up the fixtures, even function-scoped fixtures.
- There is no way to cover the fixture teardown (no hook in pytest),
only for the fixture setup and post-teardown cleanup.

As such, this functionality (covering of function-scoped fixtures)
was abandoned — since it was never promised, tested, or documented —
plus an assumption that it was never used by anyone (it should not be).
It was rather a side effect of the previous implemention,
which is not available or possible anymore.


### pytest-asyncio>=1.0.0

As it is said above, pytest-asyncio>=1.0.0 introduced several co-existing
event loops of different scopes. The time compaction in these event loops
is NOT activated. Only the running loop of the test function is activated.

Configuring and activating multiple co-existing event loops brings a few
conceptual challenges, which require a good sample case to look into,
and some time to think.

Would you need time compaction in your fixtures of higher scopes,
do it explicitly:

```python
import asyncio
import pytest

@pytest.fixture
async def fixt():
loop = asyncio.get_running_loop()
loop.setup_looptime(start=123, end=456)
with loop.looptime_enabled():
await do_things()
```

There is #11 to add a feature to do this automatically, but it is not yet done.


## Extras

### Chronometers
Expand Down Expand Up @@ -605,6 +675,8 @@ the loop time also includes the time of all fixtures setups.
Do you use a custom event loop? No problem! Create a test-specific descendant
with the provided mixin — and it will work the same as the default event loop.

For `pytest-asyncio<1.0.0`:

```python
import looptime
import pytest
Expand All @@ -620,13 +692,38 @@ def event_loop():
return LooptimeCustomEventLoop()
```

For `pytest-asyncio>=1.0.0`:

```python
import asyncio
import looptime
import pytest
from wherever import CustomEventLoop


class LooptimeCustomEventLoop(looptime.LoopTimeEventLoop, CustomEventLoop):
pass


class LooptimeCustomEventLoopPolicy(asyncio.DefaultEventLoopPolicy):
def new_event_loop(self):
return LooptimeCustomEventLoop()


@pytest.fixture(scope='session')
def event_loop_policy():
return LooptimeCustomEventLoopPolicy()
```

Only selector-based event loops are supported: the event loop must rely on
`self._selector.select(timeout)` to sleep for `timeout` true-time seconds.
Everything that inherits from `asyncio.BaseEventLoop` should work.

You can also patch almost any event loop class or event loop object
the same way as `looptime` does that (via some dirty hackery):

For `pytest-asyncio<1.0.0`:

```python
import asyncio
import looptime
Expand All @@ -639,6 +736,25 @@ def event_loop():
return looptime.patch_event_loop(loop)
```

For `pytest-asyncio>=1.0.0`:

```python
import asyncio
import looptime
import pytest


class LooptimeEventLoopPolicy(asyncio.DefaultEventLoopPolicy):
def new_event_loop(self):
loop = super().new_event_loop()
return looptime.patch_event_loop(loop)


@pytest.fixture(scope='session')
def event_loop_policy():
return LooptimeEventLoopPolicy()
```

`looptime.make_event_loop_class(cls)` constructs a new class that inherits
from the referenced class and the specialised event loop class mentioned above.
The resulting classes are cached, so it can be safely called multiple times.
Expand Down
3 changes: 2 additions & 1 deletion looptime/__init__.py
Original file line number Diff line number Diff line change
@@ -1,10 +1,11 @@
from .chronometers import Chronometer
from .loops import IdleTimeoutError, LoopTimeEventLoop, LoopTimeoutError
from .loops import IdleTimeoutError, LoopTimeEventLoop, LoopTimeoutError, TimeWarning
from .patchers import make_event_loop_class, new_event_loop, patch_event_loop, reset_caches
from .timeproxies import LoopTimeProxy

__all__ = [
'Chronometer',
'TimeWarning',
'LoopTimeProxy',
'IdleTimeoutError',
'LoopTimeoutError',
Expand Down
73 changes: 70 additions & 3 deletions looptime/loops.py
Original file line number Diff line number Diff line change
@@ -1,10 +1,12 @@
from __future__ import annotations

import asyncio
import contextlib
import selectors
import time
import warnings
import weakref
from typing import TYPE_CHECKING, Any, Callable, MutableSet, TypeVar, cast, overload
from typing import TYPE_CHECKING, Any, Callable, Iterator, MutableSet, TypeVar, cast, overload

_T = TypeVar('_T')

Expand All @@ -16,6 +18,11 @@
AnyTask = asyncio.Task


class TimeWarning(UserWarning):
"""Issued when the loop time moves backwards, violating its monotonicity."""
pass


class LoopTimeoutError(asyncio.TimeoutError):
"""A special kind of timeout when the loop's time reaches its end."""
pass
Expand Down Expand Up @@ -61,6 +68,7 @@ def setup_looptime(
idle_step: float | None = None,
idle_timeout: float | None = None,
noop_cycles: int = 42,
_enabled: bool | None = None, # None means do nothing
) -> None:
"""
Set all the fake-time fields and patch the i/o selector.
Expand All @@ -69,9 +77,33 @@ def setup_looptime(
when the mixin/class is injected into the existing event loop object.
In that case, the object is already initialised except for these fields.
"""
new_time: float | None = start() if callable(start) else start
end_time: float | None = end() if callable(end) else end
old_time: float | None
try:
# NB: using the existing (old) reciprocal!
old_time = self.__int2time(self.__now)
except AttributeError: # initial setup: either reciprocals or __now are absent
old_time = None
new_time = float(new_time) if new_time is not None else None

# If it is the 2nd or later setup, double-check on time monotonicity.
# In some configurations, this waring might raise an error and fail the test.
# In that case, the time must not be changed for the next test.
if old_time is not None and new_time is not None and new_time < old_time:
warnings.warn(
f"The time of the event loop moves backwards from {old_time} to {new_time},"
" thus breaking the monotonicity of time. This is dangerous!"
" Perhaps, caused by reusing a higher-scope event loop in tests."
" Revise the scopes of fixtures & event loops."
" Remove the start=… kwarg and rely on arbitrary time values."
" Migrate from `loop.time()` to the `looptime` numeric fixture.",
TimeWarning,
)

self.__resolution_reciprocal: int = round(1/resolution)
self.__now: int = self.__time2int(start() if callable(start) else start) or 0
self.__end: int | None = self.__time2int(end() if callable(end) else end)
self.__now: int = self.__time2int(new_time or old_time) or 0
self.__end: int | None = self.__time2int(end_time)

self.__idle_timeout: int | None = self.__time2int(idle_timeout)
self.__idle_step: int | None = self.__time2int(idle_step)
Expand All @@ -85,6 +117,13 @@ def setup_looptime(
self.__sync_clock: Callable[[], float] = time.perf_counter
self.__sync_ts: float | None = None # system/true-time clock timestamp

try:
self.__enabled # type: ignore
except AttributeError:
self.__enabled = _enabled if _enabled is not None else True # old behaviour
else:
self.__enabled = _enabled if _enabled is not None else self.__enabled

# TODO: why do we patch the selector as an object while the event loop as a class?
# this should be the same patching method for both.
try:
Expand All @@ -93,6 +132,24 @@ def setup_looptime(
self.__original_select = self._selector.select
self._selector.select = self.__replaced_select # type: ignore

@property
def looptime_on(self) -> bool:
return bool(self.__enabled)

@contextlib.contextmanager
def looptime_enabled(self) -> Iterator[None]:
"""
Temporarily enable the time compaction, restore the normal mode on exit.
"""
if self.__enabled:
raise RuntimeError('Looptime mode is already enabled. Entered twice? Avoid this!')
old_enabled = self.__enabled
self.__enabled = True
try:
yield
finally:
self.__enabled = old_enabled

def time(self) -> float:
return self.__int2time(self.__now)

Expand All @@ -111,6 +168,16 @@ def __replaced_select(self, timeout: float | None) -> list[tuple[Any, Any]]:
if ready:
pass

# If nothing to do right now, and the time is not compacted, truly sleep as requested.
# Move the fake time by the exact real time spent in this wait (±discrepancies).
elif not self.__enabled:
t0 = time.monotonic()
ready = self.__original_select(timeout=timeout)
t1 = time.monotonic()

# If timeout=None, it never exists until ready. This timeout check is for typing only.
self.__now += self.__time2int(t1 - t0 if ready or timeout is None else timeout)

# Regardless of the timeout, if there are executors sync futures, we move the time in steps.
# The timeout (if present) can limit the size of the step, but not the logic of stepping.
# Generally, external things (threads) take some time (e.g. for thread spawning).
Expand Down
Loading
Loading