Skip to content

Commit 33c1590

Browse files
Technologicatclaude
andcommitted
timer + ETAEstimator: use perf_counter instead of monotonic
`unpythonic.misc.timer` and `unpythonic.timeutil.ETAEstimator` both measured wall-clock time via `time.monotonic()`. Both are monotonic (guaranteed since Python 3.3), but `monotonic`'s resolution is implementation-defined, and on Windows it is backed by a ~16 ms tick counter. `time.perf_counter()` is documented as "the highest available resolution to measure a short duration" and is also guaranteed monotonic. The bug that forced the investigation was in `timer`: a PyPy- JIT'd `for _ in range(int(1e6)): pass` block runs in microseconds, which on Windows is **below** `monotonic`'s resolution, so `timer().dt` registered as exactly `0.0`. Three testsets in unpythonic's own suite then failed on windows-latest × pypy-3.11 in the expanded CI matrix: - `test_misc::timer` — `test[tictoc.dt > 0]` held `0 > 0`, Fail. - `test_fploop::performance benchmark` — `fp2.dt / ip.dt` was ZeroDivisionError, Error. - `test_tco::performance benchmark` — same ZeroDivisionError. All three cascaded from the one root cause; switching the clock in `timer` makes all three go green without touching the tests themselves. Every other call site of `timer` in user code also silently benefits. `ETAEstimator` measures per-task timings on the order of seconds to minutes, so `monotonic`'s resolution was not a correctness problem at that scale. Switched for consistency and for the documentation claim that `perf_counter` is the right tool for measuring wall-clock elapsed within a single process. Both classes only measure a dynamic extent in one process, so the "comparable across processes" guarantee of `monotonic` that we give up is not used anywhere. Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com>
1 parent 97b9388 commit 33c1590

3 files changed

Lines changed: 16 additions & 6 deletions

File tree

CHANGELOG.md

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44

55
**Fixed**:
66

7+
- `unpythonic.misc.timer` and `unpythonic.timeutil.ETAEstimator`: switched the underlying clock from `time.monotonic()` to `time.perf_counter()`. Both are monotonic (guaranteed since Python 3.3), but `perf_counter` is documented as *"a clock with the highest available resolution to measure a short duration"*, whereas `monotonic`'s resolution is implementation-defined. On Windows specifically, `time.monotonic()` is backed by a low-resolution (~16 ms) tick counter, so a `with timer() as t: ...` block that ran in microseconds — such as a PyPy-JIT'd `for _ in range(int(1e6)): pass` — recorded `t.dt` as **exactly 0.0**, silently producing wrong results and, in downstream code that divided by it, a `ZeroDivisionError`. On POSIX the two clocks are usually backed by the same high-resolution source, so this was a latent Windows-only bug. `ETAEstimator` is not affected as a correctness bug at its typical per-task scale (seconds to minutes), but was switched for consistency. We give up `monotonic`'s "comparable across processes" guarantee, which neither class needs — both measure a dynamic extent in wall-clock time within a single process.
78
- `unpythonic.test.runner`: module discovery crashed on MS Windows with `re.error: bad escape (end of pattern) at position 0`. The runner used `re.sub(os.path.sep, ...)` to convert a relative path into a dotted module name, which worked by accident on POSIX (where `os.path.sep` is `/`, not a regex metacharacter), but on Windows `os.path.sep` is a lone backslash — an incomplete escape as a regex pattern. Fixed by using `str.replace` instead, which treats both arguments as literal strings. Affects any project that reuses `unpythonic.test.runner` for its own macro-enabled tests on Windows.
89

910

unpythonic/misc.py

Lines changed: 12 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -15,7 +15,7 @@
1515
from itertools import count
1616
import inspect
1717
from queue import Empty
18-
from time import monotonic
18+
from time import perf_counter
1919
from types import FunctionType, LambdaType
2020

2121
from .regutil import register_decorator
@@ -124,10 +124,19 @@ def __init__(self, p=False):
124124
"""
125125
self.p = p
126126
def __enter__(self):
127-
self.t0 = monotonic()
127+
# `perf_counter`, not `monotonic`: the former is documented as "a
128+
# clock with the highest available resolution to measure a short
129+
# duration" and is backed by `QueryPerformanceCounter` (~100 ns) on
130+
# Windows, whereas `monotonic` is backed there by the ~16 ms
131+
# tick-counter and would record `dt = 0` for microsecond-scale
132+
# blocks (e.g. a PyPy-JIT'd tight loop). Both are monotonic; we
133+
# only give up the "comparable across processes" guarantee of
134+
# `monotonic`, which `timer` does not need since it only measures
135+
# a dynamic extent in wall-clock time within a single process.
136+
self.t0 = perf_counter()
128137
return self
129138
def __exit__(self, exctype, excvalue, traceback):
130-
self.dt = monotonic() - self.t0
139+
self.dt = perf_counter() - self.t0
131140
if self.p:
132141
print(self.dt)
133142

unpythonic/timeutil.py

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -70,7 +70,7 @@ class ETAEstimator:
7070
is available in `self.completed`.
7171
"""
7272
def __init__(self, total: int, keep_last: typing.Optional[int] = None):
73-
self.t1 = time.monotonic() # time since last tick
73+
self.t1 = time.perf_counter() # time since last tick
7474
self.t0 = self.t1 # time since beginning
7575
self.total = total # total number of work items
7676
self.completed = 0 # number of completed work items
@@ -79,7 +79,7 @@ def __init__(self, total: int, keep_last: typing.Optional[int] = None):
7979
def tick(self) -> None:
8080
"""Mark one more task as completed, automatically updating the internal timings cache."""
8181
self.completed += 1
82-
t = time.monotonic()
82+
t = time.perf_counter()
8383
dt = t - self.t1
8484
self.t1 = t
8585
self.que.append(dt)
@@ -109,7 +109,7 @@ def _estimate(self) -> typing.Optional[float]:
109109
estimate = property(fget=_estimate, doc="Estimate of time remaining, in seconds. Computed when read; read-only. If no tasks have been marked completed yet, the estimate is `None`.")
110110

111111
def _elapsed(self) -> float:
112-
return time.monotonic() - self.t0
112+
return time.perf_counter() - self.t0
113113
elapsed = property(fget=_elapsed, doc="Total elapsed time, in seconds. Computed when read; read-only.")
114114

115115
def _formatted_eta(self) -> str:

0 commit comments

Comments
 (0)