python logging으로 매일 log 만들기 (backupcount 설정 했는데 안 지워 질 때 해결법)

 

로그를 남기는 방법은 여러가지인데,

(매일마다 처리하려고 하니, 스크립트로 만들어서 크론탭 등록, python 로그 파일 없으면 만들고 있으면 거기다 붙여넣는 식으로)

 

python3에 있는 logging을 사용해서 해보려고 한다.

 

logging이란?

 

 

일단 로그(log)란, 내가 한 것에 대한 ‘기록’으로 일기와 다름없다. 요즘 유행하는 vlog처럼 내가 오늘 뭘했는지 기록하는 것이다.

IT에서 log란 소프트웨어 실행 중에 발생하는 이벤트 등을 기록한 것이다. 이러한 로그를 기록하는 행위는 로깅(logging)이라고 한다.

 

물론 vlog를 하고 싶어서 하는 사람도 있고 안하고 싶어서 안하는 사람들도 있는 것처럼

개발하면서 확인하고 싶으면 로그 남기는 것이고, 중요하지 않고 안해도 되면 안남기는 것이다.

일반적으로 log는 서버단에서 제대로 동작하는 지 찍어보는 용도로 많이 사용한다.

어떤 형식으로든지 log를 출력하고 싶을 때 사용하는데, 이를 커스터마이징 해서 원하는 대로 설정해서

로그를 찍을 수 있다.

 

 

 

logging level

 

로깅 레벨은 크게 5개인데, 다음 표와 같다.

해당 사항은 python logging에 대한 공식문서(https://docs.python.org/ko/3/howto/logging.html)를 참고했다.

레벨	설명
DEBUG	상세한 정보로, 일반적인 문제를 진단할 때만 사용
INFO	예상대로 작동하는 지에 대한 확인 (이걸 주로 씀)
WARNING	예상치 못한 일이 발생했거나 가까운 미래에 발생할 문제(예를 들어 ‘디스크 공간 부족’)에 대한 표시. 그러나 소프트웨어는 예상대로 작동함.
ERROR	어떤 심각한 문제로 인해, 소프트웨어가 일부 기능을 수행하지 못함
CRITICAL	심각한 에러로, 프로그램 자체가 계속 실행되지 않을 수 있음을 나타냄

 

 

Handler 종류 및 사용법

 

1. StreamHandler

- Console에 log를 바로 확인하기 위해 사용

ex) logging.StreamHandler()

 

2. FileHandler

- log를 지정한 파일에 계속 출력하고 싶을 때 사용

ex) FileHandler('./log', mode = "w")

3. RotatingFileHandler

- 로그 파일 용량을 정해서 log를 쌓고 제거할 때

ex)

RotatingFileHandler(
    filename,	        	# ~~.log / ~~.txt
    mode='a',			# a : append / w : overwrite
    maxBytes=0,			# 한 파일당 몇 byte까지 만들 것인지
    backupCount=0,		# 몇 개의 파일을 backup 할 것 인지
    encoding=None, 		# 인코딩, 만약 한글이 깨진다면 utf-8로 설정한다.
    delay=False
)

 

4. TimedRotatingFileHandler

- 시간과 기간을 정해서 log를 쌓고 제거할 때 + log파일 몇 개까지 제한으로 두고 하고 싶을 때

 

* 만약 backup이 3이면 3개 까지 있다가 한 번 실행했을 때, 날짜가 다음날로 바뀌어서 새로운 로그파일을 만든다고 하면

지금 기점으로 가장 이전에 만들어진 파일부터  바뀐다.

* LRU(Least Recently Used Algorithm) 알고리즘 처럼 가장 최근에 사용되지 않은 (말그대로 현재 기점으로 가장 최근에 사용되지 않았다면 가장 오래된 것을 의미). 것을 바꾼다는 것이다.

 

ex)

TimedRotatingFileHandler(
    filename,		# ~.log ~.txt
    when='h',		# 언제까지 log를 쌓을지, h = 시간, m = 분, s = 초
    interval=1,		# 위에서 h로 설정했으니까 1이면 1시간 2면 2시간
    backupCount=0,	# backupfile을 몇개까지 만들지
    encoding=None,	# 한글 깨지면 utf-8
    delay=False,
    utc=False,
    atTime=None 	# when w0~w6 일 때 시간 기록법
)

python TimedRotatingFileHandler의 interval 유형에 따른 롤오버

제일 중요한게 있는데,, 이말이 가장 중요하다.

내가 테스트 하려고 when='m', interval=1로 해서 로그파일 만들고 backupcount 3으로 설정했다.

그럼 세 번째까지 생성된 로그파일은 있어야 하고 네 번째 돌 때, 첫 번째로 생성된 로그파일이 지워져야 한다.

근데 안없어지더라..!!!!ㅠㅠㅠ 

방법을 찾아보면서, 공식문서의 중요성을 깨달았다...ㅠㅠ아래에 정리했으니 참고 부탁드린다.

 

 

 

logging 사용법 - 파일 생성 과정

 

logging 사용법은 순서에 따르면 다음과 같다.

1. logger 객체 생성
2. log fomatter 생성 (로그가 출력될 때, 시간과 확인하고 싶은 이벤트의 출력 형식을 지정해 주는 것)
3. handler 생성 + formatter 등록
4. logger 객체에 handler 등록 (handler는 여러개 등록이 가능)

 

