Logging decorator fails when applied after import

Viewed 71

I'm running into a strange problem that I cannot figure out. I recently used the this blog post to learn how to create a logging-decorator that takes logger object as parameter. When testing my decorator, it works fine when testing within ipython environment. However, in my actual project, I saved the decorator in a file decorator.py. When I import the decorator (from decorator import log_func) and apply it to a function within a module (@log_func(some-logger-object)), I get error. I cant figure out why...especially considering that function hasn't actually been called yet. Any of you folks have any ideas what's going on here?

See details below

decorator.py

from time import perf_counter
from functools import wraps
import logging

def log_func(_func=None, *, logger: logging.Logger=logging.getLogger(f"decorators:log_func")):
    """Decorator to log function entry, exit, and execution time"""
    def decorator_log_func(func):
        @wraps(func)
        def wrapper_log_func(*args, **kwargs):
            args_repr = [repr(a) for a in args]
            kwargs_repr = [f"{k}={v!r}" for k, v in kwargs.items()]
            signature = ", ".join(args_repr + kwargs_repr)
            logger.debug(f"Calling function {func.__name__} with args {signature}")
            start = perf_counter()
            result = func(*args, **kwargs)
            time_elapsed = perf_counter() - start
            logger.info(f"Exited function: {func.__name__}, Execution Time: {time_elapsed}")
            return result
        return wrapper_log_func
    if _func is None:
        return decorator_log_func
    else:
        return decorator_log_func(_func)

ipython output

 import logging
 log = logging.getLogger("mylogger")
 @log_func(logger=log)
 def squared(*args):
    for x in args:
        print(f"x^2 = {x**2}")

 squared(5, 6, 7)
 DEBUG:myLogger:Calling function squared with args 5, 6, 7
 x^2 = 25
 x^2 = 36
 x^2 = 49
 INFO:myLogger:Exited function: squared, Execution Time: 6.160400002386268e-05

Here is where failure occurs during actual code run attempt

python web.py
Traceback (most recent call last):
File "web.py", line 18, in <module>
  backend = load_backend(settings.backend)
File "/lib/backends/__init__.py", line 19, in load_backend
  globals()[name] = _backend_loaders[name].find_module(name).load_module(name)
File "<frozen importlib._bootstrap_external>", line 529, in _check_name_wrapper
File "<frozen importlib._bootstrap_external>", line 1034, in load_module
File "<frozen importlib._bootstrap_external>", line 859, in load_module
File "<frozen importlib._bootstrap>", line 274, in _load_module_shim
File "<frozen importlib._bootstrap>", line 711, in _load
File "<frozen importlib._bootstrap>", line 680, in _load_unlocked
File "<frozen importlib._bootstrap_external>", line 855, in exec_module
File "<frozen importlib._bootstrap>", line 228, in _call_with_frames_removed
File "/lib/backends/k8s_backend.py", line 51, in <module>
  class K8sBackend(BaseBackend):
File "/lib/backends/k8s_backend.py", line 86, in K8sBackend
  def create_task(cls, task_id: str, base: TaskBase) -> None:
File "/lib/decorators.py", line 13, in wrapper_log_func
  logger.debug(f"Calling function {func.__name__} with args {signature}")
AttributeError: 'Logger' object has no attribute '__name__'

In k8s_backend.py, there is a logger object defined and I imported the decorator and applied to function with the logger object passed in

k8s_backend.py snippet

from lib.decorators import log_func
import logging
log = logging.getLogger(__name__)
    @classmethod

@log_func(log)
def create_task(cls, task_id: str, base: TaskBase) -> None:
...
1 Answers

The problem is being caused by passing in an object where a function was expected. You're passing in the logger as the function, rather than as the logger. I think you want:

@log_func(logger=log)
Related