Python - Log Decorator 활용

이글을 통해 Python에서 제공하는 중요 기능중 하나인 Decorator를 활용한 Log Decorator관련해서 정리해보고자 한다.

Decorator 활용이 Log에 적절한 이유는

Decorator는 Python 설명을 보면 잘 나와 있듯이 함수를 감싸는 기능을 제공하기 때문에 실행전, 실행후에 일관성있게 정의하여 적용하고자 할때 Decorator만 한 것이 없다.

즉 log 입장으로 보면, 함수 실행전과 실행후에 대한 로그를 한번에 구성할 수 있어서 매우 유용하다고 할 수 있겠다.

그리고 개발한 프로그램을 서비스할 때 문제 분석을 위해 로그를 기록해야 하는 경우 log를 위한 코드를 추가를 해야하기 때문에 Decorator를 활용하기가 제격이라고 할 수 있다.

 

가장 간단하게 만들수 있는 log Decorator는 다음과 같다.

def log(func):

    def wrap_log(*args, **kwargs):
        name = func.__name__
        result = func(*args, **kwargs) # 실제 함수를 호출하는 구분
        print('log decorator',name, result)
        return func
    return wrap_log

@log
def sum(a):
    return a+a

if __name__ == "__main__":
    value = sum(2)

즉 실행 함수를 func로 가지고 와서 이를 실행하고 실행 결과를 반환해 주게 된다.

이를 활용하여 로깅을 실행전, 실행후로 정의할 수 있고, try/except를 활용하여 문제의 원인을 기록해 쉽게 관리가 가능하다.

Github을  찾아보던중 아래와 같이 로그 데코레이터를 구현해 놓은 소스가 있어, 관련 링크도 함께 남겨보았다.

(코드는 백업 목적으로 아래 남겨둔다.)

GitHub - hima03/log-decorator: Best practices and methods to implement logging in python project

log.py

import logging
import os


class CustomFormatter(logging.Formatter):
    """ Custom Formatter does these 2 things:
    1. Overrides 'funcName' with the value of 'func_name_override', if it exists.
    2. Overrides 'filename' with the value of 'file_name_override', if it exists.
    """

    def format(self, record):
        if hasattr(record, 'func_name_override'):
            record.funcName = record.func_name_override
        if hasattr(record, 'file_name_override'):
            record.filename = record.file_name_override
        return super(CustomFormatter, self).format(record)


def get_logger(log_file_name, log_sub_dir=""):
    """ Creates a Log File and returns Logger object """

    windows_log_dir = 'c:\\logs_dir\\'
    linux_log_dir = '/logs_dir/'

    # Build Log file directory, based on the OS and supplied input
    log_dir = windows_log_dir if os.name == 'nt' else linux_log_dir
    log_dir = os.path.join(log_dir, log_sub_dir)

    # Create Log file directory if not exists
    if not os.path.exists(log_dir):
        os.makedirs(log_dir)

    # Build Log File Full Path
    logPath = log_file_name if os.path.exists(log_file_name) else os.path.join(log_dir, (str(log_file_name) + '.log'))

    # Create logger object and set the format for logging and other attributes
    logger = logging.Logger(log_file_name)
    logger.setLevel(logging.DEBUG)
    handler = logging.FileHandler(logPath, 'a+')
    """ Set the formatter of 'CustomFormatter' type as we need to log base function name and base file name """
    handler.setFormatter(CustomFormatter('%(asctime)s - %(levelname)-10s - %(filename)s - %(funcName)s - %(message)s'))
    logger.addHandler(handler)

    # Return logger object
    return logger

 

log_decorator.py

import sys, os, functools
from inspect import getframeinfo, stack
import log

def log_decorator(_func=None):
    def log_decorator_info(func):
        @functools.wraps(func)
        def log_decorator_wrapper(self, *args, **kwargs):
            # Build logger object
            logger_obj = log.get_logger(log_file_name=self.log_file_name, log_sub_dir=self.log_file_dir)

            """ Create a list of the positional arguments passed to function.
            - Using repr() for string representation for each argument. repr() is similar to str() only difference being
             it prints with a pair of quotes and if we calculate a value we get more precise value than str(). """
            args_passed_in_function = [repr(a) for a in args]
            """ Create a list of the keyword arguments. The f-string formats each argument as key=value, where the !r 
                specifier means that repr() is used to represent the value. """
            kwargs_passed_in_function = [f"{k}={v!r}" for k, v in kwargs.items()]

            """ The lists of positional and keyword arguments is joined together to form final string """
            formatted_arguments = ", ".join(args_passed_in_function + kwargs_passed_in_function)

            """ Generate file name and function name for calling function. __func.name__ will give the name of the 
                caller function ie. wrapper_log_info and caller file name ie log-decorator.py
            - In order to get actual function and file name we will use 'extra' parameter.
            - To get the file name we are using in-built module inspect.getframeinfo which returns calling file name """
            py_file_caller = getframeinfo(stack()[1][0])
            extra_args = { 'func_name_override': func.__name__,
                           'file_name_override': os.path.basename(py_file_caller.filename) }

            """ Before to the function execution, log function details."""
            logger_obj.info(f"Arguments: {formatted_arguments} - Begin function")
            try:
                """ log return value from the function """
                value = func(self, *args, **kwargs)
                logger_obj.info(f"Returned: - End function {value!r}")
            except:
                """log exception if occurs in function"""
                logger_obj.error(f"Exception: {str(sys.exc_info()[1])}")
                raise
            # Return function value
            return value
        # Return the pointer to the function
        return log_decorator_wrapper
    # Decorator was called with arguments, so return a decorator function that can read and return a function
    if _func is None:
        return log_decorator_info
    # Decorator was called without arguments, so apply the decorator to the function immediately
    else:
        return log_decorator_info(_func)