로그(log), 로깅(logging)

파이썬으로 코드를 작성할 때마다 어디서 오류가 났는지 항상 print 구문으로 디버깅을 했었다.
코드가 길어질수록 print() 문을 삭제하고 주석처리하는... 노가다를 반복하다가 뒤늦게 로깅을 알게 되었다.

 

print() 구문보다 어려워보이지만?

익숙해지면 쉽다. 익혀보자.

* 참고
https://docs.python.org/ko/3/library/logging.html#
Django로 배우는 쉽고 빠른 웹 개발, 김석훈 한빛 미디어

---

로깅(logging)

로그(log)를 기록하는 행위를 말한다.

로그(log): 📜통나무 파일

과거 항해일지를 통나무에 기록했다하여 log(book)의 개념이 나왔는데, 컴퓨터 영역에도 이 개념이 확장되면서 운영 체제나 소프트웨어 실행 중 발생하는 정보 전반을 기록한 파일을 뜻하게 되었다.

파이썬의 로깅 모듈

로깅을 알기 위해서는 로깅 시스템을 구성하는 4가지 핵심 컴포넌트의 역할과 관계를 알아야 한다.
파이썬의 로깅은 로거, 핸들러, 필터, 포맷터 4가지 요소로 이루어져 있다.

 

1. 로거

• 로거(logger)는 로깅 시스템의 시작점으로, 로그 메시지를 처리하기 위해 메세지를 담아두는 저장소
• 모든 로거는 이름과 로그 레벨을 갖는다.
• 로그 레벨: 로그 메세지의 심각성에 따라 자신이 어느 레벨 이상의 메세지를 처리할지에 대한 기준

파이썬 로그 레벨

아래 프로그램을 실행해보면 debug와 info를 제외한 로그가 출력되는 것을 볼 수 있다. 이는 추가 설정을 하지 않으면 기본 로깅 레벨인 warning 이상의 심각도에 대해서만 로그가 남기 때문이다.

logging의 레벨 변경

logging.basicConfig(level=logging.level)로 로거 기본 모듈(root logger) 설정을 변경이 가능하다.

 

로그 레벨 비교
1) 로거에 저장되는 메세지를 로그 레코드라 하며, 로그 레코드도 로그 레벨을 갖는다.
2) 메세지가 로거에 도착하면 로그 레코드의 로그 레벨과 로거의 로그 레벨을 비교한다. 로그 레코드의 로그 레벨이 로거 자체의 로그 레벨과 같거나 높으면 메세지 처리를 계속 진행하고, 더 낮으면 그 메세지는 무시된다.
3) 메세지 처리를 진행하는 것으로 결정되면 로거는 메세지를 핸들러에게 넘겨준다.

2. 핸들러

• 로거에 있는 메세지에 무슨 작업을 할지 결정하는 엔진이다.
• 메세지를 콘솔 출력 또는 파일에 저장할 수도 있고, 이메일로 보내거나 외부로 전달시키는 등의 로그 동작을 정의
• FileHandler : 디스크 내 파일에 로깅 메시지를 전달하여 저장
• StreamHandler : 스트림(ex. 콘솔창)에 로그 메시지를 전달해 출력
• 핸들러도 로그 레벨을 갖고 있다.
• 로그 레코드의 로그 레벨이 핸들러의 로그 레벨보다 더 낮으면 핸들러는 메세지 무시
• 로거는 여러 개의 핸들러를 가질 수 있고, 각 핸들러는 서로 다른 로그 레벨을 가질 수 있다.
• 이에 따라 하나의 로그 메세지를 여러 다른 방식으로 처리 가능

ex. ERROR 레벨 메세지: 표준 출력으로 보내는 핸들러 + 파일로 기록하는 핸들러 = 2개의 핸들러 생성 가능

 

• 기본 모듈 설정을 사용해서 로그를 파일로 저장하기

import logging
logging.basicConfig(filename='dummy.txt')

logging.warning('경고')

 

3. 필터

• 로그 레코드가 로거에서 핸들러로 넘겨질 때, 필터를 사용해서 로그 레코드에 추가적인 제어 가능
• ex. 필터를 추가하여 ERROR 메세지 중에서 특정 소스로부터 오는 메세지만 핸들러로 넘길 수 있다.
• 로그 레코드 레벨 수정 가능
• ex. 조건에 맞을 경우, ERROR 로그 레코드를 WARNING 로그 레벨로 낮추는 필터를 만들 수도 있다.

4. 포맷터

