Gorio Tech Blog search

파이썬 logging Module 설명

13 Dec 2019 | 파이썬 References

목차

1. logging Module 소개

1.1. Introduction

logging 모듈은 파이썬 자체에 내장되어 있는 모듈로 사용이 간편함에도 불구하고 훌륭한 기능으로 널리 사용되고 있다. logging은 소프트웨어가 작동 중일 때 발생하는 여러 ‘사건’을 추적하고, 개발자는 이를 통해 어떤 ‘사건’이 발생하였고 따라서 앞으로 어떤 해결책을 강구해야 할지 판단하게 된다. 이러한 ‘사건’들은 각각 중요도가 다를 것인데, 본 logging 모듈은 이 중요도를 level이라고 정의하고 있다. level에 대한 설명은 아래 1.2장에서 확인할 수 있다.

지금은 잠시 간단한 예시를 확인해 보자. 예를 들어 다음과 같은 메서드를 만들었다고 하자.

def cal(a, b):
    try:
        result = a/b
    except ZeroDivisionError:
        logger.exception("Division by zero is not possible")
    else:
        return result

당연하게도 b에 0을 대입하면 에러가 발생할 것이다. 개발 코드 중에 실수로 b에 0을 대입할 가능성이 있다고 하자. 그렇다면 언제 어떻게 에러가 발생하는지 기록으로 남겨두면 좋을 것이다. 그래야 디버깅이 편리하고 효율적으로 이루어질 수 있다.

실제로 에러가 발생하면 다음과 같은 형식으로 메시지가 뜰 것이다.

cal(2, 0)

2019-12-12 22:29:49,091 - root - ERROR - Division by zero is not possible
Traceback (most recent call last):
  File "<ipython-input-38-41356b58271d>", line 3, in cal
    result = a/b
ZeroDivisionError: division by zero

위에서 볼 수 있는 메시지의 형식과 내용 등은 모두 logging 모듈로 제어할 수 있다. 예를 들어 root의 경우 RootLogger을 의미하는데, 사용자가 직접 설정한 Logger 이름이 출력되게 할 수 있다. 이러한 기능은 수많은 파일과 class 등이 난무할 때 어디서 문제가 발생하였는지 쉽게 알 수 있게 해줄 것이다.

본 글은 우선적으로 logging 모듈의 가장 기본적인 기능들을 정리하는 데에 초점을 맞추었다. logger Module에 대해 더욱 자세히 알고 싶다면 아래 Reference에 있는 참고 사이트를 확인하길 바란다.

1.2. 작동 원리 확인

1) Level 설정
logging은 level 설정을 통해 메시지의 중요도를 구분한다. 총 5개의 기본 level이 제공되는데, 설정에 변화를 주지 않는다면 WARNING이 기본 level로 지정되어 있다.

Level 설명
DEBUG 간단히 문제를 진단하고 싶을 때 필요한 자세한 정보를 기록함
INFO 계획대로 작동하고 있음을 알리는 확인 메시지
WARNING 소프트웨어가 작동은 하고 있지만,

예상치 못한 일이 발생했거나 할 것으로 예측된다는 것을 알림
ERROR 중대한 문제로 인해 소프트웨어가 몇몇 기능들을 수행하지 못함을 알림
CRITICAL 작동이 불가능한 수준의 심각한 에러가 발생함을 알림

2) logging work flow 확인
본 모듈을 작동시키는 중요한 구성 요소들은 아래와 같다.

logger, handler, filter, formatter

Log 사건 정보들은 LogRecord Instance 안에 있는 위 요소들 사이에서 전송되는 것이다.

이들의 역할을 알아보면,

Logger: 어플리케이션 코드가 직접 사용할 수 있는 인터페이스를 제공함
Handler: logger에 의해 만들어진 log 기록들을 적합한 위치로 보냄
Filter: 어떤 log 기록들이 출력되어야 하는지를 결정함
Formatter: log 기록들의 최종 출력본의 레이아웃을 결정함

