print vs logging

보통의 코드 작업에는 에러 발생시 트래킹하기 위한 로그가 필요하다. 

kafka 작업을 하면서 작업 중간중간 로그와 에러발생시 어떤 팟의 어떤 토픽인지 남기는 과정을 print 문으로 진행했다. 그런데 pod log를 살펴보니 timestamp가 꼬이고, 어느정도 메세지가 쌓이지 않으면 print 문이 출력이 되지 않는 현상이 발생했다. 

이는 print 문이 버퍼링이 있기 때문인데 버퍼가 차거나 flush 되기 전까지 출력이 실시간으로 나타나지 않는다. kafka 작업의 특성상 실시간으로 매우 빠르게 메세지들이 소비되는데 이렇게 느린 print문으로는 트래킹이 원활하게 되지 않았다. 

해결

첫시도

처음에는 flush를 활성화하여 해결했다고 생각했지만, 출력이 꼬이는 문제는 해결되지 않았다. print문을 전송해도 나중에 전송된 메세지가 먼저 도착하면 먼저 찍힐 수도 있기 때문에, 첫번째로 출력되어야 할 부분이 다음 작업 출력 후에 나오는 식으로 제멋대로 출력이 됐다. 

logging 사용 

그동안 print문으로도 부족함 없이 사용했어서 logging의 중요성을 잊고 있었다..

logging 모듈은 다음과 같은 장점이 있다. 

• 로깅 레벨 : DEBUG, INFO, WARNING, ERROR, CRITICAL 단계로 나뉘며 중요도에 따라 다르게 로그를 관리 할 수 있다.
• 핸들러와 포매터를 이용한 로그 출력 방식 관리 가능 
• 스레드 안전성 : 스레드 안전 설계가 되어있으므로, 멀티스레딩 환경에서 로그 메세지 처리시 서로 간섭되지 않도록 보장 

일관되고 안정적인 로깅을 위해 print문을 전부 logging 으로 변경하는 작업을 했다. 포매터를 설정해서 [시간 - 로깅 레벨 - 메세지] 순으로 출력이 일어날 수 있도록 만들었고, 로깅레벨은 INFO부터 출력되게 만들었다. 

아래와 같이 함수화 하여 여러 곳에서 동일하게 사용할 수 있도록 만들었다.

def setup_logger(name):
    log = logging.getLogger(name)
    log.setLevel(logging.INFO)

    if not log.handlers:
        console_handler = logging.StreamHandler()
        formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(message)s')
        console_handler.setFormatter(formatter)

        log.addHandler(console_handler)
    return log

이후 pod log를 가보니 설정한 포맷대로 순서 꼬임없이 일정하게 로그가 찍히기 시작했다. 

그동안 로깅과 print를 섞어서 사용하고 있었는데, 이번 기회에 logging의 중요성을 알게 됐고 지금은 보이는 곳마다 logging으로 변경하는 작업을 하고 있다.