Python : Using Decorators to write Logs on a file

Question

I'm trying to use python decorators to write logs on a file, it works when I'm using it on one method, but once I'm starting to try using it on multiple methods, things start to get messy.

For instance, if I have 2 logs for 2 methods A() and B(), B() being called inside of A(), one for when I'm calling it and one for when I'm ending it things get like that: A1 B1 B2 A2 B1 B2 B1 B2

A1 to A2 is fine but after that B() is called x times (the number of times it is called apparently changes) and I can't figure out why.

Here is my Decorator:

class LogDecorator(object):
    state: str

    def __init__(self, state):
        self.state = state
        self.log_file = 'log.txt'

    def __call__(self, *function):
        if len(function) >= 1:
            def wrapper(params=None):
                if self.state == 'main':
                    self.reset_log_file()
                function_name = function[0].__name__
                self.append_log_to_file('Calling function ' + function_name + '...')
                result = function[0]() if params is None else function[0](params)
                self.append_log_to_file('Function ' + function_name + ' ended. Returned ' + str(result))
                return result
            return wrapper

    def __get__(self, obj, objtype):
        return functools.partial(self.__call__, obj)

    def append_log_to_file(self, message: str) -> None:
        log_file = open(self.log_file, 'a')
        log_file.write(message)
        log_file.close()

    def reset_log_file(self):
        log_file = open(self.log_file, 'w+')
        log_file.write('')
        log_file.close()

I use the 'main' state because I'm on an endpoint of an API and I want to reset the file for each API call.

Here is my first class with the main state

class AppService:
    @staticmethod
    @LogDecorator(state='main')
    def endpoint() -> Response:
        response: Response = Response()

        response.append_message('Getting all tests')
        tests: list = TestDAO.get_all()
        return response

Here is my second class

class TestDAO(BaseDAO):
    @staticmethod
    @LogDecorator(state='sub')
    def get_all() -> list:
        return db.session.query(Test).all()

The expected output in this sample would be

Calling function endpoint...
Calling function get_all...
Function get_all ended. Returned [Objects]
Function endpoint ended. Returned {Object}

but I got

Calling function endpoint...
Calling function get_all...
Function get_all ended. Returned [Objects]
Calling function get_all...
Function get_all ended. Returned [Objects]
Calling function get_all...
Function get_all ended. Returned [Objects]
Function endpoint ended. Returned {Object}
Calling function get_all...
Function get_all ended. Returned [Objects]
Calling function get_all...
Function get_all ended. Returned [Objects]
Calling function get_all...
Function get_all ended. Returned [Objects]
Calling function get_all...
Function get_all ended. Returned [Objects]
Calling function get_all...
Function get_all ended. Returned [Objects]
Calling function get_all...
Function get_all ended. Returned [Objects]

Could anyone figure out why the decorator is behaving like that ?

Thank you in advance

Answer 1

Let's expect the output of the following example.

def decorator(f):
    def g():
        print('Hello, G.')
    return g


@decorator
def f():
    print('Hello, F.')


f()

It will print

Hello, G.

The decorator did not decorate f at all, but instead, without any decoration over f, it returns a completely new method (defined as g). Or, decorator can return anoynymous method as well.

def decorator(f):
    return lambda : print('Hello, G.')

What decorator does is this. It takes a method (with arguments if necessary) and defines a new method probably with the given method, aka, decoration. Then it returns the newly defined method but with the same name of the given function. The following abstraction would help.

@decorator
def f():
    print('Hello, F.')

vvvvvvvvvvvvvvvvvvvvvv

def f():  # the name is not changed
#def g():   as if anonymous function
    print('Hello, G.')

So it seems decorated f, however, it is a new method just named f. If you call TestDAO.get_all from AppService, you call already decorated TestDAO.get_all.