한빛출판네트워크

나는 개발자 경력을 자바 개발자로 시작했다. 제일 먼저 배운 메서드는 main 메서드이고 그 다음으로 배운건 System.out.println이다.
그러다가 log4j라는 고마운 녀석을 알게되어서 별 생각없이 log4j만 열심히 쓰다가, 여러 로깅모듈을 하나의 인터페이스로 모아주는 slf4j를 살짝 만져보다가 nodejs로 전향해서 엄청나게 삽질을 해댄 경험이 있다.

지금은 개발 메인언어는 nodejs이고 프로젝트 빌드 및 배포는 chef + fabric으로 하고 있고, 서브 스크립트 언어로 python과 shell을 사용하고 있다. 그중에 스케줄러로 돌아가는 파이썬 스크립트를 만들게 되었는데, 이 녀석이 돌다가 에러가 났을 때 print 메서드 만으로는 이게 실행이 됐는지 죽었는지 확인할 길이 없었다. 그래서 파이썬 로깅 모듈을 찾아봤다.



어라?! 제일 위에 표준 라이브러리가 나온다.
뭔가 내용이 많은데, 표준라이브러리 내용이 읽기 부담 스러운 분은 이 글을 읽으면 조금 도움이 될지도 모르겠다.
일단, 로깅 라이브러리라고 하면, 쉽게 말하면 로그를 찍는 기능이 기본이고, 두번째는 여러군데에 찍는 것이고 (예를 들어 아웃풋 스트림에 찍고, 파일로 찍고), 세번째는 이쁘게 찍는 것이다.

그래서 내가 원하는 기능이 있는지 찬찬히 살펴보았다. 필요한 기능은 아래와 같았다.

• 스트림과 파일에 동시에 로그를 남긴다.
• 로그를 찍은 시간과 어디에서 로그를 남겼는지 남아야 한다.
• 테스트 환경과 프로덕션 환경에서 남기는 로깅 레벨이 달라야 한다.
• 파일에 남기는 경우, 파일의 크기가 너무 크면 자동으로 하나 더 만들어 주면 좋겠다.
• 확장이 쉬우면 좋겠다.

 

일단 결론만 말하면 위에 말한거 전부 다 된다. 기본 모듈이 이정도라니 정말 놀랍다.
차근 차근 한번 알아보자.

스트림과 파일에 동시에 로그를 남기기 

 

print 메서드로만 로그를 찍어왔다면, 이제 기본 탑재된 logging 모듈을 한 번 사용해 보자.

import logging

 

logging.info("I told you so")

logging.warning("Watch out!")

 

위의 코드를 실행하면 아래와 같이 나오는데, 그 이유는 logging의 기본 로그 레벨이 WARNING으로 되어 있기 때문이다.

WARNING:root:Watch out!

 

로그를 전부다 WARNING으로 찍을 수는 없으니 살짝만 건드려 보자.

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:심각한 에러!!

 

로깅 레벨도 지정해 봤으니 파일로도 남겨보자.

import logging

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

 

logging.info("=========================================")

logging.info("파일에다가 남겨봐요~")

logging.info("=========================================")

logging.debug("디버깅용 로그~~")

logging.info("도움이 되는 정보를 남겨요~")

logging.warning("주의해야되는곳!")

logging.error("에러!!!")

logging.critical("심각한 에러!!")

 

 

위의 코드를 실행하면 실행한 폴더에 test.log라는 파일이 생기고 그 파일을 열어보면 아래와 같이 로그가 파일로 남는다. 여러번 실행하면 파일을 덮어 쓰는 것이 아니라, 기존의 로그에 이어서 붙이기를 하게된다.

INFO:root:=========================================

INFO:root:파일에다가 남겨봐요~

INFO:root:=========================================

DEBUG:root:디버깅용 로그~~

INFO:root:도움이 되는 정보를 남겨요~

WARNING:root:주의해야되는곳!

ERROR:root:에러!!!

 

그럼 이제 원래 하고 싶었던 걸 해보자.

아웃풋 스트림에도 찍어봤고, 파일로도 남겨 봤는데 둘다 동시에 남길려면 어떻게 해야되지? 라는 질문이 생기는데, 둘다 로그를 남길려면 logging.getLogger("로거이름") 이라는 메서드로 얻을 수 있는 logger라는 녀석을 사용해야한다. 

 

logger를 써서 여러군데로 로그를 남기는 것에 대해 간단하게 단계를 설명하면 아래와 같다. 

 

1. 로거 인스턴스를 만든다.

2. 스트림과 파일로 로그를 출력하는 핸들러를 각각 만든다.

3. 1번에서 만든 로거 인스턴스에 스트림 핸들러와 파일핸들러를 붙인다.

4. 로거 인스턴스로 로그를 찍는다. 

 