logging은 Logger class의 Instance (=logger)를 선언하는 것으로 부터 시작한다. 각 logger는 name을 가지는데, 이 name들은 마침표를 통해 계층적 관계를 형성하게 된다. 즉 예를 들어 Basket.html이라는 logger가 있다고 한다면, 이는 Basket이라는 logger가 html이라는 logger의 부모 역할을 하게 되는 것이다. 파이썬의 부모-자식 상속 관계를 투영한 것으로, 설정을 변화시키지 않으면 자식 logger는 부모 logger의 여러 특성들을 물려받게 된다.

이후 Handler를 통해 log 기록들을 어디에 표시하고, 어디에 기록할지 결정하게 된다. Filter는 logging 모듈을 간단히 사용할 때는 잘 쓰이지는 않지만 level보다 더 복잡한 필터링을 원할 때 사용된다.

Formatter는 실제로 출력되는 형식을 결정한다.

work flow에 대해 더욱 자세히 알고 싶다면 이곳을 참조하기 바란다.

2. 실질적인 사용법

2.1. 차례대로 logging 준비하기

2.1.1. logger 생성

logging instance인 logger는 아래와 같은 구문으로 생성한다.

logger = logging.getLogger("name")

위 “name” 에는 String이 들어가는데, 아무것도 입력하지 않을 경우 root logger가 생성된다.

root logger는 모든 logger의 부모와 같은 존재로, 다른 모든 logger는 설정을 변화시키지 않으면 root logger의 자식이다. root logger을 바로 사용할 수도 있지만, 기능과 목적에 따라 다른 logger들을 생성하는 것이 낫다.

2.1.2. logger에 level 부여하기

logger를 생성했다면, 이제는 기본적인 level을 부여해줄 차례다.

logger.setLevel(logging.INFO)

앞서 생성한 logger에 INFO level을 부여하였다. 이제 이 logger 객체는 INFO 이상의 메시지를 출력할 수 있다.
level을 소문자로 바꾸어 메서드로 사용하면 메시지를 출력할 수 있다.

logger.info("Message")

현재로서 이 logger는 오직 console에만 메시지를 출력할 수 있을 뿐이다. 더욱 정교하게 만들기 위해서는 handler가 필요하다.

2.1.3. handler와 formatter 설정하기

handler object는 log 메시지의 level에 따라 적절한 log 메시지를 지정된 위치에 전달(dispatch)하는 역할을 수행한다.

logger는 addHandler 메서드를 통해 이러한 handler를 추가할 수 있다. handler는 기능과 목적에 따라 여러 개일 수 있으며, 각 handler는 다른 level과 다른 format을 가질 수도 있다.

handler의 종류는 15개 정도가 있는데, 가장 기본적인 것은 StreamHandler와 FileHandler이다. 전자는 Stream(console)에 메시지를 전달하고, 후자는 File(예를 들어 info.log)에 메시지를 전달하는 역할을 한다. 다른 handler가 궁금하다면 이곳을 참조하기 바란다.

handler 객체의 level까지 설정했다면, 이제 이 메시지를 어떤 형식으로 출력할지에 대해 고민해야 한다.
이 때 필요한 것이 formatter이다. 아래와 같이 생성한다. format을 좀 더 편리하게 작성하는 방법에 대해서는 3장에서 설명하겠다.

logging.Formatter(
  fmt = None,     # 메시지 출력 형태. None일 경우 raw 메시지를 출력.
  datefmt = None, # 날짜 출력 형태. None일 경우 '%Y-%m-%d %H:%M:%S'.
  style = '%'     # '%', '{', '$' 중 하나. `fmt`의 style을 결정.
)

이제 준비는 끝났다. handler 객체는 아래와 같이 만들어진다.

# handler 객체 생성
stream_handler = logging.StreamHandler()
file_handler = logging.FileHandler(filename="information.log")

