Python Decorators Explained: Logging, Timing and Reusable Function Wrappers

Python course module guide: Functions and reusable design

Python decorators wrap a function or class with reusable behavior. They are common in web routes, authorization, caching, logging and testing, but they should make intent clearer rather than hide important control flow.

What a decorator changes

A decorator receives a callable and returns a callable. The @name

def announce(function):
    def wrapper():
        print("Starting")
        result = function()
        print("Finished")
        return result
    return wrapper

@announce
def build_report():
    return "report ready"

The decorated name now refers to wrapper. Review Python functions, parameters and scope before moving to configurable decorators.

Accept any function signature

from functools import wraps

def audit_call(function):
    @wraps(function)
    def wrapper(*args, **kwargs):
        print(f"Calling {function.__name__}")
        return function(*args, **kwargs)
    return wrapper

*args and **kwargs forward positional and keyword arguments. functools.wraps preserves the original name, documentation and other metadata used by help tools, test reports and frameworks.

Build a timing decorator

from functools import wraps
from time import perf_counter

def timed(function):
    @wraps(function)
    def wrapper(*args, **kwargs):
        started = perf_counter()
        try:
            return function(*args, **kwargs)
        finally:
            elapsed = perf_counter() - started
            print(f"{function.__name__}: {elapsed:.4f}s")
    return wrapper

The finally block records time even when the wrapped function raises an exception. In production, use the logging module instead of uncontrolled prints. The Python logging project demonstrates levels, structured context and rotating files.

Decorator factories with configuration

from functools import wraps

def require_role(allowed_role):
    def decorator(function):
        @wraps(function)
        def wrapper(user, *args, **kwargs):
            if user.get("role") != allowed_role:
                raise PermissionError("Access denied")
            return function(user, *args, **kwargs)
        return wrapper
    return decorator

@require_role("admin")
def export_users(user):
    return "export started"

The outer function captures configuration, the middle function accepts the target and the wrapper runs on each call. Real authorization needs a trusted identity, explicit policies and safe error responses; the example teaches structure, not a complete security system.

Stacking decorators

@audit_call
@timed
def calculate_summary(records):
    return sum(records)

The decorator closest to the function is applied first, so this is equivalent to calculate_summary = audit_call(timed(calculate_summary)). Order matters when one wrapper changes arguments, catches errors, caches results or checks permissions.

Decorators and generators

A normal timing wrapper measures creation of a generator object, not the full iteration. If you decorate a generator function, decide whether you need to measure each yielded item or the complete consumption period. Learn the execution model in the Python iterators and generators guide before wrapping lazy pipelines.

How to test decorated behavior

Test both the added behavior and the original return value. Avoid tests that depend only on printed text. Inject a logger, clock or policy function when practical so tests can substitute predictable dependencies. The pytest unit testing guide shows fixtures, parametrization and monkeypatching.

Common decorator mistakes

• Forgetting to return the wrapped function’s result.
• Omitting functools.wraps and losing useful metadata.
• Accepting no arguments when the target has parameters.
• Sharing mutable state accidentally across every decorated call.
• Catching broad exceptions and hiding failures.
• Stacking many wrappers until execution order becomes difficult to trace.

When a decorator is appropriate

Use a decorator when the same surrounding behavior genuinely belongs to several callables: tracing, timing, authorization checks or retry policy. Use a normal function call when the action is part of the business workflow and should be visible in the function body. Explicit code is often easier to debug than a clever abstraction.

Practice exercise

Create a configurable decorator that records a function name, duration and success status. Preserve metadata, forward all arguments, return the original value and re-raise failures after logging them. Test a successful function and a function that raises an error.

Python decorator FAQs

Is @decorator special syntax?

It is convenient syntax for applying a callable transformation when a function or class is defined. The decorated name receives the returned object.

Can a decorator accept arguments?

Yes. A decorator factory accepts configuration and returns the actual decorator. This adds one nesting level, so clear names and tests become important.

Why does my function name become wrapper?

