애플리케이션을 방금 만들었는데, 뭔가 의도대로 동작하지 않는 것을 발견했다고 가정해 보겠습니다. 새로 구현한 기능이 예상과 다르게 작동한다면 어떻게 해야 할까요? 이 문제를 어떻게 해결할 수 있을까요?
소프트웨어 개발에서 프로그래머는 소프트웨어가 실행되는 동안 발생하는 이벤트를 추적하기 위해 로깅(logging)에 의존합니다. 덕분에 문제가 발생했을 때 원인을 효과적으로 찾아낼 수 있습니다.
이 가이드에서는 애플리케이션 로그를 남겨야 하는 이유와 Python logging 모듈을 사용해 프로그램의 이벤트를 추적하는 방법을 알아보겠습니다.
로그를 남겨야 하는 이유
로그를 기록하면 더 유지보수하기 쉬운 코드를 작성할 수 있습니다. logging 같은 모듈을 사용하면 프로그램에서 발생하는 모든 이벤트를 정확하게 기록할 수 있습니다. 즉, 어떤 코드 줄이 실행되었고 어떤 줄이 실패했는지 확인할 수 있습니다.
Python 개발자들은 코드 로그를 남길 때 print() 문에 의존하는 경우가 많습니다. 초보자부터 전문가까지 누구나 저지르는 습관이지만, 그럴 만한 이유도 있습니다. print() 문은 사용하기 쉽고 단순하기 때문입니다.
하지만 print() 문은 코드 로그를 남기는 최선의 방법이 아닙니다. 우선 print() 문은 콘솔에 어떤 출력이든 표시할 수 있기 때문에, 어떤 출력이 로그로 저장될 내용인지, 어떤 출력이 메인 프로그램의 일부인지 구분하기 어려워집니다. 게다가 print() 문은 기본적으로 로그를 저장하지 않습니다.
바로 이때 Python logging 모듈이 빛을 발합니다. logging 모듈을 사용하면 코드에서 어떤 이벤트가 실행되었는지 더 정확한 기록을 남길 수 있고, 이를 통해 코드를 더 효과적으로 디버깅하고 오류를 수정할 수 있습니다.
Python logging 모듈 사용법
이 튜토리얼에서는 학생 성적 목록을 순회하며 시험 합격 여부를 계산하는 프로그램에 기본적인 로깅 메시지를 추가해 보겠습니다. 다음 코드를 살펴보세요:
students = ["Martin", "Lewis", "Terri", "Bart"]
grades = [92, 78, 72, 38]
pass_fail = []
for i in range(0, len(students)):
print("Calculating grade for {}".format(students[i]))
if grades[i] > 55:
pass_fail.append(True)
print("{} has passed their exam.".format(students[i]))
else:
pass_fail.append(False)
print("{} has failed their exam.".format(students[i]))
print("Student grades have been calculated. Moving on to send emails to parents of students who have failed their exams.")
위 코드는 네 명의 학생이 시험에 합격했는지 여부를 계산합니다. 프로그램에는 세 개의 리스트가 선언되어 있습니다. 첫 번째 리스트는 학생 이름을, 두 번째 리스트는 각 학생의 성적을, 마지막 리스트는 합격 여부를 저장합니다.
프로그램을 실행하면 다음과 같은 결과가 출력됩니다:
Calculating grade for Martin. Martin has passed their exam. Calculating grade for Lewis. Lewis has passed their exam. Calculating grade for Terri. Terri has passed their exam. Calculating grade for Bart. Bart has failed their exam.
print() 문으로도 코드가 정상 작동하는 것을 확인할 수 있지만, 대신 logging 모듈을 사용해 이 정보를 표시할 수도 있습니다. 그러면 디버깅 메시지와 프로그램의 실제 출력을 명확히 구분할 수 있습니다.
먼저 프로그램 상단에 logging 표준 라이브러리를 임포트합니다:
import logging
logging 라이브러리를 임포트했으니 이제 코드에서 로그를 기록할 수 있습니다. 이 예제에서는 DEBUG 설정을 사용해 로그를 기록합니다. 지금은 경고(warning)를 추적할 필요가 없기 때문입니다. 참고로 지정할 수 있는 로깅 레벨은 다음과 같습니다:
- CRITICAL: 심각한 오류를 표시할 때 사용 (logging.critical())
- ERROR: 문제가 발생했음을 표시할 때 사용 (logging.error())
- WARNING: 예상치 못한 동작을 표시할 때 사용 (logging.warning())
- INFO: 프로그램이 정상 작동 중임을 표시할 때 사용 (logging.info())
- DEBUG: 코드를 디버깅할 때 사용 (logging.debug())
logging 라이브러리의 기본 설정은 WARNING이므로, 다음 코드로 재설정해야 합니다:
import logging logging.basicConfig(level=logging.DEBUG)
이제 코드 디버깅을 시작할 준비가 되었습니다. 성적 계산 시작과 프로그램 진행 상황을 알려주던 print() 문을 디버깅 문으로 교체해 보겠습니다:
import logging
logging.basicConfig(level=logging.DEBUG)
students = ["Martin", "Lewis", "Terri", "Bart"]
grades = [92, 78, 72, 38]
pass_fail = []
for i in range(0, len(students)):
logging.debug("Calculating grade for {}".format(students[i]))
if grades[i] > 55:
pass_fail.append(True)
print("{} has passed their exam.".format(students[i]))
else:
pass_fail.append(False)
print("{} has failed their exam.".format(students[i]))
logging.debug("Student grades have been calculated. Moving on to send emails to parents of students who have failed their exams.")
코드를 실행하면 다음과 같은 결과가 반환됩니다:
DEBUG:root:Calculating grade for Martin Martin has passed their exam. DEBUG:root:Calculating grade for Lewis Lewis has passed their exam. DEBUG:root:Calculating grade for Terri Terri has passed their exam. DEBUG:root:Calculating grade for Bart Bart has failed their exam. DEBUG:root:Student grades have been calculated. Moving on to send emails to parents of students who have failed their exams.
출력 내용 자체는 앞서와 동일합니다. 하지만 "Calculating grade for…" 메시지와 성적 계산이 완료되었음을 알리는 메시지가 다르게 표시됩니다. 해당 문장 앞에 "DEBUG:root:"라는 텍스트가 붙어 있는 것을 볼 수 있습니다.
이렇게 하면 프로그램이 특정 시점에 무엇을 하고 있는지 추적할 수 있습니다. logging 모듈이 위와 같은 접두사를 자동으로 추가해 주기 때문에, 어떤 텍스트가 프로그램의 출력이고 어떤 텍스트가 디버깅용인지 쉽게 파악할 수 있습니다.
이 예제에서 "[학생명] has failed their exam" 메시지는 각 학생의 합격 여부를 알려주는 핵심 정보입니다. 반면 나머지 메시지는 프로그램이 어떻게 실행되고 있는지 확인하는 데는 유용하지만 최종 사용자에게는 불필요한 정보입니다. 바로 이런 문장들을 logging 호출로 추적하는 것입니다.
추가 팁: 지연 포매팅으로 성능 최적화하기
logging 모듈은 % 연산자 스타일의 지연 포매팅(lazy formatting)을 지원합니다. 예를 들어 logging.debug("Calculating grade for %s", students[i])처럼 작성하면, 해당 로그 레벨이 비활성화된 경우 문자열 포매팅 비용 자체를 아낄 수 있습니다. 로그 호출이 많은 대규모 애플리케이션에서 유용한 패턴입니다.
파일에 로그 저장하는 방법
logging 모듈을 사용하면 로그를 파일에 기록할 수도 있습니다. Python 셸을 닫더라도 로그가 사라지지 않기 때문에 매우 유용합니다. 특정 시점에 프로그램이 어떻게 실행되었는지 영구적인 기록을 남길 수 있습니다.
방법은 간단합니다. logging 핸들러 설정 줄에 filename 인자만 추가하면 프로그램이 자동으로 로그를 파일에 저장합니다:
import logging logging.basicConfig(level=logging.DEBUG, filename="student_data.log") …
코드를 실행하면 지정한 파일 이름으로 로그가 기록됩니다. "student_data.log" 파일을 열어 보면 다음과 같은 내용이 담겨 있습니다:
DEBUG:root:Calculating grade for Martin DEBUG:root:Calculating grade for Lewis DEBUG:root:Calculating grade for Terri DEBUG:root:Calculating grade for Bart DEBUG:root:Student grades have been calculated. Moving on to send emails to parents of students who have failed their exams.
디버그 출력에는 logging.debug() 메서드로 로그로 지정한 메시지만 포함되는 것을 확인할 수 있습니다. 덕분에 print() 문으로 표시되는 프로그램 출력과 디버그 로그를 쉽게 구분할 수 있습니다.
또한 로그 항목이 언제 기록되었는지 추적하는 파라미터를 추가할 수도 있습니다. 다음 코드처럼 format 옵션을 지정하면 됩니다:
logging.basicConfig( level=logging.DEBUG, filename="student_data.log", format="%(asctime)s:%(levelname)s:%(message)s" )
이 코드는 student_data.log 파일에 다음과 같이 기록합니다:
2020-06-18 08:27:50,123:DEBUG:Calculating grade for Martin 2020-06-18 08:27:50,123:DEBUG:Calculating grade for Lewis 2020-06-18 08:27:50,123:DEBUG:Calculating grade for Terri 2020-06-18 08:27:50,123:DEBUG:Calculating grade for Bart 2020-06-18 08:27:50,124:DEBUG:Student grades have been calculated. Moving on to send emails to parents of students who have failed their exams.
이제 코드의 각 줄이 언제 실행되었는지 알 수 있습니다. 규모가 큰 프로그램에서는 특히 유용한데, 코드가 실행되는 순서와 처리 속도를 파악하는 데 큰 도움이 되기 때문입니다.
마무리
Python logging 모듈은 디버깅에 매우 유용한 도구입니다. 프로그램에서 실행되는 모든 이벤트를 추적하고, 그 이벤트들을 별도 파일로 저장할 수 있는 옵션도 제공합니다. 이를 통해 코드를 더 효과적으로 디버깅하고, 프로그램 실행 시 어떤 이벤트가 언제 실행되었는지 명확하게 이해할 수 있습니다. 간단한 스크립트부터 대규모 애플리케이션까지, print() 대신 logging 모듈을 활용하는 습관을 들여 보세요.