말로 설명해 봤으니 코드를 보자.

import logging

import logging.handlers

 

# 1. 로거 인스턴스를 만든다

logger = logging.getLogger('mylogger')

 

# 2. 스트림과 파일로 로그를 출력하는 핸들러를 각각 만든다.

fileHandler = logging.FileHandler('./myLoggerTest.log')

streamHandler = logging.StreamHandler()

 

# 3. 1번에서 만든 로거 인스턴스에 스트림 핸들러와 파일핸들러를 붙인다.

logger.addHandler(fileHandler)

logger.addHandler(streamHandler)

 

# 4. 로거 인스턴스로 로그를 찍는다.

logger.setLevel(logging.DEBUG)

logger.debug("===========================")

logger.info("TEST START")

logger.warning("스트림으로 로그가 남아요~")

logger.error("파일로도 남으니 안심이죠~!")

logger.critical("치명적인 버그는 꼭 파일로 남기기도 하고 메일로 발송하세요!")

logger.debug("===========================")

logger.info("TEST END!")

 

위의 코드를 실행시켜 보면 콘솔과 파일에 각각 아래와 같은 로그가 남는다.

===========================

TEST START

스트림으로 로그가 남아요~

파일로도 남으니 안심이죠~!

치명적인 버그는 꼭 파일로 남기기도 하고 메일로 발송하세요!

===========================

TEST END!

 

 

로그를 찍은 시간과 어느 파일의 어느 라인에 심어 놓은 로그인지 남기기 

 

로그의 포매팅에 관한 이야기인데, 이 부분도 파이썬을 개발하는 분들이 이미 표준 logging 모듈에 심어두셨다. 위에서는 핸들러를 알아봤다면 이번에 알아볼 녀석은 포매터라는 녀석이다. 내가 알고 싶은건 날짜와 시간, 파일명, 로그레벨, 메세지 이정도가 되겠다. 코드를 만드는 단계를 설명안 해도 될정도로 엄청 간단하므로 그냥 코드로 바로 알아보도록하자.

 

import logging

import logging.handlers

 

# 로거 인스턴스를 만든다

logger = logging.getLogger('mylogger')

 

# 포매터를 만든다

fomatter = logging.Formatter('[%(levelname)s|%(filename)s:%(lineno)s] %(asctime)s > %(message)s')

 

# 스트림과 파일로 로그를 출력하는 핸들러를 각각 만든다.

fileHandler = logging.FileHandler('./myLoggerTest.log')

streamHandler = logging.StreamHandler()

 

# 각 핸들러에 포매터를 지정한다.

fileHandler.setFormatter(fomatter)

streamHandler.setFormatter(fomatter)

 

# 로거 인스턴스에 스트림 핸들러와 파일핸들러를 붙인다.

logger.addHandler(fileHandler)

logger.addHandler(streamHandler)

 

# 로거 인스턴스로 로그를 찍는다.

logger.setLevel(logging.DEBUG)

logger.debug("===========================")

logger.info("TEST START")

logger.warning("스트림으로 로그가 남아요~")

logger.error("파일로도 남으니 안심이죠~!")

logger.critical("치명적인 버그는 꼭 파일로 남기기도 하고 메일로 발송하세요!")

logger.debug("===========================")

logger.info("TEST END!")

 

 

위의 코드를 실행하면 아래와 같이 나온다.

[DEBUG|loggingFormatter.py:24] 2014-09-02 20:39:46,630 > ===========================

[INFO|loggingFormatter.py:25] 2014-09-02 20:39:46,630 > TEST START

[WARNING|loggingFormatter.py:26] 2014-09-02 20:39:46,630 > 스트림으로 로그가 남아요~

[ERROR|loggingFormatter.py:27] 2014-09-02 20:39:46,630 > 파일로도 남으니 안심이죠~!

[CRITICAL|loggingFormatter.py:28] 2014-09-02 20:39:46,631 > 치명적인 버그는 꼭 파일로 남기기도 하고 메일로 발송하세요!

[DEBUG|loggingFormatter.py:29] 2014-09-02 20:39:46,631 > ===========================

[INFO|loggingFormatter.py:30] 2014-09-02 20:39:46,631 > TEST END!

 

이처럼 포매터의 값만 이리저리 바꿔주면, 내가 원하는 대로 로그를 남길 수 있다!

포매터에 들어가는 변수의 문자열은 여기(logrecord-attributes)에서 확인하길 바란다. 

 

 

테스트 환경과 프로덕션 환경에서 로그 레벨을 다르게 하고 싶을 경우 

 