# formatter 객체 생성
formatter = logging.Formatter(fmt="%(asctime)s - %(name)s - %(levelname)s - %(message)s")

# handler에 level 설정
stream_handler.setLevel(logging.INFO)
file_handler.setLevel(logging.DEBUG)

# handler에 format 설정
stream_handler.setFormatter(formatter)
file_handler.setFormatter(formatter)

부가적으로 하나 더 설명하자면, 위에 있는 간단한 예시의 경우 단지 하나의 logger를 생성했을 뿐이지만, 실제로는 여러개의 logger를 계층적으로 사용할 가능성이 높다. 이러한 계층적인 구조와 관련하여, 앞의 1.2장에서 언급한 부모-자식 관계와 관련하여 염두에 두어야 할 부분이 있다.

자식 logger는 부모 logger와 관련된 handler로 메시지를 전파(propagate)한다. 즉, 부모 logger의 설정은 자식 logger과 연결되어 있다. 이 때문에 사실 모든 logger에 대해 handler를 일일히 정의하고 설정하는 것은 불필요한 일이라고 볼 수 있다. 따라서 가장 효율적인 방법은 최상위 logger에 대해 handler 설정을 완료하고 때에 따라 자식 logger를 생성하는 것이 될 것이다. 만약 이러한 연결을 원치 않는다면, 아래와 같이 logger의 propagate attribute를 False로 설정해주면 된다.

logger.propagate = False

2.1.4. logger에 생성한 handler 추가하기

logger.addHandler(stream_handler)
logger.addHandler(file_handler)

위 과정을 거치면, 지금까지 설정한 모든 것들이 logger에 담기게 된다.

2.2. 빠른 Setting

위에서 차근차근 알아본 logging 모듈 사용법을 확실히 익혔다면, 기본적인 Setting 환경을 만들어두고 이를 조금씩 변형하여 사용하는 것이 편리할 것이다.

Setting을 진행하는 방법에는 여러가지가 있는데, 본 글에서는 그 중 1) json 파일로 setting하는 법과 2) 파이썬 코드로 하는 법에 대해 설명할 것이다. 본 예제에서는 INFO를 기본 level로 설정한다.

2.2.1. json 파일로 세팅

아래와 같은 json 파일을 만들어보자.

{
    "version": 1,
    "formatters": {
        "basic": {
            "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
        }
    },

    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "level": "INFO",
            "formatter": "basic",
            "stream": "ext://sys.stdout"
        },

        "file_handler": {
            "class": "logging.FileHandler",
            "level": "DEBUG",
            "formatter": "basic",
            "filename": "info.log"
        }
    },

    "root": {
        "level": "INFO",
        "handlers": ["console", "file_handler"]
    }
}

첫 문단에서 basic이라는 이름의 format을 만들었다. 앞으로 설정을 변경하지 않는 이상 [시간-logger이름-level이름-메시지] 형식으로 출력됨을 의미한다.

두 번째 문단과 세 번째 문단은 2개의 handler에 대한 설정이다. console은 말 그대로 console(Stream)에 출력되는 handler로, logging.StreamHandler class로 구성되며 위에서 설정한 basic format을 사용함을 알 수 있다. 이 handler의 level은 INFO이다. file_handler는 디렉토리 내에 info.log란 파일을 생성하여 로그를 기록하면서 저장하는 handler이다. 이 handler의 level은 DEBUG이다.

마지막 문단에서는 root logger에 대한 설정을 마무리하고 있다.

이제 json 파일을 읽어오자.

with open("logging.json", "rt") as file:
    config = json.load(file)

logging.config.dictConfig(config)
logger = logging.getLogger()

2.2.2. 코드로 세팅

사실 코드로 세팅한다는 것은 위에 있는 정보들을 코드로 입력한다는 것에 불과하다. 위에서 자세히 설명한 것을 다시 한 번 확인하는 수준이라고 생각하면 될 것이다. 특별할 것이 없으므로 바로 확인해보자.

