Lined Notebook

[python] logging 기본 사용법 (디버깅 기초편)

by cuore J

logging의 기본 사용법

0.) 복습

헷갈려서 다시 찾아온 분들을 위한 핵심을 적어드려요.

더보기
import logging

logging.basicConfig(format='(%(asctime)s) %(levelname)s:%(message)s',
                    datefmt ='%m/%d %I:%M:%S %p',
                    level=logging.DEBUG)
# format이 없다면? 레벨:root 로 표기됨
# datefmt가 없다면? 2021-02-28 16:49:45,896 형식 (쉼표는 ms)
# level? 로깅을 출력할 범위를 설정. 없다면? warning이 기본!


logging.debug("디버그")  # 여기선 debug를 기본으로 설정하여서 여기서부터 다!
logging.info("정보")
logging.warning("경고")  #warning이 기본!
logging.error("에러")
logging.critical("심각")

try:
    1/0
except Exception:
    logging.exception("에러")

1.) 필요성.

파이썬으로 코드를 짜면서 디버깅 용도의 print( ) 문을 많이 쓴 기억이 한 번쯤은 있나요? 저는 옛날에 함수 사이에 수많은 print( )문을 적고 실행해 가며 문제를 해결한 후, 일일이 print( ) 문을 삭제 또는 주석처리를 했었죠... 반복하면서 말이죠! 또는 디버거를 배워 쓰기도 할 거예요. 하지만 코드의 양이 매우 많아져서 나중에 문제를 파악, 로깅하는데 시간이 너무 많이 걸리면 어떻게 해야 할까요? 이를 위해 파이썬은 logging이라는 내장 함수를 저희에게 제공합니다. 자세한 내용에 앞서 정말 기초적으로 바로 내 코드에 쓸 수 있는 "기초 편"을 작성해 보겠습니다. "기초 편"으로 대부분의 디버깅이 훨씬 편해질 거예요! 

print("1. 여기서 문제생겼니?")
함수 1.

print("2. 여기서 문제생겼니?")
함수 2.
import logging

logging.warning('1.여기서 문제다.')
#함수 1
logging.warning('2.여기서 문제다.')
#함수 2
>>> WARNING:root:1.여기서 문제다.
>>> WARNING:root:2.여기서 문제다.

위의 사용예제를 보시면 print( ) 대신 logging.warning( ) 을 통해 사용되네요. 여기서 warning은 level이라고 합니다. 즉, WARNING 레벨의 디버깅 문자를 뿌려주네요.. 이걸 어떻게 심화 활용할까요?

2.) logging의 level

logging모듈은 기본 적으로 발생되는 이벤트의 5가지 level을 따라 로깅 메시지를 출력하며, 기본적으로 WARNING 이상의 문제만을 출력해 줍니다. 즉, DEBUG, INFO 의 경우는 로그가 남지 않습니다.

Level 설명
DEBUG 상세한 정보. 문제 진단 시 필요.
INFO 예상대로 작동하는지에 대한 확인.
WARNING (기본) 예상치 못한 일의 발생 ( 소프트웨어는 여전히 예상대로 작동)
ERROR 심각한 문제로 인해 소프트웨어 일부 기능 수행 못함
CRITICAL 심각한 에러로 인해 프로그램 자체가 계속 실행되지 않을 수 있음.
import logging

logging.debug("디버그")
logging.info("정보")
logging.warning("경고")
logging.error("에러")
logging.critical("심각")
>>> WARNING:root:경고
>>> ERROR:root:에러
>>> CRITICAL:root:심각

3.) logging의 기본 level 변경

그렇다면 WARNING이 아닌 DEBUG 의 레벨까지 전부 보려면 우리는 로깅의 레벨을 변경해야 합니다. logging의 레벨 변경은 logging.basicConfig(level=logging.level) 로 바꿔 줄 수가 있습니다.

import logging

logging.basicConfig(level=logging.DEBUG)

logging.debug("디버그")
logging.info("정보")
logging.warning("경고")
logging.error("에러")
logging.critical("심각")
>>> DEBUG:root:디버그
>>> INFO:root:정보
>>> WARNING:root:경고
>>> ERROR:root:에러
>>> CRITICAL:root:심각

4.) logging의 포맷

위에서 가만 보면 DEBUG:root:디버그라고만 나옵니다. 이걸 좀 바꿀 순 없을까요? 바로 format을 지정하면 됩니다.

import logging

logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.DEBUG)

