I tried to use time counter and logger in a while, I found it got some wrose.
For convaniently, I maked them to be class and used it by decorator in my case like example below.
The problem is when I use them in same function, it only show one function’s log, you can see I also try to make logger info in Timer, I’d like to record the fouction’s log time log. how can It fix it and please tell me what problem in the code, thanks.
Example code:
import time
import functools
import logging
# simple cofiguration
logging.basicConfig(level=logging.INFO, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
logger = logging.getLogger(__name__)
class Timer:
def __init__(self, func):
self.func = func
functools.update_wrapper(self, func)
def __call__(self, *args, **kwargs):
start_time = time.time()
result = self.func(*args, **kwargs)
end_time = time.time()
elapsed_time = end_time - start_time
logger.info(f"Function {self.func.__name__} took {elapsed_time:.4f} seconds to complete")
return result
class Logger:
def __init__(self, func):
self.func = func
functools.update_wrapper(self, func)
# print(f"Logger initialized for {func.__name__}") # test info
def __call__(self, *args, **kwargs):
# print("Logger __call__ invoked") # test info
logger.info(f"Calling function {self.func.__name__} with args: {args} and kwargs: {kwargs}")
result = self.func(*args, **kwargs)
logger.info(f"Function {self.func.__name__} returned {result}")
return result
@Timer
@Logger
def example_function(x, y):
time.sleep(1)
return x + y
if __name__ == "__main__":
example_function(3, 4)
What the final result I expected is:
024-05-29 18:32:54,591 - __main__ - INFO - Calling function example_function with args: (3, 4) and kwargs: {}
2024-05-29 18:32:55,596 - __main__ - INFO - Function example_function returned 7
2024-05-30 19:36:01,538 - __main__ - INFO - Function example_function took 1.0050 seconds to complete
I tried to change decorator’s order, it was only show one. When @Timer is first, it only show its log, but no @Logger. I supposed its probelm related to call fun in Logger class, so I put a test info on it, and indeed. When @Timer is first decorator, @Logger would not call in code.