The wrapper replaced the original callable without copying its metadata. Apply functools.wraps to the wrapper to preserve the original identity for documentation and tools.

Can decorators be removed at runtime?

Decoration normally replaces the name during definition, so it is not designed as a temporary toggle. For optional behavior, inject a policy or keep the undecorated function accessible deliberately. The __wrapped__ attribute added by functools.wraps can help tooling and focused tests, but application code should not depend on bypassing important authorization or validation wrappers.

Trace the call order with an observable experiment

Reading stacked decorators from top to bottom can confuse two separate moments: building the decorated function and calling it later. Decoration constructs the nested callables when the definition executes. A later call enters the outer wrapper first, reaches the inner wrapper and then runs the original body. Work after the call returns proceeds back out through those layers.

The following experiment uses a shared event list deliberately, so the order can be inspected without relying on elapsed time. The function also has a keyword-only argument. This checks that the wrapper forwards a real calling convention instead of succeeding only for a function with no parameters.

from functools import wraps

events = []

def trace(label):
    def decorate(function):
        @wraps(function)
        def wrapper(*args, **kwargs):
            events.append(f"{label}: enter")
            try:
                return function(*args, **kwargs)
            finally:
                events.append(f"{label}: leave")
        return wrapper
    return decorate

@trace("outer")
@trace("inner")
def combine(left, *, right):
    """Add two values."""
    events.append("body")
    return left + right

print(combine(4, right=6))
print(events)
print(combine.__name__, combine.__doc__)

Observed output using Python 3.12.14:

10
['outer: enter', 'inner: enter', 'body', 'inner: leave', 'outer: leave']
combine Add two values.

The result remains ten, and the event sequence reveals both entry and exit order. Reversing the two decorator lines would reverse which named wrapper surrounds the other. The preserved function name and documentation demonstrate the purpose of metadata copying. They do not mean the wrapper has become the same function object as the original.

Decide where decorator state belongs

A list created inside the wrapper is new for each call. A list created inside the decorator but outside the wrapper is retained by that decorated function across calls. A module-level list, like the event list in this demonstration, can be shared by several wrappers. These are different lifetimes, and accidental sharing can make one customer’s request appear to influence another.

Imagine adding a call counter to a report function. Decide whether the counter means attempts, successful returns or completed executions including failures. Incrementing before the call counts attempts; incrementing after a successful return counts successes. A finalisation block can record completion on both paths. Name the metric according to what the implementation actually measures.

Do not assume a simple retained counter is automatically suitable for concurrent workers or multiple processes. A teaching closure explains lifetime, but application metrics may need a dedicated collector. Similarly, a cached result has a lifetime and an invalidation policy: reusing yesterday’s answer may be incorrect even when the decorator code works perfectly.

Preserve the function contract, not only its name

The useful contract includes arguments, returned values, raised exceptions and relevant side effects. A wrapper that prints a result but returns nothing has changed the contract. A wrapper that catches every exception and returns an empty list can make a failed report look like a valid report with no rows. Document any intentional change instead of hiding it inside a reusable annotation.

The trace example was also checked with a function that raises a ValueError. Its exit event was recorded and the original error still reached the caller. That is the important distinction between recording a failure and suppressing it. If logging itself can fail, consider how that secondary failure should be handled without concealing the original business error.

Does metadata copying validate arguments?

No. It helps documentation and inspection. Argument forwarding and validation remain responsibilities of the wrapper and target function.

Can the same wrapper time an async operation correctly?

Not necessarily. Calling an async function produces a coroutine; a synchronous wrapper can time its creation rather than its awaited work. Design and test an async-aware wrapper when the goal is to measure execution across the await.

What should the practice review include?

Check a keyword argument, a returned value, an exception and the order of two wrappers. Then explain the lifetime of every mutable object used by the decorator. Those checks reveal more than a screenshot showing that a decorator ran once.

Further official documentation: Python functools metadata helpers; Python function definition and decorator semantics.

Official reference: Python glossary definition of decorator.