• 로그 레코드는 최종적으로 텍스트로 표현되는데, 포맷터는 문자열에 특정 값을 삽입하는 데 사용한다.
• 보통 파이썬의 포맷 스트링을 사용하지만, 사용자 정의 포맷터도 생성 가능
• 기본 모듈 설정의 포맷 스트링으로 %(asctime)s를 사용하여 로그 시간을 추가할 수 있다.

import logging
 
logging.basicConfig(format='(%(asctime)s) %(levelname)s:%(message)s',
                    level=logging.DEBUG)
 
logging.warning('경고')

>> (2022-01-02 11:10:42,616) WARNING:경고

 

📜나만의 로거 모듈 만들기

로그를 기록하기 위해서는 위 설명한 로거, 핸들러, 필터, 포맷터 등을 설정한 후에, 코드 내에서 로깅 메소드를 호출하면 된다. 위에서 logging.warning('경고') 처럼 logging의 함수를 직접 호출하면 파이썬이 미리 만들어 놓은 디폴트 설정의 루트 로거가 실행되지만, 자신 만의 로거를 따로 만들어서 사용하는게 일반적이다. 또한 로그 시간을 추가하는 등의 기본 모듈 설정인 basicConfig은 여러번 실행해도 가장 처음 호출된 설정만 유효하고, 나머지는 설정이 적용되지 않는다. 따라서 나만의 로거 객체를 만들어 사용한다.

 

1) logging.getLogger( )메소드를 호출하면 로거 객체를 만들 수 있다.

import logging

# logging 모듈 사용해서 나만의 로거 객체 생성
mylogger = logging.getLogger('firstlogger')

# 내 로거 객체에 레벨 지정
mylogger.setLevel(logging.DEBUG)

# 파일 핸들러 객체 생성
file_handle = logging.FileHandler("./mylog.txt")

# 스트림 핸들러 객체 생성: 스트림(ex. 콘솔창)에 로그 메시지를 전달해 출력
stream_handle = logging.StreamHandler()

# 내 로거 객체에 핸들러 객체 적용
mylogger.addHandler(file_handle)
mylogger.addHandler(stream_handle)

mylogger.debug('서버 시작')

>>> 서버 시작

 

생성한 Logger를 설정하는 주요 method들은 아래와 같다.

• Logger.setLevel() : 처리할 메시지의 최소 레벨을 설정
• Logger.addHandler(), Logger.removeHandler() : Handler 객체를 추가하고 제거
• Logger.addFilter(), Logger.removeFilter() : Filter 객체를 추가하고 제거

 

2) 포맷터를 이용하여 출력하기

import logging

# logging 모듈 사용해서 로거 객체 생성
mylogger = logging.getLogger('firstlogger')

# 내 로거 객체에 레벨 지정
mylogger.setLevel(logging.DEBUG)

# 포맷터 설정
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')

# 파일 핸들러 객체 생성
file_handle = logging.FileHandler("./mylog.txt")

# 스트림 핸들러 객체 생성: 스트림(ex. 콘솔창)에 로그 메시지를 전달해 출력
stream_handle = logging.StreamHandler()
stream_hander.setFormatter(formatter)

# 내 로거 객체에 핸들러 객체 적용
mylogger.addHandler(file_handle)
mylogger.addHandler(stream_handle)

mylogger.debug('서버 시작')

>>> 2022-01-02 14:05:59,370 - firstlogger - DEBUG - 서버 시작

 

asctime 시간

name 로거이름
levelname 로깅레벨 
message 메세지 

 

로거 이름 계층화

모듈 단위로 로그를 기록하고 싶으면, 로거를 구분하는 이름을 도트( . ) 방식으로 명명해주면 된다.

logging.getLogger('mylogger') 메소드로 로거 객체를 만들었는데 매개변수 없이 메소드를 호출하면,

logging.getLogger()

루트 로거를 생성하게 된다. 이처럼 루트 로거(최상위 로거)를 만들면 루트 로거에서 핸들러 하나만 만들어도 하위 로거가 보내주는 모든 로그 메세지를 잡을 수 있게 된다.

import logging

# main.py
# 최상위 루트 로거 객체 생성
rootlogger = logging.getLogger()
rootlogger.setLevel(logging.INFO)

formatter = logging.Formatter('%(levelname)s: %(message)s')

stream_handle = logging.StreamHandler()
stream_handle.setFormatter(formatter)
rootlogger.addHandler(stream_handle)

# /mylogger.py
# my 로거 객체 생성
mylogger = logging.getLogger('my')
mylogger.info('my logger의 메세지')

>>> INFO: my logger의 메세지