나는 테스트환경과 프로덕션 환경을 구분하기 위해서 처음에 서버를 세팅할 때 환경변수를 심어놓는다. nodejs모듈에서 사용되는(expressjs) NODE_ENV라는 환경변수명이 있는데 이 값을 미리 테스트 서버와 알파서버, 프로덕션 서버에 각각 다른 값으로 설정을 해둔다. 여기서는 로컬 개발 머신과 테스트 서버만 있다고 가정하고 예제를 만들어봤다.

 

import os

import logging

import logging.handlers

 

# 로거 인스턴스를 만든다

logger = logging.getLogger('mylogger')

 

# 포매터를 만든다

fomatter = logging.Formatter('[%(levelname)s|%(filename)s:%(lineno)s] %(asctime)s > %(message)s')

 

# 환경변수를 읽어서 로깅 레벨과 로그를 남길 파일의 경로를 변수에 저장한다

if (os.environ['NODE_ENV'] == 'local'):

    loggerLevel = logging.DEBUG

    filename = '/tmp/test.log'

elif(os.environ['NODE_ENV'] == 'test'):

    loggerLevel = logging.DEBUG

    filename = '/home/www/log/testServer.log'

else:

    loggerLevel = logging.INFO

    filename = '/home/www/log/server.log'

 

# 스트림과 파일로 로그를 출력하는 핸들러를 각각 만든다.

fileHandler = logging.FileHandler(filename)

streamHandler = logging.StreamHandler()

 

# 각 핸들러에 포매터를 지정한다.

fileHandler.setFormatter(fomatter)

streamHandler.setFormatter(fomatter)

 

# 로거 인스턴스에 스트림 핸들러와 파일핸들러를 붙인다.

logger.addHandler(fileHandler)

logger.addHandler(streamHandler)

 

# 로거 인스턴스로 로그를 찍는다.

logger.setLevel(loggerLevel)

logger.debug("===========================")

logger.info("TEST START")

logger.warning("파일 명과 로깅 레벨을 각각 환경마다 다르게 남도록 했어요.")

logger.debug("디버그 로그는 테스트 환경과 로컬 피씨에서남 남는 답니다.")

logger.critical("치명적인 버그는 꼭 파일로 남기기도 하고 메일로 발송하세요!")

logger.debug("===========================")

logger.info("TEST END!")

 

환경변수 NODE_ENV의 값에 따라 로그가 남는 파일의 경로와 로깅 레벨이 달라졌습니다~ 

 

 

파일로 로그를 남기는 경우 파일이 너무 커지면 자동으로 새로운 파일을 만들어 줬으면… 

 

보통 이런거는 shell 스크립트를 스케줄러로 돌려서 자동으로 돌리거나 하는데, 파이썬에는 RotatingFileHandler라는 놈이 이미 만들어져 있다. 그냥 가져다 쓰면 된다. 정말 감동적인 모듈인듯! 

 

이전에 만들어둔 파일 핸들러를 RotatingFileHandler로 교체해보자. 

 

위에 있는 fileHandler부분만 아래 코드로 교체하면 된다.

fileMaxByte = 1024 * 1024 * 100 #100MB

fileHandler = logging.handlers.RotatingFileHandler(filename, maxBytes=fileMaxByte, backupCount=10)

 

maxBytes 파라메터는 한개의 파일의 최대 바이트 수 이고, backupCount는 몇개까지 백업파일을 남길것인지 세팅하는 파라메터이다. 위의 세팅 대로라면 100MB 짜리 파일을 10개까지 남기겠다. 라는 의미가 된다. 이제 로그 파일의 용량이 엄청나게 커져서 서버에 용량이 부족할까 걱정하지 않아도 된다~ 야호~~! 

눈치가 빠른 사람이라면 logging.handlers 아래에 다른 핸들러들도 많겠구나~ 라는 생각이들것이다. 

logging.handlers 링크를 타고 가보면 많은 핸들러들을 볼 수가 있다. 

어지간한 기능은 다 넣어본것 같은데 기존에 없는 기능을 추가할려면 어떻게 하지?! 

 

 

확장이 쉬우면 좋겠다! 

 

에러가 났을 때 mongodb에 그 정보를 저장했으면 좋겠다! 어떻게 하지? 

 

일단 쉬운 방법은 나보다 똑똑한 사람이 만들어 놓은 것을 쓰면 된다. 요즘 세상이 참 좋은 세상이라 구글로 찾으면 내가 생각한건 다있다. ㅎㅎ 근데 가끔 이렇게 찾아도 내 마음에 쏙~ 안들 수도 있다. 그럴 때는 한번 만들어보는 것도 힘들긴 하지만, 도움이 될 때가 많다. 

 

그런 의미에서 다른분들도 이미 뜬 삽이겠지만, 나도 한삽을 더 해보려고 한다. 진짜 기본기능만 되는걸 하나 만들어보자. 

 

참고로, mongodb 모듈로 pymongo가 설치되어 있어야 한다. pip3 install pymongo로 간단히 설치가능하다.

