How to Build a Python Timer Class You Can Use as a Context Manager or Decorator
Build a reusable Python Timer class from scratch, then turn it into a context manager and a decorator while catching two real bugs a naive version would ship with.
Every developer eventually needs to answer a simple question: how long did that piece of code actually take to run? Maybe you are comparing two implementations to see which one is faster, maybe you are hunting for the slow line in a request handler, or maybe you just want to log how long a batch job took. The instinct is almost always to reach for Python’s time module, jot down a timestamp before the code runs and another one after, and subtract. That instinct is correct, but the details underneath it are not as obvious as they look, and getting them wrong quietly skews every number you measure afterward.
Table Of Content
- What You Will Build
- Prerequisites
- Step 1: Learn Python’s Three Clocks Before You Trust Any of Them
- time.time(): Wall-Clock Time That Can Jump Backward
- time.perf_counter(): The Right Tool for Benchmarking
- time.process_time(): CPU Time, Not Wall-Clock Time
- Proving the Difference With a Real Comparison
- Step 2: Time a Block of Code the Manual Way
- Step 3: Wrap the Logic in a Timer Class
- Step 4: Support Multiple Named Timers With a Dataclass
- Step 5: Turn the Timer Into a Context Manager
- Step 6: The __exit__ Return-Value Trap (a Real Bug)
- Step 7: Make the Timer Usable as a Decorator Too
- A Real Reentrancy Bug: When Decorators and Recursion Collide
- Fixing It With a Decorator Factory
- Step 8: Put It to Work: A Real Performance Comparison
- Step 9: Verify Everything With pytest
- Common Mistakes and Gotchas
- Verify It All Works End to End
- Next Steps
This tutorial builds a small, reusable Timer class from scratch, using nothing but Python’s standard library. Along the way you will learn which of Python’s three timing functions to actually use and why the other two can mislead you, how to turn a plain class into a context manager so you can write with Timer(): around any block of code, and how to make that same class double as a decorator so you can write @timed above a function definition. You will also personally trigger two real bugs that a naive version of this code ships with, a silently swallowed exception and a decorator that breaks under recursion, and fix both of them. Every command in this tutorial was run for real while writing it, and every number shown is real output, not an invented example.
What You Will Build
- A working comparison of Python’s three timing functions,
time.time(),time.perf_counter(), andtime.process_time(), showing exactly how they disagree - A
Timerclass that raises a clear error instead of silently misbehaving when it is used incorrectly - Support for multiple named timers that accumulate a running total, using a
dataclass - A context manager version of the Timer, plus a demonstration of a real bug where an incorrectly written
__exit__method silently swallows exceptions - A decorator version of the same Timer built on
contextlib.ContextDecorator, plus a real, reproducible bug where that decorator breaks under recursive calls, and a fix for it - A pytest suite that verifies all of the above without relying on fragile sleep-and-hope timing assertions
Prerequisites
- Python 3.10 or newer (this tutorial uses the
X | Noneunion syntax from PEP 604 throughout; if you are on an older Python, swap intyping.Optional[X]instead). This tutorial was written and tested against Python 3.13.14 on Windows, but nothing here is platform-specific - Basic familiarity with Python classes and functions. No prior experience with context managers or decorators is assumed: this tutorial builds that understanding as it goes
pytestinstalled for the verification section (pip install pytest)- No external services, accounts, or API keys. Everything in this tutorial runs entirely on your own machine
- About 30 to 40 minutes
Step 1: Learn Python’s Three Clocks Before You Trust Any of Them
Python’s time module actually gives you three different ways to measure elapsed time, and they are not interchangeable. Using the wrong one for the wrong job is the single most common mistake in hand-rolled timing code, so it is worth understanding the difference before writing a single line of the Timer class itself.
time.time(): Wall-Clock Time That Can Jump Backward
time.time() returns the number of seconds since the Unix epoch, the same value your operating system’s clock reports. The official Python documentation is direct about its biggest hazard: While this function normally returns non-decreasing values, it can return a lower value than a previous call if the system clock has been set back between the two calls.
That is not a hypothetical edge case. Network Time Protocol (NTP) synchronization, a user manually adjusting the clock, or a virtual machine correcting for clock drift after being paused can all move this value backward mid-measurement. If you subtract two time.time() readings and the clock happened to jump backward in between, you can end up with a negative “elapsed time”, which is obviously wrong and can crash code that assumes elapsed time is never negative.
time.perf_counter(): The Right Tool for Benchmarking
For measuring how long code takes to run, Python provides a function built specifically for that job. The documentation describes time.perf_counter() as a clock with the highest available resolution to measure a short duration,
and, critically, notes that on CPython it use[s] the same clock as time.monotonic() and is a monotonic clock, i.e. a clock that cannot go backwards.
A monotonic clock has no fixed relationship to wall-clock time at all; its only guarantee is that later readings are never smaller than earlier ones. That guarantee is exactly what you want when the only thing you care about is the difference between two timestamps. The documentation adds one more detail worth remembering: perf_counter does include time elapsed during sleep,
meaning it measures real wall-clock duration, including time your program spent waiting on I/O, a lock, or an explicit sleep() call.
time.process_time(): CPU Time, Not Wall-Clock Time
time.process_time() measures something different on purpose. Per the documentation, it returns the sum of the system and user CPU time of the current process,
and explicitly does not include time elapsed during sleep.
If your code spends most of its time waiting on a network call or a sleep(), process_time() will barely move, even while several real seconds pass on the wall clock. That makes it the right tool for a specific, narrower question: how much actual CPU work did this code do, independent of how long it sat around waiting for something else.
Proving the Difference With a Real Comparison
Rather than take those claims on faith, measure them. Create a project folder and a file called compare_clocks.py:
import time
def cpu_bound_work(n: int = 5_000_000) -> int:
total = 0
for i in range(n):
total += i * i
return total
def run_with_clock(label: str, clock_func, include_sleep: bool) -> None:
start = clock_func()
cpu_bound_work()
if include_sleep:
time.sleep(0.3)
end = clock_func()
print(f"{label:>16}: {end - start:.4f}s")
if __name__ == "__main__":
print("-- CPU work only (no sleep) --")
run_with_clock("time.time()", time.time, include_sleep=False)
run_with_clock("perf_counter()", time.perf_counter, include_sleep=False)
run_with_clock("process_time()", time.process_time, include_sleep=False)
print()
print("-- CPU work + time.sleep(0.3) --")
run_with_clock("time.time()", time.time, include_sleep=True)
run_with_clock("perf_counter()", time.perf_counter, include_sleep=True)
run_with_clock("process_time()", time.process_time, include_sleep=True)
Run it:
python compare_clocks.py
Real captured output from this exact run:
-- CPU work only (no sleep) --
time.time(): 0.1266s
perf_counter(): 0.1263s
process_time(): 0.1094s
-- CPU work + time.sleep(0.3) --
time.time(): 0.4189s
perf_counter(): 0.4198s
process_time(): 0.1250s
With no sleep involved, all three clocks roughly agree, give or take normal measurement noise. Add a 0.3 second time.sleep() call, though, and time.time() and perf_counter() both jump up by roughly that amount, while process_time() barely moves at all. That gap is not a rounding error: it is process_time() doing exactly what its documentation promises: ignoring time your process spent asleep rather than doing work. This is also diagnostically useful in real applications: if a slow request shows high wall-clock time (perf_counter()) but low CPU time (process_time()), that is a strong signal the bottleneck is I/O, a network call, a database query, a lock, not your own code’s computation.
The takeaway for the rest of this tutorial: use time.perf_counter() for measuring elapsed wall-clock duration. It is the function the standard library itself recommends for benchmarking, and it is what the Timer class below is built on.
Step 2: Time a Block of Code the Manual Way
Before building a class, look at the pattern it is going to wrap. The simplest possible way to time something is two function calls around the code you care about:
import time
def start_timer():
return time.perf_counter()
def stop_timer(start_time):
elapsed = time.perf_counter() - start_time
print(f"Elapsed: {elapsed:.4f} seconds")
return elapsed
if __name__ == "__main__":
t = start_timer()
time.sleep(0.2)
stop_timer(t)
t = start_timer()
total = sum(i * i for i in range(2_000_000))
stop_timer(t)
Save this as manual_timer.py and run it. Real captured output:
Elapsed: 0.2006 seconds
Elapsed: 0.0670 seconds
This works, but it has an obvious weakness: nothing stops you from calling stop_timer() without ever calling start_timer() first, or calling start_timer() twice and losing track of the first timestamp. There is also nowhere to keep state, like a running total across several calls, without threading extra variables through your code by hand. A class fixes both problems.
Step 3: Wrap the Logic in a Timer Class
Create timer_v1.py:
import time
class TimerError(Exception):
"""A Timer was used incorrectly."""
class Timer:
def __init__(self):
self._start_time = None
self.elapsed = None
def start(self):
if self._start_time is not None:
raise TimerError("Timer is already running. Use .stop() first.")
self._start_time = time.perf_counter()
def stop(self):
if self._start_time is None:
raise TimerError("Timer is not running. Use .start() first.")
self.elapsed = time.perf_counter() - self._start_time
self._start_time = None
print(f"Elapsed: {self.elapsed:.4f} seconds")
return self.elapsed
if __name__ == "__main__":
t = Timer()
t.start()
time.sleep(0.15)
t.stop()
print("\nCalling stop() twice in a row:")
try:
t.stop()
except TimerError as exc:
print(f"Caught expected error: {exc}")
print("\nCalling start() twice in a row:")
t2 = Timer()
t2.start()
try:
t2.start()
except TimerError as exc:
print(f"Caught expected error: {exc}")
t2.stop()
Run it. Real captured output:
Elapsed: 0.1502 seconds
Calling stop() twice in a row:
Caught expected error: Timer is not running. Use .start() first.
Calling start() twice in a row:
Caught expected error: Timer is already running. Use .stop() first.
Elapsed: 0.0000 seconds
The custom TimerError exception matters more than it might look like. A generic ValueError or, worse, an unhandled TypeError from calling arithmetic on None, gives a caller no reliable way to distinguish “this Timer was misused” from any other kind of bug. A dedicated exception class means code that uses Timer can catch exactly this failure mode on purpose, and the error message tells you precisely which of the two possible mistakes you made.
Step 4: Support Multiple Named Timers With a Dataclass
A single unnamed Timer is useful for a one-off measurement, but real code usually wants to track several different things and see a running total for each, for example, how much cumulative time was spent across every call to a particular database query during a request. Refactor Timer into a dataclass with a name and a shared timers dictionary that accumulates elapsed time by name. Create timer_v2.py:
import time
from dataclasses import dataclass, field
class TimerError(Exception):
"""A Timer was used incorrectly."""
@dataclass
class Timer:
timers: dict = field(default_factory=dict)
name: str | None = None
_start_time: float | None = field(default=None, init=False, repr=False)
elapsed: float | None = field(default=None, init=False)
def start(self):
if self._start_time is not None:
raise TimerError("Timer is already running. Use .stop() first.")
self._start_time = time.perf_counter()
def stop(self):
if self._start_time is None:
raise TimerError("Timer is not running. Use .start() first.")
self.elapsed = time.perf_counter() - self._start_time
self._start_time = None
if self.name:
self.timers.setdefault(self.name, 0)
self.timers[self.name] += self.elapsed
print(f"Elapsed ({self.name or 'unnamed'}): {self.elapsed:.4f} seconds")
return self.elapsed
if __name__ == "__main__":
totals: dict = {}
for i in range(3):
t = Timer(timers=totals, name="db_query")
t.start()
time.sleep(0.05 * (i + 1))
t.stop()
print()
print("Cumulative totals by name:", totals)
Run it. Real captured output:
Elapsed (db_query): 0.0504 seconds
Elapsed (db_query): 0.1005 seconds
Elapsed (db_query): 0.1505 seconds
Cumulative totals by name: {'db_query': 0.30135040008462965}
Three separate Timer instances, all sharing the same totals dictionary and the same name, correctly accumulate into a single running total. A few details in this dataclass are worth explaining. timers uses field(default_factory=dict) rather than a plain = {} default, because a mutable default argument in Python is created exactly once and shared across every instance that does not override it, a classic and well-documented footgun. _start_time and elapsed both use field(init=False), which excludes them from the auto-generated __init__ signature since they are internal bookkeeping the caller should never set directly.
Step 5: Turn the Timer Into a Context Manager
Calling .start() and .stop() by hand still means you can forget the closing call, especially if an exception is raised partway through the code you are timing. Python’s with statement exists precisely to guarantee that a cleanup step runs no matter how the block exits. Implementing the context manager protocol only requires two methods, __enter__ and __exit__. Add them to the Timer class:
def __enter__(self):
self.start()
return self
def __exit__(self, exc_type, exc_value, traceback):
self.stop()
return False
__enter__ runs when the with block begins and its return value is what gets bound to the as variable. __exit__ runs when the block ends, whether that is a normal fall-through or an exception being raised inside it, and Python passes it the exception’s type, value, and traceback (all three are None if nothing went wrong). Try it, including the case where the wrapped code raises. Save this as timer_v3.py, reusing the dataclass version from Step 4 plus the two methods above:
if __name__ == "__main__":
print("-- normal use --")
with Timer(name="block_a") as t:
time.sleep(0.1)
print(f"t.elapsed after the block: {t.elapsed:.4f}")
print()
print("-- an exception is raised inside the block --")
try:
with Timer(name="block_b") as t2:
time.sleep(0.05)
raise ValueError("something went wrong inside the block")
except ValueError as exc:
print(f"Exception propagated as expected: {exc}")
print(f"t2.elapsed was still recorded: {t2.elapsed:.4f}")
Real captured output:
-- normal use --
Elapsed (block_a): 0.1005 seconds
t.elapsed after the block: 0.1005
-- an exception is raised inside the block --
Elapsed (block_b): 0.0502 seconds
Exception propagated as expected: something went wrong inside the block
t2.elapsed was still recorded: 0.0502
Two things happened here that are worth noticing. First, __exit__ ran and recorded the elapsed time even though the code inside the with block raised an exception halfway through, exactly the guarantee a with statement is supposed to give you. Second, the ValueError still propagated out to the surrounding try/except, because __exit__ returned False. That return value is not a formality: it is a real signal to Python with real consequences, and it is the subject of the next step.
Step 6: The __exit__ Return-Value Trap (a Real Bug)
The Python data model is specific about what __exit__‘s return value means: if it evaluates to true, the exception is suppressed and the program continues right after the with block as if nothing happened. If it evaluates to false, the exception continues to propagate normally. It is easy to write this wrong by accident, especially if you reason “I want to know whether an exception happened, so let me return whether one happened” without stopping to think about what that return value actually does. Reproduce the bug directly. Create buggy_timer.py:
import time
from dataclasses import dataclass, field
@dataclass
class BuggyTimer:
"""__exit__ accidentally returns a truthy value."""
name: str | None = None
_start_time: float | None = field(default=None, init=False, repr=False)
elapsed: float | None = field(default=None, init=False)
def start(self):
self._start_time = time.perf_counter()
def stop(self):
self.elapsed = time.perf_counter() - self._start_time
self._start_time = None
return self.elapsed
def __enter__(self):
self.start()
return self
def __exit__(self, exc_type, exc_value, traceback):
self.stop()
# BUG: returning a truthy value here tells Python "I handled this
# exception, do not propagate it" -- even though nothing was handled.
return exc_type is not None
if __name__ == "__main__":
print("-- using BuggyTimer around code that raises --")
ran_the_line_after_the_with_block = False
with BuggyTimer(name="buggy") as t:
raise RuntimeError("a real bug in the wrapped code")
ran_the_line_after_the_with_block = True
print(f"Timer still measured: {t.elapsed:.6f} seconds")
print(f"Did execution continue past the with block? {ran_the_line_after_the_with_block}")
print("The RuntimeError never surfaced. The bug it represents was silently discarded.")
Run it. Real captured output:
-- using BuggyTimer around code that raises --
Timer still measured: 0.000001 seconds
Did execution continue past the with block? True
The RuntimeError never surfaced. The bug it represents was silently discarded.
The line right after the with block executed as if the RuntimeError never happened, because return exc_type is not None evaluates to True whenever an exception occurred, which tells Python to suppress it. This is a genuinely dangerous mistake, because the failure mode is silence: no traceback, no log line, nothing. Whatever real bug triggered that exception is now invisible. The fix is the one used everywhere else in this tutorial: __exit__ should return False (or nothing at all, since None is also falsy) unless you have a specific, deliberate reason to suppress a particular exception type.
Step 7: Make the Timer Usable as a Decorator Too
Sometimes you want to time an entire function every time it is called, rather than wrapping call sites in with blocks by hand. Python’s standard library has a purpose-built base class for exactly this: contextlib.ContextDecorator, which the documentation describes plainly as a base class that enables a context manager to also be used as a decorator.
Inheriting from it is the only change required; __enter__ and __exit__ stay exactly as they were. Create timer_decorator.py:
import time
from contextlib import ContextDecorator
from dataclasses import dataclass, field
class TimerError(Exception):
"""A Timer was used incorrectly."""
@dataclass
class Timer(ContextDecorator):
timers: dict = field(default_factory=dict)
name: str | None = None
_start_time: float | None = field(default=None, init=False, repr=False)
elapsed: float | None = field(default=None, init=False)
def start(self):
if self._start_time is not None:
raise TimerError("Timer is already running. Use .stop() first.")
self._start_time = time.perf_counter()
def stop(self):
if self._start_time is None:
raise TimerError("Timer is not running. Use .start() first.")
self.elapsed = time.perf_counter() - self._start_time
self._start_time = None
if self.name:
self.timers.setdefault(self.name, 0)
self.timers[self.name] += self.elapsed
print(f"Elapsed ({self.name or 'unnamed'}): {self.elapsed:.4f} seconds")
return self.elapsed
def __enter__(self):
self.start()
return self
def __exit__(self, exc_type, exc_value, traceback):
self.stop()
return False
TIMER_TOTALS: dict = {}
@Timer(timers=TIMER_TOTALS, name="fetch_page")
def fetch_page(delay: float) -> str:
time.sleep(delay)
return "<html>...</html>"
if __name__ == "__main__":
print("-- calling the decorated function three times, sequentially --")
for delay in (0.05, 0.05, 0.05):
fetch_page(delay)
print("Cumulative total:", TIMER_TOTALS)
Run it. Real captured output:
-- calling the decorated function three times, sequentially --
Elapsed (fetch_page): 0.0504 seconds
Elapsed (fetch_page): 0.0506 seconds
Elapsed (fetch_page): 0.0505 seconds
Cumulative total: {'fetch_page': 0.1515777998138219}
The same Timer class, unchanged apart from the new base class, now works as @Timer(...) above a function definition. This looks like it should be the end of the story. It is not.
A Real Reentrancy Bug: When Decorators and Recursion Collide
The contextlib documentation includes a note that is easy to skim past: As the decorated function must be able to be called multiple times, the underlying context manager must support use in multiple with statements. If this is not the case, then the original construct with the explicit with statement inside the function should be used.
The @Timer(...) syntax creates exactly one Timer instance at decoration time, and ContextDecorator reuses that same instance for every call to the decorated function. The sequential calls above worked because each call’s start()/stop() pair fully completed before the next one began. Recursive calls are a different story, because an inner call’s start() runs before the outer call’s stop() has had a chance to run. Add this to the bottom of timer_decorator.py:
print()
print("-- calling the decorated function recursively --")
call_count = {"n": 0}
@Timer(name="recursive_call")
def recurse(depth: int) -> None:
call_count["n"] += 1
if depth > 0:
recurse(depth - 1)
try:
recurse(2)
except TimerError as exc:
print(f"TimerError raised on the re-entrant call: {exc}")
print(f"Only {call_count['n']} of 3 intended calls completed before it failed.")
Run it again. Real captured output for this second block:
-- calling the decorated function recursively --
Elapsed (recursive_call): 0.0000 seconds
TimerError raised on the re-entrant call: Timer is already running. Use .stop() first.
Only 1 of 3 intended calls completed before it failed.
Walk through why. recurse(2) calls the shared Timer instance’s __enter__, which sets _start_time. Inside the function body, recurse(1) is called, which is the same decorated function, so it triggers __enter__ again on the exact same instance. But _start_time is still set from the outer call, so start() raises TimerError immediately, exactly matching the guard built back in Step 3. The exception unwinds back out through recurse(2)‘s own body, which triggers recurse(2)‘s own __exit__ as the stack unwinds, and that is the single “Elapsed” line printed above, from the outer call’s own stop(). Only one of the three intended calls ever completed its work. This is a real, reproducible bug, and it is exactly the scenario the contextlib documentation was warning about: a single shared instance does not support being entered a second time before the first entry exits.
Fixing It With a Decorator Factory
The fix is to stop sharing one Timer instance across every call, and instead build a fresh one every time the decorated function runs. Rather than using ContextDecorator directly on the class, write a small decorator function that wraps each call in its own with Timer(...) block. This version of Timer also drops the print() call from inside stop(), since the wrapper below now owns printing, which avoids printing the same line twice. Create timer_decorator_fixed.py:
import functools
import time
from dataclasses import dataclass, field
class TimerError(Exception):
"""A Timer was used incorrectly."""
@dataclass
class Timer:
timers: dict = field(default_factory=dict)
name: str | None = None
_start_time: float | None = field(default=None, init=False, repr=False)
elapsed: float | None = field(default=None, init=False)
def start(self):
if self._start_time is not None:
raise TimerError("Timer is already running. Use .stop() first.")
self._start_time = time.perf_counter()
def stop(self):
if self._start_time is None:
raise TimerError("Timer is not running. Use .start() first.")
self.elapsed = time.perf_counter() - self._start_time
self._start_time = None
if self.name:
self.timers.setdefault(self.name, 0)
self.timers[self.name] += self.elapsed
return self.elapsed
def __enter__(self):
self.start()
return self
def __exit__(self, exc_type, exc_value, traceback):
self.stop()
return False
def timed(name: str | None = None, timers: dict | None = None):
"""Decorator factory: builds a *new* Timer for every call instead of
sharing one instance, so recursive / re-entrant calls each get their
own independent start_time."""
shared_timers = timers if timers is not None else {}
def decorator(func):
@functools.wraps(func)
def wrapper(*args, **kwargs):
with Timer(timers=shared_timers, name=name or func.__name__) as t:
result = func(*args, **kwargs)
print(f"Elapsed ({t.name}): {t.elapsed:.4f} seconds")
return result
return wrapper
return decorator
if __name__ == "__main__":
totals: dict = {}
call_count = {"n": 0}
@timed(name="recursive_call", timers=totals)
def recurse(depth: int) -> None:
call_count["n"] += 1
if depth > 0:
recurse(depth - 1)
print("-- calling the FIXED decorator recursively --")
recurse(2)
print(f"All {call_count['n']} of 3 intended calls completed.")
print("Cumulative total:", totals)
Run it. Real captured output:
-- calling the FIXED decorator recursively --
Elapsed (recursive_call): 0.0000 seconds
Elapsed (recursive_call): 0.0000 seconds
Elapsed (recursive_call): 0.0000 seconds
All 3 of 3 intended calls completed.
Cumulative total: {'recursive_call': 4.3899985030293465e-05}
All three calls now complete, because wrapper() creates a brand-new Timer(...) instance inside a fresh with block on every single invocation. Each nested call gets its own independent _start_time, so there is no shared mutable state for recursion to collide with. Notice this also uses functools.wraps(func), which copies the wrapped function’s __name__, docstring, and other metadata onto wrapper, without it, recurse.__name__ would report "wrapper" instead of "recurse", which makes debugging and introspection confusing.
Step 8: Put It to Work: A Real Performance Comparison
With a working Timer, use it for the job it was built for: comparing two implementations of the same task. A commonly repeated claim is that building up a string with += in a loop is dramatically slower than str.join(). Rather than repeat that claim, measure it. Create compare_string_building.py:
def build_with_concat(n: int) -> str:
result = ""
for i in range(n):
result += str(i)
return result
def build_with_join(n: int) -> str:
return "".join(str(i) for i in range(n))
if __name__ == "__main__":
n = 200_000
results: dict = {}
with Timer(timers=results, name="string concatenation (+=)"):
out_a = build_with_concat(n)
with Timer(timers=results, name="str.join()"):
out_b = build_with_join(n)
assert out_a == out_b
print()
for name, elapsed in results.items():
print(f"{name:>32}: {elapsed:.4f}s")
slower = max(results, key=results.get)
faster = min(results, key=results.get)
ratio = results[slower] / results[faster]
print(f"\n'{faster}' was {ratio:.1f}x faster than '{slower}' on this run.")
Add the two functions above to timer_v3.py from Step 5 (which already has the context manager Timer class defined), and replace that file’s existing if __name__ == "__main__": block with the one shown here, then run the file. Real captured output:
string concatenation (+=): 0.0204s
str.join(): 0.0142s
'str.join()' was 1.4x faster than 'string concatenation (+=)' on this run.
str.join() was indeed faster on this run, but honestly only by 1.4x, not the dramatic multiple-times-faster gap that older folklore about Python string concatenation sometimes claims. Modern CPython has optimized the common case of repeatedly reassigning result += ... to the same local variable. The lesson here is less about strings specifically and more about the discipline the Timer gives you: instead of trusting a rule of thumb, you now have a two-line way to check whether it actually holds for your code, on your machine, with your data.
Step 9: Verify Everything With pytest
Manually running scripts and eyeballing printed numbers is fine for exploration, but a reusable utility deserves an automated test suite, one that does not depend on fragile timing assertions like “this should take roughly 0.1 seconds.” Consolidate the final version of the Timer (the plain, non-decorator-broken version from Step 4 and 5, plus the timed decorator factory from Step 7) into timer.py:
import functools
import time
from dataclasses import dataclass, field
class TimerError(Exception):
"""A Timer was used incorrectly."""
@dataclass
class Timer:
timers: dict = field(default_factory=dict)
name: str | None = None
_start_time: float | None = field(default=None, init=False, repr=False)
elapsed: float | None = field(default=None, init=False)
def start(self) -> None:
if self._start_time is not None:
raise TimerError("Timer is already running. Use .stop() first.")
self._start_time = time.perf_counter()
def stop(self) -> float:
if self._start_time is None:
raise TimerError("Timer is not running. Use .start() first.")
self.elapsed = time.perf_counter() - self._start_time
self._start_time = None
if self.name:
self.timers.setdefault(self.name, 0)
self.timers[self.name] += self.elapsed
return self.elapsed
def __enter__(self) -> "Timer":
self.start()
return self
def __exit__(self, exc_type, exc_value, traceback) -> bool:
self.stop()
return False
def timed(name: str | None = None, timers: dict | None = None):
shared_timers = timers if timers is not None else {}
def decorator(func):
@functools.wraps(func)
def wrapper(*args, **kwargs):
with Timer(timers=shared_timers, name=name or func.__name__) as t:
result = func(*args, **kwargs)
return result
return wrapper
return decorator
Then create test_timer.py in the same folder:
import time
import pytest
from timer import Timer, TimerError, timed
def test_start_then_stop_returns_elapsed():
t = Timer()
t.start()
time.sleep(0.05)
elapsed = t.stop()
assert elapsed > 0.04
def test_stop_without_start_raises():
t = Timer()
with pytest.raises(TimerError):
t.stop()
def test_start_twice_raises():
t = Timer()
t.start()
with pytest.raises(TimerError):
t.start()
t.stop()
def test_context_manager_records_elapsed():
with Timer() as t:
time.sleep(0.05)
assert t.elapsed > 0.04
def test_context_manager_reraises_exceptions():
with pytest.raises(ValueError):
with Timer() as t:
raise ValueError("boom")
assert t.elapsed is not None
def test_named_timer_accumulates_across_calls():
totals: dict = {}
for _ in range(3):
with Timer(timers=totals, name="op"):
time.sleep(0.01)
assert totals["op"] >= 0.03
def test_timed_decorator_returns_function_result():
@timed(name="add")
def add(a, b):
return a + b
assert add(2, 3) == 5
def test_timed_decorator_records_elapsed_time():
totals: dict = {}
@timed(name="sleepy", timers=totals)
def sleepy():
time.sleep(0.02)
sleepy()
assert totals["sleepy"] >= 0.015
def test_timed_decorator_supports_recursion():
calls = {"n": 0}
@timed(name="recurse")
def recurse(depth):
calls["n"] += 1
if depth > 0:
recurse(depth - 1)
recurse(3)
assert calls["n"] == 4
Run the suite:
python -m pytest test_timer.py -v
Real captured output:
collected 9 items
test_timer.py::test_start_then_stop_returns_elapsed PASSED [ 11%]
test_timer.py::test_stop_without_start_raises PASSED [ 22%]
test_timer.py::test_start_twice_raises PASSED [ 33%]
test_timer.py::test_context_manager_records_elapsed PASSED [ 44%]
test_timer.py::test_context_manager_reraises_exceptions PASSED [ 55%]
test_timer.py::test_named_timer_accumulates_across_calls PASSED [ 66%]
test_timer.py::test_timed_decorator_returns_function_result PASSED [ 77%]
test_timer.py::test_timed_decorator_records_elapsed_time PASSED [ 88%]
test_timer.py::test_timed_decorator_supports_recursion PASSED [100%]
============================== 9 passed in 0.21s ==============================
Notice the last test, test_timed_decorator_supports_recursion, is exactly the scenario that broke in Step 7 and was fixed in the same step. Keeping that test in the suite means if anyone (including a future version of yourself) ever changes timed() back to something that shares a single Timer instance across calls, this test will fail immediately instead of silently reintroducing the bug.
Common Mistakes and Gotchas
- Using
time.time()to benchmark code. It is meant for reporting the current wall-clock time (for example, in a log timestamp), not for measuring durations. Its documented ability to move backward makes it unsuitable for anything you plan to subtract two readings from. Usetime.perf_counter()instead. - Confusing
perf_counter()andprocess_time(). If your code is waiting on I/O, a lock, or asleep(), and you time it withprocess_time(), you will get a number that looks suspiciously small. That is not a bug: it isprocess_time()correctly excluding time your process spent not doing CPU work. Pick the one that answers the actual question you are asking. - Returning a truthy value from
__exit__without meaning to. As shown in Step 6, this silently suppresses any exception raised inside thewithblock. Always returnFalse(or nothing) unless you have a deliberate, narrow reason to swallow a specific exception type. - Sharing one
ContextDecoratorinstance across recursive or concurrent calls. As shown in Step 7, decorating a function with a single shared context-manager instance breaks the moment that function calls itself, or is called concurrently from multiple threads, because every call reuses the same_start_time. Build a fresh instance per call instead, as thetimed()factory in Step 7 and 9 does. - Using a mutable default argument like
timers: dict = {}. Python evaluates default argument values exactly once, at function or class definition time, not on every call. A bare{}default would be silently shared and mutated across everyTimerinstance that does not explicitly pass its own dictionary.field(default_factory=dict), used throughout this tutorial, avoids that trap by building a new dictionary for each instance.
Verify It All Works End to End
To confirm the complete picture holds together, run through this checklist:
- Run
compare_clocks.pyand confirmprocess_time()stays roughly flat across the sleep-included run whiletime.time()andperf_counter()both jump by about the sleep duration. - Run
python -m pytest test_timer.py -vand confirm all 9 tests pass, includingtest_timed_decorator_supports_recursion. - In a Python shell, import your final
timer.pyand wrap any block of code you actually care about timing inwith Timer(name="my_block") as t: ..., then printt.elapsedto confirm it reports a sensible number. - Apply
@timed(name="my_function")to a real function in your own code, call it a few times, and confirm the elapsed times printed look consistent with what you would expect for that function’s work.
If all four steps check out, you have a Timer that is safe to drop into real code: it fails loudly when misused, it measures the right kind of time by default, and it works correctly as a context manager, a decorator, and under recursion.
Next Steps
- If you want to go deeper on decorators generally, including how
functools.wrapsworks under the hood and how to stack multiple decorators correctly, see How to Write Python Decorators From Scratch on this site. - If you are timing network calls or database queries specifically and want to catch a slow dependency before it takes down the rest of your service, see How to Build a Bulkhead in Python to Stop a Slow Dependency From Starving the Rest.
- For turning ad hoc
print()-based timing like the kind built in this tutorial into structured, queryable metrics you can graph over time, see How to Turn Slow SQL Queries Into Actionable Reliability Metrics With OpenTelemetry. - Try extending the
Timeryourself: add athreading.Lockso the same named timer can be safely updated from multiple threads at once, or add atexttemplate attribute so callers can customize the printed message without subclassing.








No Comment! Be the first one.