The first time I wrote a timing decorator, it was because I was manually copy-pasting start = time.time() and print(time.time() - start) around a function every time I wanted to check its speed, then deleting it before committing, then adding it back the next time I needed it. It took embarrassingly long for me to realize this was exactly the kind of repetitive, cross-cutting behavior decorators exist to solve. This guide walks through building a timing decorator properly — from the basic version to a production-grade one with logging, statistics, and support for both sync and async functions.
What a Decorator Actually Is
A decorator is a function that takes another function as input and returns a new function that wraps it, typically adding behavior before and/or after the original call. @decorator syntax is just sugar:
@my_decorator
def some_function():
pass
# is exactly equivalent to:
def some_function():
pass
some_function = my_decorator(some_function)
The Basic Timing Decorator
import time
import functools
def timer(func):
@functools.wraps(func)
def wrapper(*args, **kwargs):
start = time.perf_counter()
result = func(*args, **kwargs)
end = time.perf_counter()
print(f"{func.__name__} took {end - start:.6f} seconds")
return result
return wrapper
@timer
def slow_square(n):
total = 0
for i in range(n):
total += i ** 2
return total
slow_square(1_000_000)
# slow_square took 0.123456 seconds
A few details matter here more than they look:
time.perf_counter()instead oftime.time().perf_counteruses the highest-resolution clock available and is specifically designed for measuring short durations — it’s monotonic (never goes backward, even if the system clock is adjusted) and unaffected by things like daylight saving changes.time.time()reflects wall-clock time and is the wrong tool for benchmarking.*args, **kwargsinwrapper. This makes the decorator work on any function signature, not just zero-argument ones.functools.wraps(func). Without this,wrapperreplaces the original function’s__name__,__doc__, and other metadata with its own generic values — meaningslow_square.__name__would print"wrapper"instead of"slow_square", which breaks introspection, documentation tools, and debugging.
Returning the Timing Instead of Just Printing
Printing is fine for quick scripts, but for real use you usually want the timing data available programmatically:
import time
import functools
def timer(func):
@functools.wraps(func)
def wrapper(*args, **kwargs):
start = time.perf_counter()
result = func(*args, **kwargs)
elapsed = time.perf_counter() - start
wrapper.last_elapsed = elapsed
return result
wrapper.last_elapsed = None
return wrapper
@timer
def compute():
time.sleep(0.05)
return 42
value = compute()
print(value, compute.last_elapsed)
# 42 0.0512...
Attaching last_elapsed directly to the wrapper function object is a lightweight way to expose timing data without changing the function’s actual return value.
A Decorator With Configurable Behavior (Decorator Factory)
Often you want to control how timing is reported — logged, printed, sent to a metrics system. This calls for a decorator that itself takes arguments, which means an extra layer of nesting:
import time
import functools
import logging
def timer(logger=None, precision=4):
def decorator(func):
@functools.wraps(func)
def wrapper(*args, **kwargs):
start = time.perf_counter()
result = func(*args, **kwargs)
elapsed = time.perf_counter() - start
message = f"{func.__name__} took {elapsed:.{precision}f}s"
if logger:
logger.info(message)
else:
print(message)
return result
return wrapper
return decorator
log = logging.getLogger("perf")
logging.basicConfig(level=logging.INFO)
@timer(logger=log, precision=6)
def process_data(items):
return sum(x * x for x in items)
process_data(range(100_000))
# INFO:perf:process_data took 0.012345s
timer(logger=log, precision=6) runs first and returns decorator, which is then applied to process_data. This is why decorator factories need three nested functions: the outer one accepts configuration, the middle one accepts the function being decorated, and the inner one is the actual replacement.
Handling Exceptions Correctly
A common bug in hand-rolled timing decorators: if the wrapped function raises, timing code placed after the call never runs, and worse, the exception’s traceback can get harder to read if not handled carefully:
import time
import functools
def timer(func):
@functools.wraps(func)
def wrapper(*args, **kwargs):
start = time.perf_counter()
try:
return func(*args, **kwargs)
finally:
elapsed = time.perf_counter() - start
print(f"{func.__name__} took {elapsed:.6f}s (even on exception)")
return wrapper
@timer
def risky():
raise ValueError("boom")
try:
risky()
except ValueError:
pass
# risky took 0.000012s (even on exception)
Using try/finally guarantees the timing report happens regardless of whether the function succeeds or raises, which is exactly the behavior you want for profiling code paths that sometimes fail.
Supporting Both Sync and Async Functions
If you’re timing code in an asyncio codebase, a plain decorator breaks — await-ing a coroutine function wrapped by a synchronous wrapper doesn’t work correctly, because func(*args, **kwargs) on a coroutine function returns a coroutine object immediately rather than the actual result. You need to detect and branch:
import time
import functools
import asyncio
def timer(func):
if asyncio.iscoroutinefunction(func):
@functools.wraps(func)
async def async_wrapper(*args, **kwargs):
start = time.perf_counter()
result = await func(*args, **kwargs)
print(f"{func.__name__} took {time.perf_counter() - start:.6f}s")
return result
return async_wrapper
else:
@functools.wraps(func)
def sync_wrapper(*args, **kwargs):
start = time.perf_counter()
result = func(*args, **kwargs)
print(f"{func.__name__} took {time.perf_counter() - start:.6f}s")
return result
return sync_wrapper
@timer
async def fetch_data():
await asyncio.sleep(0.1)
return "data"
asyncio.run(fetch_data())
# fetch_data took 0.100xxx s
Class-Based Timing Decorator (for Statistics)
If you want to accumulate stats across many calls (min, max, average, call count), a class-based decorator using __call__ is a natural fit:
import time
import functools
class Timer:
def __init__(self, func):
functools.update_wrapper(self, func)
self.func = func
self.calls = 0
self.total_time = 0.0
def __call__(self, *args, **kwargs):
start = time.perf_counter()
result = self.func(*args, **kwargs)
elapsed = time.perf_counter() - start
self.calls += 1
self.total_time += elapsed
return result
@property
def average_time(self):
return self.total_time / self.calls if self.calls else 0.0
@Timer
def add(a, b):
return a + b
for _ in range(1000):
add(1, 2)
print(f"Calls: {add.calls}, avg: {add.average_time:.8f}s")
functools.update_wrapper is the class-based analog of functools.wraps, copying over __name__, __doc__, and similar metadata onto the instance.
Using timeit for Rigorous Benchmarking
A hand-rolled decorator is great for spot-checking timing in real usage, but for rigorous micro-benchmarking (comparing two implementations precisely), the standard library’s timeit module is the more appropriate tool, since it runs the target code many times and controls for common measurement pitfalls (garbage collection interference, one-off system noise):
import timeit
def approach_a():
return sum(i * i for i in range(1000))
def approach_b():
return sum(map(lambda i: i * i, range(1000)))
print(timeit.timeit(approach_a, number=10000))
print(timeit.timeit(approach_b, number=10000))
timeit disables garbage collection by default during measurement and runs the callable many times, giving a far more stable estimate than a single perf_counter() call around one execution — which is exactly why a timing decorator (best for observing real, in-context call performance) and timeit (best for controlled micro-benchmarks) solve related but different problems.
Common Mistakes
- Using
time.time()instead oftime.perf_counter()for benchmarking —time.time()is lower resolution on some platforms and can jump if the system clock changes. - Forgetting
functools.wraps, which silently breaks introspection,help(), and any tooling that relies on__name__/__doc__. - Not handling exceptions, causing timing output to simply never appear for failing calls, which is often exactly when you most want the timing data.
- Timing a single call and treating it as representative, when JIT-like caching effects, disk caching, or system load can make a single measurement noisy — use
timeitor run multiple iterations for anything you’re actually trying to optimize based on.
FAQs
Q: Does adding a timing decorator meaningfully slow down my function? The overhead of perf_counter() calls and a wrapper function call is extremely small (nanoseconds to low microseconds) — negligible for almost everything except extremely hot, tight loops calling the decorated function millions of times per second, where the wrapper’s own call overhead could start to matter.
Q: Can I stack a timing decorator with other decorators? Yes — decorators compose top-to-bottom in the order they’re written, so @timer above @cache times the cached-or-not call as a whole; order matters for what exactly gets measured.
Q: Should I use a decorator or a context manager for timing? Decorators are best for timing an entire function every time it’s called; a context manager (with Timer():) is better for timing an arbitrary block of code that isn’t naturally its own function.
Summary
A timing decorator is one of the clearest, most practical demonstrations of what decorators are for: adding consistent, reusable cross-cutting behavior (measurement, in this case) without cluttering the function’s own logic. Building one well means using time.perf_counter() for accuracy, functools.wraps to preserve metadata, try/finally for exception safety, and branching for async support when needed. For rigorous comparisons rather than observational timing, timeit is the more appropriate tool.