내코드
TimedRotatingFileHandler(
    filename=dir_log+'test.log', 
    when='midnight', 
    interval=1, 
    backupCount=7, 
    encoding='utf-8'
)

#############################################

log_dir = "경로"
# 로그 객체에 handler 등록
mylogger = logging.getLogger()
# 위험 레벨 등록
mylogger.setLevel(logging.INFO)
# fomatter 생성
formatter = logging.Formatter('[%(asctime)s] %(message)s')
# handler 생성 및 fomatter 등록
rotate_handler = logging.handlers.TimedRotatingFileHandler(filename=log_dir+'test.log', when='midnight', interval=1, backupCount=2, encoding='utf-8')
rotate_handler.suffix = "log-%Y%m%d"
rotate_handler.setFormatter(formatter)
mylogger.addHandler(rotate_handler)

 

[실행 결과]

rotate_handler.suffix = "log-%Y%m%d"는

예를 들어 위의 코드처럼 when=midnight, interval = 1이라면

첫 번째 실행에 따른 로그는 test.log로 된다.

두 번째 실행에 따른 로그는 test.log가 되고, 첫 번째 실행에 따른 로그가 test.log -> test.log-log20220318

세 번째 실행에 따른 로그는 test.log가 되고, 두 번째 실행에 따른 로그가 test.log -> test.log-log20220319가 된다.

이렇게 바뀐다는 것이다. 로그 파일이 생성된 시간은 그대로 두고, 파일 명만 바뀌는 것이다.

 

처음에 이해가 안됐는데, 1분마다 돌리는 것으로 해보니 그런 것이었다..

 

 

logging backupcount 설정 했는데 안 지워 질 때 해결법

 

아무리해도 계속 시간 지났는데 안지워지길래, stackoverflow에 확인했다.

why TimedRotatingFileHandler does not delete old files?

 

아.. 이래서 공식문서가 중요한 것이었다... 나는 간과하고 지나갔는데 저게 핵심이었다??ㅠㅠ

 

시스템은 파일 이름에 확장자를 추가해서 오래된 로그 파일을 자체적으로 저장한다.

양식은 %Y-%m-%d_%H-%M-%S 형식으로 저장한다.

다만, 테스트 하다보니, when에 따라 뒤에 붙는 날짜 형식은 유동적이며 이 날짜로 백업시스템을 관리한다.

when	strftime 형식
s(초)	%Y-%m-%d_%H-%M-%S
m(분)	%Y-%m-%d_%H-%M
h(시)	%Y-%m-%d_%H
d(일)	%Y-%m-%d
midnight(자정)	%Y-%m-%d

 

내가 따로 날짜나 시간을 입력해주지 않아도, 시스템에서 내가 정한 시간 대에 돌게 될 때 

바로 전 타임의 시간을 파일명에 추가한다.

 

 

 

예를 들어, 아래를 기준으로 하면
backup = 2, 분마다, 간격은 2분으로 설정하면, 2분 이후 실행시
1. 로그가 2개 이상이면 backupcount =2이니까 가장 오래된거 지움
2. 2분 지났을 때 돌리면 롤오버 진행, 로그가 2개 이상이면 backupcount =2이니까 가장 오래된거 지움
3. 2분 지나지 않았을 때 돌리면 그 파일 그대로에서 로그 찍혀서 나옴. 롤오버 되지 않음, backupcount도 세지 않음

log_dir = "경로"
mylogger = logging.getLogger()
mylogger.setLevel(logging.INFO)
formatter = logging.Formatter('[%(asctime)s] %(message)s')
rotate_handler = logging.handlers.TimedRotatingFileHandler(
filename=dir_log+'test.log', when='M', interval=2, backupCount=2, encoding='utf-8'
)
rotate_handler.setFormatter(formatter)
mylogger.addHandler(rotate_handler)

[실행 결과]

- 최초 생성 -> test.log파일로 생성(10시)

- 2분 뒤 -> test.log -> test.log.2022-03-21_10-00 로 바뀌고 10시 2분에 실행한 새로운 test.log파일이 생성

- 2분 뒤 -> test.log -> test.log.2022-03-21_10-02 로 바뀌고 10시 4분에 실행한 새로운 test.log파일이 생성

- 2분 뒤 -> backupcount가 2이니까, 가장 오래된 로그를 지운다.

test.log.2022-03-21_10-00가 가장 오래됐으니 지우고, test.log -> test.log.2022-03-21_10-04로 바뀌고 

10시 6분에 실행한 새로운 test.log파일이 생성

- 2분 뒤 -> backupcount가 2이니까, 가장 오래된 로그를 지운다.

test.log.2022-03-21_10-02가 가장 오래됐으니 지우고, test.log -> test.log.2022-03-21_10-06 으로 바뀌고 

10시 8분에 실행한 새로운 test.log파일이 생성

 

이런 식으로 동작을 한다는 것이다.

그래서 파일 이름을 바꾸면 백업시스템이 관리하는 이름형식이 아니라서 인식하지 못하기 때문에, 백업이 안된다.

 

제일 중요한건 

파일 이름을 바꾸면 백업시스템이 관리하는 이름형식이 아니라서 인식하지 못하기 때문에, 백업이 안된다.