위의 예시처럼 'my' 로거에 별도의 핸들러 설정을 하지 않았지만, 루트 로거로 전파(propogate)되어 콘솔에 출력.

 

모듈 별로 로깅 레벨을 다르게 설정하여 로그를 남길 수도 있다. 도트( . ) 방식에 의해 'parent.child' 로거의 로그 메세지는 'parent' 로거로 전파되고, 이는 다시 최종적으로 최상위 로거로 전파된다. 따라서 'parent' 로거와 'parent.child' 로거가 남기는 로그는 최상위 로거에 연결되어 있는 두 개의 핸들러에 의해서 처리되는 것이다.

parent_logger = logging.getLogger("parent")
parent_logger.setLevel(logging.DEBUG)

child_logger = logging.getLogger("parent.child")
child_logger.setLevel(logging.WARNING)

 

(편의상 한 모듈에 모든 로거를 작성했지만, 실제로는 각기 다른 모듈에서 작성되었다고 가정)

import logging

# 최상위 루트 로거 객체 생성
rootlogger = logging.getLogger()
rootlogger.setLevel(logging.INFO)

formatter = logging.Formatter('%(levelname)s: %(message)s')

stream_handle = logging.StreamHandler()
stream_handle.setFormatter(formatter)
rootlogger.addHandler(stream_handle)

# 부모 로거
parent_logger = logging.getLogger("parent")
parent_logger.setLevel(logging.INFO)

# 자식 로거
child_logger = logging.getLogger("parent.child")
child_logger.setLevel(logging.DEBUG)

parent_logger.info('정보')
child_logger.debug('디버그')

>>> INFO: 정보
    DEBUG: 디버그

 

자식 로거에도 핸들러 설정하고 싶으면, 해당 로거의 propogate 속성을 False로 설정하여 부모 로거로의 전파를 차단하면 된다. 기본적으로 propogate가 True라서 핸들러를 중복 연결하면 같은 메세지를 여러 번 출력할 수 있습니다.

파이썬 공식 문서에 따르면 일반적으로 최상위 루트 로거에만 핸들러를 만들고, 부모 로거로의 전파를 통해 모든 자식 로거들의 메세지를 처리하도록 한다.

 

장고에서의 로깅 설정

장고에서는 항상 로깅이 가능한 상태이므로, 로그가 필요한 시점에 로거를 취득하고 로깅 메소드를 호출하면 된다. settings.py 파일에 LOGGING 항목을 지정하지 않으면 장고는 디폴트 로깅 설정을 사용한다. 이것을 그대로 사용하는 경우는 많지 않고, settings.py의 LOGGING 항목에 기존의 디폴트로 설정된 로거들을 오버라이딩하여 핸들러, 필터, 포맷터 등 동작을 변경하는 방법을 많이 사용한다.

# mypage/settings.py

#
LOGGING = {
    'version': 1,
    # 기본 디폴트는 True이며, True로 유지하면 기존 로거들을 비활성화한다. 장소에서는 False를 권장
    'disable_existing_loggers': False,
    
    # 메세지만 출력하는 포맷터와 상세 정보까지 출력하는 포맷터 두 개로 생성 가능
    'formatters': {
    	'basic_content': {'format': '%(message)s'},
        'detail_content': { 'format': '%(asctime)s %(levelname)s [%(name)s] %(message)s'},
    	}
    
    'handlers': {
    	# --------------- 파일 핸들러 정의 ---------------
    	'file': {
       	    'level': 'ERROR',
            'class': 'logging.FileHandler',
            # BASE_DIR은 settings.py 파일이 위치한 폴더로, BASE_DIR/logs/mypage.log에 저장
            'filename': os.path.join(BASE_DIR, 'logs', 'mypage.log'),
            # 포맷터 지정
            'formatter': 'basic_content'},
        # ---------------- 콘솔 출력 핸들러 정의 ---------------
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'detail_content'}
    	},
    
    # 로거 생성
    'loggers': {
    	# 디폴트로 설정된 장고 로거인데, 핸들러와 로거 레벨 오버라이딩하여 동작 방식 변경
    	'django': {
            'handlers': ['file', 'console'],
            'level': 'WARNING'},
        
        # 나만의 로거 설정 정의, DEBUG 이상의 메세지를 file 핸들러에게 보냄
        'parent': {
            'handlers': ['file'],
            'level': 'DEBUG'},
        # 핸들러를 지정하지 않으면, 장고의 file, console 디폴트 핸들러 동작
        'parent.child': {
            'level': 'DEBUG'},    
    	},
}