mongodb도 물론 설치가 되어있어야한다. 해당 내용은 이글과는 크게 관계없으므로 생략하겠다. 

 

핸들러를 만드는 순서는 아래와 같다. 

 

1. mongodb에 로그를 저장할 수 있도록 handler를 만든다.

2. handler는 logging.Handler를 상속하고 emit 메서드를 구현하면된다. 

 

간단히 만들어본 소스는 아래와 같다.

import logging

from pymongo.connection import Connection

from bson import InvalidDocument

 

 

class MongoHandler(logging.Handler):

 

    def __init__(self, db='mongolog', collection='log', host='localhost', port=None, level=logging.NOTSET):

        logging.Handler.__init__(self, level)

        self.collection = Connection(host, port)[db][collection]

 

    def emit(self, record):

        data = record.__dict__.copy()

 

        try:

            self.collection.save(data)

        except InvalidDocument as e:

            logging.error("Unable save log to mongodb: %s", e.message)

 

if __name__ == '__main__':

    MongoHandler('mongolog', 'test')

 

 

테스트용 소스도 만들어보자. 간단히 핸들러를 추가하고 로그를 찍어본다.

import logging

from mongoLogger import MongoHandler

 

if __name__ == '__main__':

    logger = logging.getLogger('mongoTest')

    logger.setLevel(logging.WARNING)

    logger.addHandler(MongoHandler('mongolog', 'log'))

 

    logger.debug("test debug")

    logger.info("test info")

    logger.warning("test warning")

    logger.error("test error")

    logger.critical("test critical")

 

 

실행 후 mongodb에 들어가서 확인을 해보면 아래와 같이 WARNING이상의 로그가 저장되어 있다.

> db.log.find().pretty();

{

    "_id" : ObjectId("5405c2cc1626051dcf238cfa"),

    "stack_info" : null,

    "exc_text" : null,

    "exc_info" : null,

    "processName" : "MainProcess",

    "lineno" : 11,

    "msecs" : 891.3910388946533,

    "relativeCreated" : 50.26507377624512,

    "process" : 7631,

    "name" : "mongoTest",

    "pathname" : "mongoTest.py",

    "created" : 1409663692.891391,

    "filename" : "mongoTest.py",

    "funcName" : "<module>",

    "threadName" : "MainThread",

    "msg" : "test warning",

    "args" : [ ],

    "module" : "mongoTest",

    "levelno" : 30,

    "thread" : NumberLong("140735296762640"),

    "levelname" : "WARNING"

}

{

    "_id" : ObjectId("5405c2cc1626051dcf238cfb"),

    "stack_info" : null,

    "exc_text" : null,

    "exc_info" : null,

    "processName" : "MainProcess",

    "lineno" : 12,

    "msecs" : 891.618013381958,

    "relativeCreated" : 50.492048263549805,

    "process" : 7631,

    "name" : "mongoTest",

    "pathname" : "mongoTest.py",

    "created" : 1409663692.891618,

    "filename" : "mongoTest.py",

    "funcName" : "<module>",

    "threadName" : "MainThread",

    "msg" : "test error",

    "args" : [ ],

    "module" : "mongoTest",

    "levelno" : 40,

    "thread" : NumberLong("140735296762640"),

    "levelname" : "ERROR"

}

{

    "_id" : ObjectId("5405c2cc1626051dcf238cfc"),

    "stack_info" : null,

    "exc_text" : null,

    "exc_info" : null,

    "processName" : "MainProcess",

    "lineno" : 13,

    "msecs" : 891.7689323425293,

    "relativeCreated" : 50.642967224121094,

    "process" : 7631,

    "name" : "mongoTest",

    "pathname" : "mongoTest.py",

    "created" : 1409663692.891769,

    "filename" : "mongoTest.py",

    "funcName" : "<module>",

    "threadName" : "MainThread",

    "msg" : "test critical",

    "args" : [ ],

    "module" : "mongoTest",

    "levelno" : 50,

    "thread" : NumberLong("140735296762640"),

    "levelname" : "CRITICAL"

}

 

 

결론

파이썬에서는 로그를 남기기 위해서 뭘쓸까 고민할 필요가 전혀 없다. 표준 라이브러리가 워낙에 잘되어 있고, 확장 또한 쉽기 때문에 별다른 고민없이 logging 모듈만 잘 공부하면 된다. 나도 필요해서 찾아보고 공부해본 것이지만, 위에서 소개한 것 이외에도 많은 기능들을 가지고 있으므로 아마 거의 대부분의 경우에는 표준 logging 모듈로도 충분할 것으로 생각된다.

관심이 있는 사람은 logging-cookbook 페이지를 참고하도록 하자.

 

 

저자: 박승규(http://gyus.me/), 한빛리더스