[Python] 디버깅과 로그

여러분들은 어떻게 디버깅을 하시나요? 보통은 코드의 특정 위치에 print()문을 띄워서 데이터의 출력값이나 코드의 흐름을 콘솔에 띄울 수 있는데요, 이것 보다 좀 더 세련되고 정형화된 방법으로 로그를 띄우는 방법에 대해 알아봅시다.

 

파이썬에서는 logging이라는 모듈을 사용하여 로그를 띄울 수 있습니다.

 

---

로거 생성과 레벨 설정

getLogger 함수를 통해서 특정 이름을 가진 로거를 생성할 수 있습니다. 그리고 생성된 로거에 setLevel 메소드를 이용해 로깅의 레벨을 정할 수 있습니다.

import logging

logger = logging.getLogger("my_log")
logger.setLevel(logging.INFO)

 

로깅의 레벨은 다음과 같이 크게 6단계가 있습니다.

Level	Numeric value
CRITICAL	50
ERROR	40
WARNING	30
INFO	20
DEBUG	10
NOTSET	0

예를 들어 로깅의 레벨을 INFO로 설정했다는 것은, 레벨이 INFO 레벨 이상인 로그에 대해서만 출력하고, 그 밑의 레벨들은 전부 무시하겠다는 뜻입니다. 만약 따로 레벨을 설정하지 않는다면 기본값은 WARNING으로 고정됩니다.  

 

INFO 등급을 가지는 로거는 DEBUG 레벨의 메세지에 반응할까요? isEnabledFor 메소드로 그 사실을 확인할 수 있습니다.

logger.isEnabledFor(level=logging.DEBUG)	# False

 

로그는 다음과 같은 방식으로 메세지를 직접 띄울 수 있습니다.

logger.debug("debug log printed")
logger.info("info log printed")
logger.warning("warning log printed")
logger.error("error log printed")
logger.critical("critical log printed")

 

---

핸들러 설정 1 (로그 포매팅)

앞서 만든 로거에 핸들러라는 것을 등록해 본인만의 로거를 커스터마이징할 수 있습니다.

 

첫번째로, 로그가 특정 형태를 띄도록 포매팅하는 핸들러를 만들어 봅시다. StreamHandler와 Formatter객체를 각각 만든 뒤 포맷 객체를 핸들러 객체에 넣으면 됩니다.

format_handler = logging.StreamHandler()
formatter = logging.Formatter(
	"%(asctime)s  %(name)s  %(levelname)s  %(message)s"
)
format_handler.setFormatter(formatter)

 

위 Formatter 안의 포매팅 식에서 %(asctime)s는 로그가 출력된 시간, %(name)s는 로거의 이름, %(levelname)s는 로그의 레벨, 그리고 %(message)s는 메세지를 나타냅니다.

그리고 다음과 같이 로거에 핸들러를 추가합니다.

logger.addHandler(format_handler)

 

코드를 한번 실행해보면 다음과 같은 메세지가 콘솔에 출력됩니다.

logger.warning("warning log printed")

# 2021-12-16 02:48:35,750  my_logger  WARNING  warning log printed

 

%(asctime)s 처럼 문자열로 포매팅할 수 있는 다양한 속성들을 logrecord attributes라고 하는데요, 아래 공식 문서에서 좀 더 다양한 속성들을 한번 찾아보세요!

https://docs.python.org/3/library/logging.html#logrecord-attributes

logging — Logging facility for Python — Python 3.10.1 documentation

 

---

핸들러 설정 2 (파일 저장)

두번째로, 출력된 로그들을 파일에 저장할 수 있는 핸들러를 만들어 봅시다.

file_handler = logging.FileHandler("my.log")
logger.addHandler(file_handler)

 

이렇게 하면 이제부터 출력되는 로그들은 모두 my.log라는 파일에 저장되게 될 것입니다.

 

---

루트 로거의 성질

만약 getLogger 메소드로 아무 이름도 설정하지 않고 로거를 만들게 되면 루트 로거라는 것이 만들어 지는데요, 이 루트 로거는 모든 로거들의 최상단이 되는 로거로, 이 로거의 특성이 하위 로거들로 유전되는 특징이 있습니다.

 

따라서 루트 로거에 레벨을 설정하게 되면 다른 로거들은 따로 레벨을 설정하지 않아도 루트 로거에서 정한 레벨값을 따르게 됩니다.

rootlogger = logging.getLogger()	# 루트 로거 생성
rootlogger.setLevel(level=logging.DEBUG)

logger = logging.getLogger("custom_logger")