logging.debug('디버그')
logging.info('정보')
logging.warning('경고')
>>> DEBUG:디버그
>>> INFO:정보
>>> WARNING:경고

%(levelname)s:%(message)s  는 결국 레벨:메시지를 출력하는 포맷으로 바꿔주는 역할입니다. 포맷의 여러 가지 종류는 포맷의 Attribute(속성) 를 확인해 주세요. 조금 더 의미 있게 시간을 추가해서 포함해 볼까요?

import logging

logging.basicConfig(format='(%(asctime)s) %(levelname)s:%(message)s',
                    datefmt ='%m/%d %I:%M:%S %p',
                    level=logging.DEBUG)

logging.debug('디버그')
logging.info('정보')
logging.warning('경고')
>>> (02/28 10:20:02 PM) DEBUG:디버그
>>> (02/28 10:20:02 PM) INFO:정보
>>> (02/28 10:20:02 PM) WARNING:경고

Attribute에 있는 %(asctime)s를 사용하여 시간을 추가해 주었으며 제 입맛대로 시간을 표기하기 위해 datefmt에 time.strtime()의 지시자(directives)을 사용하였습니다.

5.) logging의 예외처리

logging.exception을 이용하여 문제가 생겼을 때의 Error 메시지를 로깅할 수도 있습니다. 이 방법은 exception handler에서만 호출해야 합니다. 이 방법을 통해 예외처리에 대한 로깅을 할 수 있습니다.

import logging

logging.basicConfig(format='(%(asctime)s) %(levelname)s:%(message)s',
                    datefmt ='%m/%d %I:%M:%S %p',
                    level=logging.DEBUG)

try:
    1/0
except Exception:
    logging.exception("에러")
>>> (02/28 10:29:51 PM) ERROR:에러
>>> Traceback (most recent call last):
>>>   File "D:/1.STUDY/1-2. Python_library/1. logging/logging1.py", line 8, in <module>
>>>     1/0
>>> ZeroDivisionError: division by zero

6.) logging의 출력?

지금까지 보면, 로깅의 출력이 콘솔에서만 작동되는 것을 감지하셨을 겁니다. 이때, 다음과 같은 방법으로 파일에 저장할 수 도 있습니다.

import logging

logging.basicConfig(filename = './debug.log', level=logging.DEBUG)

logging.debug("디버그")
logging.info("정보")

이렇게 하면 'debug.log' 라는 파일에 저장이 됩니다. 다만 이렇게 설정하게 되면, 반대로 콘솔에 실행되지 않습니다.
이런 문제에 대한 해결 방법은 고급편에서 추후 다루도록 하겠습니다!!

7.) 여러 모듈로 구성되어 있는 경우의 로깅

자 이제, 기본적인 로깅은 다 알게 되었습니다. 그렇다면! 마지막으로 여러 모듈로 구성되어 있는 경우 로깅을 구성하는 방법은 다음과 같습니다.

#main.py
import logging
import mylib

logging.basicConfig(level=logging.DEBUG)

logging.debug("디버그(어느 모듈이게?)")
mylib.do_something()
logging.debug(" 끝 (어느 모듈이게?)")
#mylib.py
import logging

def do_something():
    logging.info('정보(어느 모듈이게?)')
>>> DEBUG:root:디버그(어느 모듈이게?)
>>> INFO:root:정보(어떤모듈이게?)
>>> DEBUG:root: 끝 (어느 모듈이게?)

다만, 이런 기초 방식의 로깅으론 아쉽게도 어떤 모듈에서 파생된 로깅인지 알 방법이 없습니다.
그럼, 5)의 문제와 같이 출력을 조정하고 싶고, 6)에서 여러 모듈 일 경우 어느 모듈에서 파생됐는지 알고 싶다면? 이렇게 되면 더 이상 logging.basicConfig로는 해결이 되지 않습니다. 이는 고급편 으로 넘어가야 하는 것이죠.

제가 가장 중요하게 여기는 것은, 딱 필요한 만큼만 아는 것입니다. 위의 문제에서 더 이상 필요 없다면, 바로 프로그래밍을 시작하시면 될 거예요! 아쉽게도 저는 부족한! 부분이 필요한 프로그래밍을 해야 하기 때문에 머리 아프게도 고급 편을 익혀야 했습니다. 추후 포스팅하겠습니다. 읽어봐 주셔서 감사합니다.

블로그의 정보

cuore J

cuore J

활동하기