[Python] 로그 파일 핸들러 2개(TimedRotatingFileHandler, RotatingFileHandler) 합쳐서 사용하는 방법

배경

스프링과 FastAPI를 각각 사용하여 서버를 개발 하던 중 두 서버 모두 로그를 파일로 저장하는 기능이 필요했습니다. 두 프레임워크 모두 로깅은 기본적으로 제공하고 있었는데 스프링에서는 간단한 설정만으로 파일 크기와 시간(일별 기록)을 모두 고려한 파일 롤링 정책 적용이 가능했지만, 파이썬에는 두 경우에 각각 대응되는 파일 핸들러들을 분리하여 제공하고 있습니다. 파이썬에서도 스프링에서처럼 파일 크기와 시간(일별 기록) 둘 다를 고려한 핸들러가 필요하여 해당 내용을 탐색했습니다.

문제

파이썬의 logging 라이브러리는 TimedRotatingFileHandler와 RotatingFileHandler를 제공합니다. 전자는 이름 그대로 시간을 기준으로 롤링 정책을 적용하는 핸들러이고, 후자는 파일의 크기와 개수를 고려한 롤링 정책을 가진 핸들러입니다. 단순하게 생각하면 두 개를 다 적용하면 될 것 같지만, 실제로 핸들러를 2개 등록하여 로그를 시도해보니 각각의 핸들러에서 로그가 기록되어 동일 로그가 중복 출력되는 현상이 발생했습니다.

해결 방법

별도의 핸들러를 직접 정의하여 사용하면 이러한 문제를 해결할 수 있습니다. 별도의 핸들러 객체를 만든 후 TimedRotatingFileHandler와 RotatingFileHandler를 합친 롤링 정책을 적용한 롤링 동작을 정의하면 제가 원하는 기능을 구현할 수 있다는 걸 알게 되었습니다. 문제는 두 핸들러를 뜯어봐야한다는 것이었는데, 다행히도 기존에 비슷한 고민을 했던 자료가 온라인 커뮤니티에 남아있어 해당 코드를 그대로 가져와서 사용하고 테스트해볼 수 있었습니다. 코드는 다음과 같습니다.

import logging, time
class EnhancedRotatingFileHandler(logging.handlers.TimedRotatingFileHandler, logging.handlers.RotatingFileHandler):

    def __init__(self, filename, mode='a', maxBytes=0, backupCount=0, encoding=None,
                 delay=0, when='h', interval=1, utc=False):
        logging.handlers.TimedRotatingFileHandler.__init__(
            self, filename=filename, when=when, interval=interval,
            backupCount=backupCount, encoding=encoding, delay=delay, utc=utc)

        logging.handlers.RotatingFileHandler.__init__(self, filename=filename, mode=mode, maxBytes=maxBytes,
                                                      backupCount=backupCount, encoding=encoding, delay=delay)

    def computeRollover(self, current_time):
        return logging.handlers.TimedRotatingFileHandler.computeRollover(self, current_time)

    def doRollover(self):
        # get from logging.handlers.TimedRotatingFileHandler.doRollover()
        current_time = int(time.time())
        dst_now = time.localtime(current_time)[-1]
        new_rollover_at = self.computeRollover(current_time)

        while new_rollover_at <= current_time:
            new_rollover_at = new_rollover_at + self.interval

        # If DST changes and midnight or weekly rollover, adjust for this.
        if (self.when == 'MIDNIGHT' or self.when.startswith('W')) and not self.utc:
            dst_at_rollover = time.localtime(new_rollover_at)[-1]
            if dst_now != dst_at_rollover:
                if not dst_now:  # DST kicks in before next rollover, so we need to deduct an hour
                    addend = -3600
                else:  # DST bows out before next rollover, so we need to add an hour
                    addend = 3600
                new_rollover_at += addend
        self.rolloverAt = new_rollover_at

        return logging.handlers.RotatingFileHandler.doRollover(self)

    def shouldRollover(self, record):
        return logging.handlers.TimedRotatingFileHandler.shouldRollover(self, record) or logging.handlers.RotatingFileHandler.shouldRollover(self, record)

출처: https://stackoverflow.com/questions/6167587/the-logging-handlers-how-to-rollover-after-time-or-maxbytes (댓글 하단의 개선된 코드)

사용 예시

# uvicorn logger
uvicorn_logger = logging.getLogger("uvicorn")
uvicorn_logger.setLevel(logging.INFO)

# enhanced file handler (time and file size)
enhanced_handler = EnhancedRotatingFileHandler(filename='logs/error.log'.format(datetime.now()),
                                               maxBytes=1024 * 1024 * 1024, backupCount=1, encoding="utf-8")
enhanced_handler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(message)s"))
enhanced_handler.setLevel(logging.INFO)
uvicorn_logger.addHandler(enhanced_handler)

여전히 해결되지 않은 것

적용된 핸들러를 테스트해본 결과 한 가지 문제점이 추가로 발견되었습니다. 테스트 결과 1) 용량 + 파일 개수, 2) 시간 + 파일 개수 조합은 문제가 없었으나 3) 시간 + 용량 + 파일 개수 조합에서는 파일 개수의 일별 제한만 가능하다는 문제를 발견하게 되었습니다. 이는 로그 파일이 일별로 계속 쌓이게 되어 용량이 계속 늘어날 수 있다는 문제를 가지고 있기에 꼭 해결해야 했습니다. 

 

그러나 1) 로깅 폴더의 전체 용량을 제한할 수 없고, 앞서 언급한 바와 같이 2) 전체 파일 개수를 제한할 수 없다는 두 가지 문제를 동시에 해결하기에는 시간이 촉박했습니다. 또한 문제 해결을 위해 코드를 내부까지 들여다보고 다양한 시나리오 테스트를 해보기에는 더 높은 우선순위의 작업들이 많아 현재로서 그다지 가치있는 일은 아니라는 결론에 이르게 되었습니다. 향후에 필요하게 되면 조금 더 들여다보고 이 문제까지 해결하여 사용할 생각입니다. 현재로서는 파일 1개로 용량 제한을 거는 방법이 차선책이다보니 RotatingFileHandler를 적용해놓은 상태입니다.