rootlogger.debug("It will be shown")
logger.debug("It will be shown too")

 

만약 루트 로거를 따르지 않는 독립적인 로거를 만들고 싶다면 propagate 속성을 False로 설정하면 됩니다.

logger.propagate = False

 

---

config를 이용한 정교한 커스터마이징

지금까지는 다양한 메소드나 객체를 불러옴으로써 로그를 출력하는 로거를 커스터마이징했지만, 이는 코드를 매우 지저분하게 만듭니다. 게다가 섬세한 로거를 만들기도 힘들구요. 만약 WARNING 레벨 이상의 로그에 대해서만 콘솔에 출력하되, ERROR 레벨 이상의 로그는 따로 파일에 저장되도록 할 수는 없을까요?

logging.config를 사용하면 로거를 커스터마이징할 수 있는 상세 정보를 미리 변수 하나로 정의해두고, 로거에 바로바로 적용함으로써 좀 더 깔끔한 코드로 복잡한 로거를 만들 수 있습니다.

 

우선 예시 코드는 다음과 같습니다.

import logging
import sys

LOGGING_CONFIG = dict(
    version=1,
    loggers={
        "my_logger": {
            "level": "INFO",
            "handlers": ["console", "file_handler"],
            "propagte": "no",
        }
    },
    handlers={
        "console": {
            "class": "logging.StreamHandler",
            "level": "WARNING",
            "formatter": "simple",
            "stream": sys.stdout,
        },
        "file_handler": {
            "class": "logging.FileHandler",
            "level": "ERROR",
            "formatter": "simple",
            "filename": "info.log",
        },
    },
    formatters={
        "simple": {
            "class": "logging.Formatter",
            "format": "%(asctime)s  %(name)s  %(levelname)s  %(message)s",
        }
    },
)

logging.config.dictConfig(LOGGING_CONFIG)
logger = logging.getLogger("my_logger")

 

LOGGING_CONFIG라는 상수는 version, loggers, handlers, formatters 라는 key를 가진 딕셔너리 형태입니다. loggers에는 로거의 이름과 레벨, 등록할 핸들러를 작성하고, handlers에는 사용할 핸들러와 각 핸들러 고유의 레벨을 작성하고, formatters에는 핸들러에서 사용할 포매터를 작성합니다.

이렇게 정의된 상수를 logging.config.dictConfig에 적용하면, LOGGING_CONFIG의 loggers에서 정의했던 로거 이름으로 로거를 만들 때, 그 세부 설정들이 모두 자동으로 로거에 적용됩니다. 위 코드를 보면 로거의 이름이 "my_logger"로 통일된 것을 확인할 수 있죠?

 

따라서 아래 코드를 동작시키면 콘솔에는 warning과 error로그 둘 다 나타나지만, 로그 파일에는 error로그만 저장된다는 것을 확인할 수 있을 것입니다.

logger.warning("this will be appeared on console as formatted string")
logger.error("this will be stored in a file as formatted string")

 

---

json파일로 config 관리하기

바로 위에서 작성했던 코드를 파일을 분리해서 작업해 봅시다. LOGGING_CONFIG가 담고 있던 정보를 json파일로 따로 저장하고, 파이썬 파일에서는 그 값을 읽어 logging에 적용하는 방식입니다.

 

먼저 logging.json이라는 이름의 파일을 만듭니다.

{
    "version": 1,
    "loggers": {
        "my_logger": {
            "level": "INFO",
            "handlers": ["console", "file_handler"],
            "propagte": "no"
        }
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "level": "WARNING",
            "formatter": "simple",
            "stream": "ext://sys.stdout"
        },
        "file_handler": {
            "class": "logging.FileHandler",
            "level": "ERROR",
            "formatter": "simple",
            "filename": "info.log"
        }
    },
    "formatters": {
        "simple": {
            "class": "logging.Formatter",
            "format": "%(asctime)s  %(name)s  %(levelname)s  %(message)s"
        }
    }
}

 

그리고 다른 파일에서 위 json파일을 불러와 로거를 만드는 코드를 작성합니다.

import logging
import json

with open("logging.json", "rt") as f:
    config = json.load(f)
    logging.config.dictConfig(config)
    logger = logging.getLogger("my_logger")

 

---

참고 자료

• 파이썬 공식 문서 : https://docs.python.org/3/library/logging.html
• 파이썬 로깅의 모든것 : https://hamait.tistory.com/880
• 개인 깃허브 : https://github.com/kmlee78/Python_Coding/tree/main/logging