def make_logger(name=None):
    #1 logger instance를 만든다.
    logger = logging.getLogger(name)

    #2 logger의 level을 가장 낮은 수준인 DEBUG로 설정해둔다.
    logger.setLevel(logging.DEBUG)

    #3 formatter 지정
    formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")
    
    #4 handler instance 생성
    console = logging.StreamHandler()
    file_handler = logging.FileHandler(filename="test.log")
    
    #5 handler 별로 다른 level 설정
    console.setLevel(logging.INFO)
    file_handler.setLevel(logging.DEBUG)

    #6 handler 출력 format 지정
    console.setFormatter(formatter)
    file_handler.setFormatter(formatter)

    #7 logger에 handler 추가
    logger.addHandler(console)
    logger.addHandler(file_handler)

    return logger

#2 과정에서 만일 가장 낮은 수준으로 level을 설정하지 않는다면, 아래 handler들에서 setLevel을 한 것이 무의미해진다는 점을 꼭 알아두길 바란다. (handler 별로 다른 level 설정하기)

위 코드를 보면 console에 표기되는 StreamHandler에는 INFO level을, 파일에 기록되는 FileHandler에는 DEBUG level을 설정한 것을 확인할 수 있다.

logger = make_logger()

logger.debug("test")
logger.info("test")
logger.warning("test")

위와 같은 코드를 입력하면, console 창에는 아래와 같이 기록되지만,

2019-12-13 14:50:40,133 - root - INFO - test
2019-12-13 14:50:40,679 - root - WARNING - test

test.log file에는 아래와 같이 기록됨을 확인할 수 있다.

3. Format 편리하게 설정하기

바로 위의 log 기록들은 사실 아주 도움이 되는 정보들이라고 하기는 어렵다. line 번호도 없고, file 이름도 없다. logging 모듈은 이러한 log 기록들을 남길 때 굉장히 다양한 형식을 지원하고 있다. 그 형식에 대해 알아보기 전에 먼저 log 기록들, 즉 LogRecord Objects에 대해 알아보도록 하자.

LogRecord 객체는 Logger에 의해 자동적으로 생성되며, 수동으로 생성하려면 makeLogRecord 메서드를 이용하면 된다.

logging.LogRecord(name, level, pathname, lineno, msg, …)

여기서 pathname은 logging call이 만들어지는 소스 파일의 전체 pathname을 의미한다.
lineno는 logging call이 만들어지는 소스파일의 라인 번호를 말한다.
msg는 event description 메시지를 의미한다.

이 LogRecord는 여러 속성(attribute)을 갖고 있는데, 이 속성들은 format을 정의하는데 활용된다.
그 리스트와 설명은 아래와 같다.

속성 이름 format 설명
asctime %(asctime)s 인간이 읽을 수 있는 시간 표시
created %(created)f logRecord가 만들어진 시간
filename %(filename)s pathname의 file 이름 부분
funcName %(funcName)s logging call을 포함하는 function의 이름
levelname %(levelname)s 메시지의 Text logging level: 예) INFO
lineno %(lineno)d logging call이 발생한 코드의 line 숫자
module %(module)s filename의 모듈 이름 부분
message %(message)s 메시지
name %(name)s logger의 이름
pathname %(pathname)s full pathname
thread %(thread)d thread ID
threadName %(threadName)s thread 이름

간단한 예는 아래와 같다.

LOG_FORMAT = "[%(asctime)-10s] (줄 번호: %(lineno)d) %(name)s:%(levelname)s - %(message)s"
logging.basicConfig(format=LOG_FORMAT)
logger = logging.getLogger("setting")
logger.setLevel(20)
logger.info("sth happened")

[2019-12-16 13:53:29,889] (줄 번호: 6) setting:INFO - sth happened

Reference

공식문서 https://hamait.tistory.com/880 https://www.machinelearningplus.com/python/python-logging-guide/ https://snowdeer.github.io/python/2017/11/17/python-logging-example/

Related Posts