From e9cf30a99543909da6e011afd6e31c19b59cf200 Mon Sep 17 00:00:00 2001 From: Rafael Martins Date: Sun, 2 Aug 2026 16:40:16 -0300 Subject: [PATCH 1/3] Stop losing and double-counting lap time Three ways the stopwatch reported wrong numbers without ever raising. `lap()` was a @contextmanager with a bare `yield` between `start()` and `stop()`, so an exception inside the block skipped `stop()` entirely. The lap stayed open forever, and because `Lap.elapsed` falls back to `perf_counter() - self._start` while running, `elapsed`, `statistics` and `report()` then returned a different value on every read. Measured before the fix: 0.0502 then 0.1004 from two consecutive reads of the same stopwatch. Now wrapped in try/finally. Nested `lap()` calls silently discarded the outer lap's time. `start()` returns early when the stopwatch is already running, so the inner call opened no lap, and the inner `stop()` closed the *outer* one -- leaving the outer `stop()` a no-op and everything after the inner block unmeasured. A 0.25s outer block containing a 0.10s inner block reported 0.15s in a single lap. Each `lap()` now owns a distinct lap. The reuse of the running lap is deliberate and kept: a Stopwatch starts measuring on construction, so the first `lap()` adopts that lap rather than opening a second one, which is what stops `with Stopwatch() as sw: with sw.lap():` from recording a phantom lap. Clearing `_current_lap` is what hands ownership to the context manager and lets a nested call open its own lap. What remains is noted as a ponytail comment on `lap()`: time between construction and the first `lap()` is still billed to that first lap. `running` now asks the laps instead of `_current_lap`, which is None while a `lap()` block owns its lap. `Lap.stop()` is idempotent. It used to append `perf_counter() - self._start` unconditionally after having reset `_start` to 0.0, so a second call recorded the machine uptime as a lap fraction. Not reachable through Stopwatch today, but `Lap` is importable and the failure mode is silent garbage rather than an error. Each fix has a regression test. Verified they catch the bugs by reverting the three fixes and re-running: exactly those three tests fail, the other 35 pass. Co-Authored-By: Claude Opus 5 --- stopwatch/lap.py | 6 +++++- stopwatch/stopwatch.py | 32 ++++++++++++++++++++++++++------ tests/test_lap.py | 12 ++++++++++++ tests/test_stopwatch.py | 35 +++++++++++++++++++++++++++++++++++ 4 files changed, 78 insertions(+), 7 deletions(-) diff --git a/stopwatch/lap.py b/stopwatch/lap.py index febacf4..da87833 100644 --- a/stopwatch/lap.py +++ b/stopwatch/lap.py @@ -30,8 +30,12 @@ def start(self) -> None: def stop(self) -> None: """ - Stop the lap timer. + Stop the lap timer. Stopping an already stopped lap does nothing. """ + # Without this guard a second stop() would record + # perf_counter() - 0.0, i.e. the machine uptime, as a fraction. + if not self.running: + return self._fractions.append(time.perf_counter() - self._start) self._start = 0.0 self.running = False diff --git a/stopwatch/stopwatch.py b/stopwatch/stopwatch.py index 93b6ac0..d53213f 100644 --- a/stopwatch/stopwatch.py +++ b/stopwatch/stopwatch.py @@ -53,7 +53,7 @@ def elapsed(self) -> float: @property def running(self) -> bool: """`bool`: True if the stopwatch is running, False if stopped.""" - return self._current_lap is not None and self._current_lap.running + return any(lap.running for lap in self.laps) @property def statistics(self) -> Statistics: @@ -63,12 +63,32 @@ def statistics(self) -> Statistics: @contextmanager def lap(self) -> Iterator[None]: """ - Context manager for add a new lap. + Context manager that records the block it wraps as its own lap. + + Each call records a distinct lap, so nesting works and the lap is + always closed even if the block raises. + + ponytail: the first lap adopts the lap started on construction, so + any time between `Stopwatch()` and the first `lap()` is billed to + that lap. Call `reset()` before the first `lap()` to avoid it; add + an `autostart=False` option if that turns out to be the common + case. """ - # calling start twice consecutively -> use stack to solve this problem - self.start() - yield - self.stop() + # A Stopwatch starts measuring on construction, so adopt the lap + # that is already running instead of opening a second one -- that + # is what keeps `with Stopwatch() as sw: with sw.lap():` from + # recording a phantom lap. Handing ownership over by clearing + # _current_lap is what lets a nested lap() open its own. + lap = self._current_lap + if lap is None or not lap.running: + lap = Lap() + self.laps.append(lap) + lap.start() + self._current_lap = None + try: + yield + finally: + lap.stop() def start(self) -> Stopwatch: """ diff --git a/tests/test_lap.py b/tests/test_lap.py index 02a98a2..fec3fa3 100644 --- a/tests/test_lap.py +++ b/tests/test_lap.py @@ -31,6 +31,18 @@ def test_stop(self) -> None: self.assertEqual(lap.elapsed, 1) self.assertEqual(repr(lap), '') + def test_stop_twice_is_a_noop(self) -> None: + with patch('time.perf_counter', self.time_mock.perf_counter): + lap = Lap() + lap.start() + self.time_mock.increment(1) + lap.stop() + self.time_mock.increment(100) + # An unguarded second stop() records perf_counter() - 0.0. + lap.stop() + self.assertEqual(lap.elapsed, 1.0) + self.assertEqual(lap._fractions, [1.0]) + def test_multiples_stars(self) -> None: with patch('time.perf_counter', self.time_mock.perf_counter): lap = Lap() diff --git a/tests/test_stopwatch.py b/tests/test_stopwatch.py index b41433e..b61fe23 100644 --- a/tests/test_stopwatch.py +++ b/tests/test_stopwatch.py @@ -127,6 +127,41 @@ def test_stopwatch_report_with_laps(self) -> None: 'min=0.00s, median=2.00s, max=4.00s, dev=1.41s', ) + def test_stopwatch_lap_closes_on_exception(self) -> None: + with patch('time.perf_counter', self.time_mock.perf_counter): + sw = Stopwatch() + with self.assertRaises(ValueError): + with sw.lap(): + self.time_mock.increment(1) + raise ValueError('boom') + # A lap left open would keep billing wall-clock time here. + self.time_mock.increment(10) + self.assertFalse(sw.running) + self.assertEqual(len(sw.laps), 1) + self.assertEqual(sw.elapsed, 1.0) + + def test_stopwatch_nested_laps_keep_outer_time(self) -> None: + with patch('time.perf_counter', self.time_mock.perf_counter): + sw = Stopwatch() + with sw.lap(): + self.time_mock.increment(1) + with sw.lap(): + self.time_mock.increment(2) + self.time_mock.increment(4) + self.assertEqual(len(sw.laps), 2) + self.assertEqual(sw.laps[0].elapsed, 7.0) + self.assertEqual(sw.laps[1].elapsed, 2.0) + self.assertFalse(sw.running) + + def test_stopwatch_instances_do_not_share_laps(self) -> None: + with patch('time.perf_counter', self.time_mock.perf_counter): + sw1 = Stopwatch() + sw2 = Stopwatch() + self.time_mock.increment(1) + sw1.stop() + self.assertIsNot(sw1.laps, sw2.laps) + self.assertFalse(hasattr(Stopwatch, 'laps')) + def test_stopwatch_statistics(self) -> None: with patch('time.perf_counter', self.time_mock.perf_counter): with Stopwatch() as sw: From 30433daf06bbf7bf48f0faf7522eb6d66bb20a4d Mon Sep 17 00:00:00 2001 From: Rafael Martins Date: Sun, 2 Aug 2026 17:16:47 -0300 Subject: [PATCH 2/3] Let the code carry the explanation instead of comments Drop the inline comments and the ponytail marker, and make the lap handover legible on its own: `_take_running_lap() or _open_lap()` says what the branch did. `_open_lap` also removes the duplicated append/start that `start()` was repeating. The remaining docstrings state behaviour only, no rationale. Co-Authored-By: Claude Opus 5 --- stopwatch/lap.py | 2 -- stopwatch/stopwatch.py | 36 +++++++++++++++++------------------- tests/test_lap.py | 1 - tests/test_stopwatch.py | 1 - 4 files changed, 17 insertions(+), 23 deletions(-) diff --git a/stopwatch/lap.py b/stopwatch/lap.py index da87833..3fae30d 100644 --- a/stopwatch/lap.py +++ b/stopwatch/lap.py @@ -32,8 +32,6 @@ def stop(self) -> None: """ Stop the lap timer. Stopping an already stopped lap does nothing. """ - # Without this guard a second stop() would record - # perf_counter() - 0.0, i.e. the machine uptime, as a fraction. if not self.running: return self._fractions.append(time.perf_counter() - self._start) diff --git a/stopwatch/stopwatch.py b/stopwatch/stopwatch.py index d53213f..ed2efab 100644 --- a/stopwatch/stopwatch.py +++ b/stopwatch/stopwatch.py @@ -68,28 +68,28 @@ def lap(self) -> Iterator[None]: Each call records a distinct lap, so nesting works and the lap is always closed even if the block raises. - ponytail: the first lap adopts the lap started on construction, so - any time between `Stopwatch()` and the first `lap()` is billed to - that lap. Call `reset()` before the first `lap()` to avoid it; add - an `autostart=False` option if that turns out to be the common - case. + A stopwatch is already running once constructed, and the first lap + takes over that lap rather than opening a second one, so any time + between `Stopwatch()` and the first `lap()` belongs to it. Call + `reset()` first to leave it out. """ - # A Stopwatch starts measuring on construction, so adopt the lap - # that is already running instead of opening a second one -- that - # is what keeps `with Stopwatch() as sw: with sw.lap():` from - # recording a phantom lap. Handing ownership over by clearing - # _current_lap is what lets a nested lap() open its own. - lap = self._current_lap - if lap is None or not lap.running: - lap = Lap() - self.laps.append(lap) - lap.start() - self._current_lap = None + lap = self._take_running_lap() or self._open_lap() try: yield finally: lap.stop() + def _open_lap(self) -> Lap: + lap = Lap() + self.laps.append(lap) + lap.start() + return lap + + def _take_running_lap(self) -> Lap | None: + lap = self._current_lap + self._current_lap = None + return lap if lap is not None and lap.running else None + def start(self) -> Stopwatch: """ Starts the stopwatch. @@ -100,9 +100,7 @@ def start(self) -> Stopwatch: The started stopwatch instance. """ if not self.running: - self.laps.append(Lap()) - self._current_lap = self.laps[-1] - self._current_lap.start() + self._current_lap = self._open_lap() return self def stop(self) -> Stopwatch: diff --git a/tests/test_lap.py b/tests/test_lap.py index fec3fa3..70c6eb2 100644 --- a/tests/test_lap.py +++ b/tests/test_lap.py @@ -38,7 +38,6 @@ def test_stop_twice_is_a_noop(self) -> None: self.time_mock.increment(1) lap.stop() self.time_mock.increment(100) - # An unguarded second stop() records perf_counter() - 0.0. lap.stop() self.assertEqual(lap.elapsed, 1.0) self.assertEqual(lap._fractions, [1.0]) diff --git a/tests/test_stopwatch.py b/tests/test_stopwatch.py index b61fe23..741883a 100644 --- a/tests/test_stopwatch.py +++ b/tests/test_stopwatch.py @@ -134,7 +134,6 @@ def test_stopwatch_lap_closes_on_exception(self) -> None: with sw.lap(): self.time_mock.increment(1) raise ValueError('boom') - # A lap left open would keep billing wall-clock time here. self.time_mock.increment(10) self.assertFalse(sw.running) self.assertEqual(len(sw.laps), 1) From 17af883fa6c21804ed9c8d3a2d1637869ee1c4c6 Mon Sep 17 00:00:00 2001 From: Rafael Martins Date: Sun, 2 Aug 2026 17:58:26 -0300 Subject: [PATCH 3/3] Add Stopwatch(autostart=False) A stopwatch starts measuring on construction, and the first lap() takes over that lap, so setup work between the constructor and the first lap() is billed to it: sw = Stopwatch() load_config() # 5s for item in items: with sw.lap(): process(item) # 0.1s -> first lap reports 5.1s `autostart=False` skips the initial start(), so only the blocks wrapped in lap() are measured. The default stays True, so nothing changes for existing callers, and using the stopwatch as a context manager still starts it because __enter__ restarts regardless. Co-Authored-By: Claude Opus 5 --- stopwatch/stopwatch.py | 22 +++++++++++++++++++--- tests/test_stopwatch.py | 19 +++++++++++++++++++ 2 files changed, 38 insertions(+), 3 deletions(-) diff --git a/stopwatch/stopwatch.py b/stopwatch/stopwatch.py index ed2efab..481301c 100644 --- a/stopwatch/stopwatch.py +++ b/stopwatch/stopwatch.py @@ -18,7 +18,22 @@ def __init__( name: str | None = None, print_report: bool = False, precision: int = 2, + autostart: bool = True, ) -> None: + """ + Parameters + ---------- + name : Optional[`str`] + The name shown in the reports. + print_report : `bool` + Print a report when leaving a `with` block. Default is False. + precision : `int` + The number of decimal places in the reports. Default is 2. + autostart : `bool` + Start measuring right away. Default is True. Pass False to + measure only the blocks wrapped in `lap()`, leaving the time + before the first one out. + """ self.name = name self.precision = precision self.laps: list[Lap] = [] @@ -27,7 +42,8 @@ def __init__( self._caller: Caller | None = ( inspect_caller() if print_report else None ) - self.start() + if autostart: + self.start() def __enter__(self) -> Stopwatch: return self.restart() @@ -70,8 +86,8 @@ def lap(self) -> Iterator[None]: A stopwatch is already running once constructed, and the first lap takes over that lap rather than opening a second one, so any time - between `Stopwatch()` and the first `lap()` belongs to it. Call - `reset()` first to leave it out. + between `Stopwatch()` and the first `lap()` belongs to it. Build it + with `autostart=False` to leave that time out. """ lap = self._take_running_lap() or self._open_lap() try: diff --git a/tests/test_stopwatch.py b/tests/test_stopwatch.py index 741883a..1d17dc1 100644 --- a/tests/test_stopwatch.py +++ b/tests/test_stopwatch.py @@ -127,6 +127,25 @@ def test_stopwatch_report_with_laps(self) -> None: 'min=0.00s, median=2.00s, max=4.00s, dev=1.41s', ) + def test_stopwatch_without_autostart_measures_only_laps(self) -> None: + with patch('time.perf_counter', self.time_mock.perf_counter): + sw = Stopwatch(autostart=False) + self.time_mock.increment(5) + self.assertFalse(sw.running) + self.assertEqual(sw.laps, []) + self.assertEqual(sw.elapsed, 0.0) + with sw.lap(): + self.time_mock.increment(1) + self.assertEqual(len(sw.laps), 1) + self.assertEqual(sw.elapsed, 1.0) + + def test_stopwatch_without_autostart_still_starts_as_context(self) -> None: + with patch('time.perf_counter', self.time_mock.perf_counter): + with Stopwatch(autostart=False) as sw: + self.time_mock.increment(1) + self.assertTrue(sw.running) + self.assertEqual(sw.elapsed, 1.0) + def test_stopwatch_lap_closes_on_exception(self) -> None: with patch('time.perf_counter', self.time_mock.perf_counter): sw = Stopwatch()