파이썬 로깅의 모든것
파이썬 로깅의 모든것
파이썬 로깅에 대한 "모든것은" 사실 낚시구요. ㅎㅎ (유희열이 진행했던 All that music 이라는 라디오 프로그램에서 내가 좋아하는 국악이나 시부야계는 거의 나오지도 않았었다...먼소리야 이게 ;;) 그래도 블로그용으로는 꽤나 많은 정보를 담으려고 애를 썼습니다. 파이썬에서 자체 제공하는 기본 로깅 시스템에 대한 내용이구요. 버전이 올라감에 따라 내용이 달라질수 있으며, 오류도 있을 것이고 더 손쉬운 방법등이 있을 수 있음을 인지하시고 항상 다른것들도 같이 확인 하세요.
본론으로 바로 들어가시죠.
먼저 제가 원하는 로깅 시스템은 이렇습니다. IoT 의 게이트웨이 안에서 활약 할 놈으로써~
logging.conf 파일을 통해서 외부에서 설정 가능
레벨을 자유롭게 설정하고 추가 할 수 있어야 한다.
(CRITICAL, ERROR,INFO, DEBUG )파일,스트림에 동시에 출력 할 수 있어야 한다.
다양한 목적에 따라 다양한 파일에 출력 할 수 있어야 한다.
로깅 시간 출력 및 다양한 정보에 대한 추가가 가능해야 한다.
하루에 한번씩 파일을 생성 해야하며, 지난 파일은 압축하여 보관 해야한다.
하루에 한번씩 파일을 생성 해야하며, 오래된 파일을 삭제 할 수 있어야 한다.
파일 용량이 너무 커질 경우에는 자동으로 분리 시켜야 한다.
멀티프로세스를 활용해야 하는 파이썬의 특성상 멀티프로세스에서도 로그를 취득할 수 있어야 한다.
핸들러를 커스터마이징 할 수 있어야 한다. 즉 콘솔,파일 출력 뿐 만 아니라, DB 및 소켓을 통하여도 발송 할 수 있어야 한다.
사용하기 쉬워야 한다. (문서화가 잘 되 있어야 한다) , 기본 로깅 모듈을 사용해야한다.
이것을 해결 하기 위해 알아야 할 것들에 대해 공부해 보는것이 이 글의 목표 입니다. 즉 이 글을 모두 읽고 나면 모든 기능을 본인의 프로젝트에서 사용 할 수 있게 될 것이라 봅니다.
* 참고로 자바개발자에게 익숙한 log4j 같은 거대한 로깅 시스템에 비하면 제공되는 기능이 조금 부족합니다. 몇가지는 직접만들어야합니다.
* 2.x / 3.x 상관없으나, 몇몇 부분은 2.7 기준입니다. 3.x 버전의 새기능 활용 안함.
초급
print (" 30이 들어왔어")
import logging
if __name__ == '__main__':
logging.error("something wrong!!") 결과: ERROR:root:somthing wrong!!
" 서버의 대기포트는 이 번호로 시작 됬습니다"
" 어떤 함수가 호출 되었어요"
" 100이 들어왔어요"
import logging
if __name__ == '__main__':
logging.info("hello world")
import logging
if __name__ == '__main__':
mylogger = logging.getLogger("my")
나의 로깅 모듈 사용하기 - 2 (레벨 설정)
import logging
if __name__ == '__main__':
mylogger = logging.getLogger("my")
mylogger.setLevel(logging.INFO)
setLevel 메소드를 통해서 INFO 레벨 이상은 출력 하도록 설정 하였습니다. (DEBUG 출력 안함)
나의 로깅 모듈 사용하기 - 3 (핸들러 설정)
import logging
if __name__ == '__main__':
mylogger = logging.getLogger("my")
mylogger.setLevel(logging.INFO)
stream_hander = logging.StreamHandler()
mylogger.addHandler(stream_hander)
mylogger.info("server start!!!") 결과: server start!!!
핸들러란 내가 로깅한 정보가 출력되는 위치 설정하는 것을 말합니다. 위에서는 콘솔을 통해 출력하도록 설정 했지만, 파일,DB,소켓,큐등을 통해 출력 하도록 설정 할 수도 있습니다.
나의 로깅 모듈 사용하기 - 4 (파일 핸들러 설정)
파일로도 동시에 출력하게 해봅시다. 매우 간단합니다.
#!/usr/bin/python
import logging
if __name__ == '__main__':
mylogger = logging.getLogger("my")
mylogger.setLevel(logging.INFO)
stream_hander = logging.StreamHandler()
mylogger.addHandler(stream_hander)
file_handler = logging.FileHandler('my.log')
mylogger.addHandler(file_handler)
mylogger.info("server start!!!")
logging.FileHandler 클래스를 통해 객체를 만들어서 나의 로거에 추가해주면 됩니다. 현재 디렉토리에 파일(my.log)이 만들어 질 것 입니다.
노트: 파일은 a 모드로 열리는게 디폴트입니다. a 모드란 같은 이름의 파일이 이미 있다면, 파일 끝에 추가하여 쓰고, 없다면 쓰기용으로 파일 만들라는 뜻입니다.
나의 로깅 모듈 사용하기 - 5 (출력 포매팅 설정)
server start!!! 라는 메세지 말고도, 이 메세지가 언제 쓰여졌는지, 어떤 모듈에서 쓰여졌는지 등 기타 정보를 같이 출력하고 싶을 것입니다. 이때 포매팅이란 것을 하게 되는데요.
import logging
if __name__ == '__main__':
mylogger = logging.getLogger("my")
mylogger.setLevel(logging.INFO)
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
stream_hander = logging.StreamHandler()
stream_hander.setFormatter(formatter)
mylogger.addHandler(stream_hander)
file_handler = logging.FileHandler('my.log')
mylogger.addHandler(file_handler)
mylogger.info("server start!!!") 결과: 2017-08-07 12:00:29,141 - my - INFO - server start!!!
포매팅에 추가한 정보를 모든 로그 데이터에 추가해서 출력하게 됩니다.
asctime 시간
name 로거이름
levelname 로깅레벨
message 메세지
이것 말고도 모듈이름, 파일이름, 출력라인넘버등 다앙하게 많으니, 더 많은 정보는 메뉴얼을 참고 하시구요. 위에서는 포매터를 콘솔출력에 한정해서 적용했기에 파일은 기존 그대로 출력 될 것입니다. 파일도 포매팅되게 하고 싶으면 역시 포매터를 파일 핸들러에도 추가하세요.
중급
로깅 모듈 생성에 관한 고찰
그냥 매개변수 없이 logging.getLogger() or logging.getLogger("") 이렇게 만들 수도 있습니다.
* logging.error() 를 직접 호출하면 내부에서 루트로거를 이용합니다.
로깅 모듈 생성 실제 - 로거 범위
보통 main 에서 로깅 시스템 (대표설정) 을 만들어서 사용하게 됩니다. 이것을 디폴트로 자식 로거들에서 사용하게 되며, 자식별로 필요하면 특정 설정을 하게 됩니다. 또한 핸들러는 버퍼링을 하고 있기 때문에 어플리케이션이 갑자기 중지되기 전에 logging.shutdown() 을 호출해서 모두 출력해 주면 좋습니다. (fianllly 절에서 수행)
이제 로거를 만드는 대표적인 범위를 살펴보시죠.
# 루트 로거 생성 rootlogger = logging.getLogger()
rootlogger.setLevel(logging.INFO)
stream_hander = logging.StreamHandler()
rootlogger.addHandler(stream_hander)
# "my" 로거 생성
mylogger = logging.getLogger("my")
mylogger.setLevel(logging.INFO)
stream_hander2 = logging.StreamHandler()
mylogger.addHandler(stream_hander2)
# "my" 로거 생성
mylogger.info("message from mylogger")
이것을 막으려면, 간단하게는 루트로거에서 핸들러를 추가해 주지 않아도 되며, 혹은
mylogger.propagate = 0{
"version": 1,
"formatters": {
"simple": {
"format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
}
},
"handlers": {
"console": {
"class": "logging.StreamHandler",
"level": "INFO",
"formatter": "simple",
"stream": "ext://sys.stdout"
},
"info_file_handler": {
"class": "logging.FileHandler",
"level": "DEBUG",
"formatter": "simple",
"filename": "info.log"
}
},
"root": {
"level": "DEBUG",
"handlers": ["console", "info_file_handler"]
}
}
파일핸들러를 통해서 info.log 파일에 DEBUG 레벨 이상일 경우 출력합니다. 저것을 실제 서비스시 INFO로 바꾸면 디버깅 출력은 disable 되겠죠.
import logging
import logging.config
import json
import os
if __name__ == '__main__':
with open('logging.json', 'rt') as f:
config = json.load(f)
logging.config.dictConfig(config)
logger = logging.getLogger()
logger.info("test!!!")
"loggers": {
"my_module": {
"level": "ERROR",
"handlers": ["console"],
"propagate": "no"
}
},
class LoggerAdapter(logging.LoggerAdapter):
def __init__(self, prefix, logger):
super(LoggerAdapter, self).__init__(logger, {})
self.prefix = prefix
def process(self, msg, kwargs):
return '[%s] %s' % (self.prefix, msg), kwargs
if __name__ == '__main__':
with open('logging.json', 'rt') as f:
config = json.load(f)
logging.config.dictConfig(config)
logger = logging.getLogger("")
logger = LoggerAdapter("SAS", logger)
logger.info("test!!!") 결과: 2017-08-07 12:54:55,911 - root - INFO - [SAS] test!!!!
CRITICAL = 50
FATAL = CRITICAL
ERROR = 40
WARNING = 30
WARN = WARNING
INFO = 20
DEBUG = 10
NOTSET = 0
logging.addLevelName(15, "DATA")
logging.DATA = 15
logger.log(logging.DATA, "message")
import logging
import threading
import time
def worker(arg):
while not arg['stop']:
logging.debug('Hi from myfunc')
time.sleep(0.5)
def main():
logging.basicConfig(level=logging.DEBUG, format='%(relativeCreated)6d %(threadName)s %(message)s')
info = {'stop': False}
thread = threading.Thread(target=worker, args=(info,))
thread.start()
while True:
try:
logging.debug('Hello from main')
time.sleep(0.75)
except KeyboardInterrupt:
info['stop'] = True
break
thread.join()
if __name__ == '__main__':
main()
import Queue
import threading
import traceback
import logging
import sys
class QueueListener(threading.Thread):
def __init__(self, queue, stream_h):
threading.Thread.__init__(self)
self.queue = queue
self.daemon = True
self.logger = logging.getLogger("main")
self.logger.addHandler(self.handler)
def run(self):
while True:
try:
record = self.queue.get()
self.logger.callHandlers(record)
except (KeyboardInterrupt, SystemExit):
raise
except EOFError:
break
except:
traceback.print_exc(file=sys.stderr)
class QueueHandler(logging.Handler):
def __init__(self, queue):
logging.Handler.__init__(self)
self.queue = queue
def emit(self, record):
self.queue.put(record)
if __name__ == '__main__': # 리스터 부분
logging_q = Queue.Queue(-1)
stream_h = logging.StreamHandler()
log_queue_reader = QueueListener(logging_q,stream_h)
log_queue_reader.start()
# 핸들러 부분
handler = QueueHandler(logging_q)
root = logging.getLogger()
root.addHandler(handler)
# 사용
root.error("queue handler test!!")
큐 생성)
큐에 데이터를 담아줄 QueueHandler 를 만듭니다. 핸들러는 기본적으로 emit 메소드를 가지고 있어서 이 메소드를 통해서 log 정보를 (LogRecord 객체) 콘솔로 쏴주거나, 파일로 쏘게 됩니다만, 여기서는 큐에 데이터를 넣습니다.
실제 처리를 담당할 핸들러를 위에서는 스트림 핸들러를 만들어서 매개변수로 넣어주었습니다.
위에서는 쓰레드를 사용했지만, 멀티프로세싱을 통해서 할 수도 있으며, 이 방식은 파이썬에서 문제가 되는 멀티프로세싱 로깅을 해결 할 수 있는 실마리를 제공해줍니다. 이 부분은 고급에서 배우게 될 것입니다.
이전 로그파일을 압축하려고 할 때 우리는 , 압축 할 파일을 잠시 close 하고 압축을 하게 되는데, 윈도우즈에서는 압축이 안되는 현상 및 기존 로그 파일을 날짜가 붙은 새로운 이름으로 변경 하러 할 때도 안되는 현상이 있다.이것은 다른 프로세스에서 그 로그파일을 열고 있기 때문인데 우분투에서는 잘되었다. 아마 파일 디스크립터는 다르기 때문으로 추정한다. 아무튼 운영체제별 이런 차이들이 있어서 좀 골치 아프다. 마지막으로 멀티프로세스 환경의 로깅에서는 각각 따로 쓰면 파일에 써지지 않기 때문에 멀티프로세스용 큐를 이용하여 하나로 모아서 파일에 쓰게 되는 것을 보게 될 것이다.
윈도우)
- 2개의 프로세스에서 하나의 파일에 쓰기를 할 경우 윈도우는 예측 불가능이고 (하나의 프로세스 것만 써질 수도 있고, 부분 누락이 되며 순서대로 써질 수도 있고)
- 파일 삭제는 불가능
- 압축파일에 파일 옮겨 쓰는것은 예측 불가하다.
- 다만 하나의 프로세스에서 파일을 close 하면 ,그 이후로 다른프로세스의 데이터는 파일에 써지며, close 한 프로세스에서 쓴 데이터의 일부는 압축도 된다.
리눅스)
- 2개의 프로세스에서 하나의 파일에 쓰기를 할 경우 리눅스는 하나의 프로세스 것만 써진다.
- 파일 삭제는 가능하다.
- 압축파일로 옮겨 쓰는 것도 가능하다. 다만 파일을 close 해주고 해야한다. 물론 메인프로세스에서 쓴 내용만 압축된다.
고급
* 용량 넘어선 로깅파일 나누기
https://github.com/Clivern/pylogging
그래도 먼가 많은 기능들이 다 있으며, 표준처럼 활용하는 멋진 로깅라이브러리가 없는건 아쉽네요.
레퍼런스)
https://docs.python.org/3/howto/logging-cookbook.html#logging-to-a-single-file-from-multiple-processes
https://fangpenlin.com/posts/2012/08/26/good-logging-practice-in-python/
https://stackoverflow.com/questions/8467978/python-want-logging-with-log-rotation-and-compression
https://www.amazon.com/Mastering-Object-oriented-Python-Steven-Lott/dp/1783280972/ref=sr_1_2?ie=UTF8&qid=1501725014&sr=8-2&keywords=mastering+python