Consider this module:
#mymodule.py
import logging
def print_start_end(name):
"""
Decorator that creates a logger and logs the start
and the end of the function call
"""
def decorator(f):
logger = logging.getLogger(name)
def wrapper(*args, **kwargs):
logger.info("start")
res = f(*args, **kwargs)
logger.info("end")
return res
return wrapper
return decorator
@print_start_end(__name__)
def f(x):
return x
def g(y=f(3)):
return y
And an example script:
import logging
from mymodule import f
logger = logging.getLogger("")
logger.setLevel(logging.INFO)
h = logging.StreamHandler()
h.setLevel(logging.INFO)
logger.addHandler(h)
print f(3)
Output:
start
end
3
The decorator is working. But now I write a script to use g instead of f:
import logging
from mymodule import g
logger = logging.getLogger("")
logger.setLevel(logging.INFO)
h = logging.StreamHandler()
h.setLevel(logging.INFO)
logger.addHandler(h)
print g()
Output:
3
When executing the statement print g(), the call to f was successful because it printed the expected return value 3. But why doesn't it also print "start" and "end"?
Note that the
f(3)indef g(y=f(3)):is executed only once, when the function is defined, not every time when it is called.Thus, the problem seems to be that by the time
f(3)is executed inmymodule, the logger is not yet initialized. Initialize first, then import, then it works: