Как написать декоратор для логирования результата функции и времени выполнения с настроенным логером

Что проверяют

Умеете ли вы написать декоратор с параметрами и не сломать обёрнутую функцию, а заодно знаете ли, как устроен logging. Следом обычно просят доработать: логировать исключения и поддержать async-функции.

Как отвечать

Раз логер «настроенный», его передают параметром, значит нужна фабрика декораторов с тремя уровнями вложенности (импорты functools, logging, time):

def log_call(logger=None, level=logging.INFO):
    def decorator(func):
        log = logger or logging.getLogger(func.__module__)
        @functools.wraps(func)
        def wrapper(*args, **kwargs):
            start = time.perf_counter()
            try:
                result = func(*args, **kwargs)
            except Exception:
                log.exception("%s упала", func.__qualname__)
                raise
            log.log(level, "%s вернула %r за %.3f с", func.__qualname__,
                    result, time.perf_counter() - start)
            return result
        return wrapper
    return decorator

Что стоит проговорить:

• functools.wraps: без него у функции пропадут __name__, __doc__ и __wrapped__, сломаются интроспекция и документация;
• time.perf_counter(): монотонные часы высокого разрешения, а time.time() может прыгнуть при синхронизации системного времени;
• ленивое форматирование: аргументы передаются в log.log() отдельно, и строка соберётся, только если уровень включён;
• исключения: log.exception() пишет трейсбек, а raise без аргументов пробрасывает исходную ошибку;
• конфигурация: basicConfig и хендлеры настраивают в точке входа приложения, а не в модуле с декоратором.

Для корутин нужна отдельная обёртка async def с await func(...), выбор делается по inspect.iscoroutinefunction(func).

Где спотыкаются

Забывают wraps, и в логах все функции называются wrapper.

Логируют result целиком. Большой список раздувает лог, а токены и персональные данные туда попадать не должны: используйте reprlib.repr или пишите только тип и размер.

Вешают синхронный декоратор на async def. Замеряется время создания корутины, а не её работы, и в лог уходит объект корутины вместо результата.