파이썬 예외 로그 남기기 — 스크립트가 조용히 죽을 때 원인을 파일로 잡는 법, 함정 4가지 (실측)

터미널에서 직접 돌릴 때는 멀쩡히 오류 메시지를 보여 주던 스크립트가, 작업 스케줄러나 백그라운드로 돌리면 아무 말 없이 멈춰 있는 경우가 있습니다. 결과 파일이 안 생겼다는 사실만 다음 날 알게 되고, 어디서 왜 죽었는지는 알 길이 없습니다. 이번 글에서는 파이썬 예외 로그 남기기를 표준 라이브러리 logging만으로 구성해, 잡은 예외든 놓친 예외든 스레드 안의 예외든 트레이스백까지 로그 파일에 남기는 방법을 직접 돌려 보며 정리합니다.

먼저 출력이 어디에도 연결되지 않은 실행을 흉내 내 봤습니다. 세 번째 파일에서 ValueError가 나는 스크립트였는데, 실행이 끝나고 남은 건 종료 코드 1 하나뿐이었습니다. 결과 파일도, 로그도, 어느 줄에서 무슨 예외였는지도 없었습니다. 같은 스크립트에 로그 설정 20여 줄을 붙이자, 세 종류의 예외가 모두 파일·줄 번호와 함께 남았습니다. 그 과정과 중간에 만난 함정 4가지를 순서대로 보여 드리겠습니다.

실험 환경과 “조용히 죽는” 스크립트

Windows 11, Python 3.12.10에서 실행했고 외부 패키지는 쓰지 않았습니다. 이 PC의 기본 인코딩(locale.getpreferredencoding)은 cp949였습니다. 테스트용 스크립트는 data 폴더의 a~d.txt 네 파일(10, 20, “삼십”, 40)을 읽어 합계를 구하는데, c.txt의 “삼십”에서 int() 변환이 실패하도록 만들었습니다.

처음에는 콘솔 없이 실행되는 pythonw.exe로 띄우면 스케줄러와 같은 상황이 될 거라고 생각했습니다. 그런데 실제로 돌려 보니 부모 프로세스가 파이프를 연결해 주자 stderr 278자가 그대로 넘어왔고, DETACHED_PROCESS 옵션으로 띄워도 부모의 핸들을 물려받아 stderr가 살아 있었습니다. 그래서 출력을 DEVNULL로 버리는 방식으로 “아무도 출력을 받지 않는 실행”을 흉내 냈습니다.

$ python ../timed.py run_devnull.py
exit: 1
result.txt 존재: False
남은 단서: 종료 코드 1 하나뿐

이 상태가 바로 “조용히 죽은” 스크립트입니다. 종료 코드 1은 실패했다는 사실만 알려 줄 뿐, 원인은 알려 주지 않습니다.

로그를 남기는 완성본

아래가 최종 스크립트입니다. 핵심은 네 가지입니다. 파일 핸들러에 encoding="utf-8"을 명시하고, 로그 파일 경로를 __file__ 기준으로 잡고, 잡은 예외는 log.exception()으로 기록하고, 놓친 예외는 sys.excepthook과 threading.excepthook으로 받습니다.

# 2단계: logging + logger.exception + sys.excepthook + threading.excepthook
import logging
import sys
import threading
from logging.handlers import RotatingFileHandler
from pathlib import Path

LOG = Path(__file__).with_name("job.log")

handler = RotatingFileHandler(LOG, maxBytes=1_000_000, backupCount=3, encoding="utf-8")
handler.setFormatter(logging.Formatter("%(asctime)s %(levelname)s [%(threadName)s] %(message)s"))
logging.basicConfig(level=logging.INFO, handlers=[handler])
log = logging.getLogger("job")


def log_uncaught(exc_type, exc, tb):
    if issubclass(exc_type, KeyboardInterrupt):  # Ctrl+C는 평소처럼
        sys.__excepthook__(exc_type, exc, tb)
        return
    log.critical("잡히지 않은 예외로 종료", exc_info=(exc_type, exc, tb))


def log_thread(args):
    log.critical("스레드 %s 에서 예외", args.thread.name,
                 exc_info=(args.exc_type, args.exc_value, args.exc_traceback))


sys.excepthook = log_uncaught
threading.excepthook = log_thread


def main():
    data = Path(__file__).with_name("data")
    total, failed = 0, []
    log.info("시작: 파일 %d개", len(list(data.glob("*.txt"))))
    for f in sorted(data.glob("*.txt")):
        try:
            total += int(f.read_text(encoding="utf-8"))
        except ValueError:
            log.exception("숫자가 아닌 내용: %s", f.name)  # 트레이스백까지 기록하고 계속
            failed.append(f.name)
    log.info("합계 %d, 실패 %s", total, failed)

    t = threading.Thread(target=lambda: 1 / 0, name="worker-1")
    t.start()
    t.join()

    Path(__file__).with_name("missing.cfg").read_text()  # 일부러: 잡지 않은 예외


if __name__ == "__main__":
    main()

실행하면 콘솔에는 아무것도 나오지 않고 종료 코드 1로 끝나지만(0.14초), job.log에는 다음 내용이 남았습니다. 경로와 일부 내부 프레임은 줄였습니다.

2026-11-13 10:01:19,146 INFO [MainThread] 시작: 파일 4개
2026-11-13 10:01:19,147 ERROR [MainThread] 숫자가 아닌 내용: c.txt
Traceback (most recent call last):
  File "...\exc-log\job_logged.py", line 38, in main
    total += int(f.read_text(encoding="utf-8"))
ValueError: invalid literal for int() with base 10: '삼십'
2026-11-13 10:01:19,149 INFO [MainThread] 합계 70, 실패 ['c.txt']
2026-11-13 10:01:19,150 CRITICAL [worker-1] 스레드 worker-1 에서 예외
Traceback (most recent call last):
  ...
  File "...\exc-log\job_logged.py", line 44, in <lambda>
    t = threading.Thread(target=lambda: 1 / 0, name="worker-1")
ZeroDivisionError: division by zero
2026-11-13 10:01:19,153 CRITICAL [MainThread] 잡히지 않은 예외로 종료
Traceback (most recent call last):
  File "...\exc-log\job_logged.py", line 48, in main
    Path(__file__).with_name("missing.cfg").read_text()  # 일부러: 잡지 않은 예외
  ...
FileNotFoundError: [Errno 2] No such file or directory: '...\\exc-log\\missing.cfg'
  • 잡은 예외(c.txt): 트레이스백을 남기고 다음 파일로 넘어가 합계 70(10+20+40)까지 계산했습니다.
  • 스레드 안의 예외: threading.excepthook 덕분에 스레드 이름(worker-1)과 함께 기록됐습니다.
  • 잡지 않은 예외: sys.excepthook이 마지막 트레이스백을 남겼고, 종료 코드는 원래대로 1이라 스케줄러에서도 실패로 보입니다.

excepthook 안에서 KeyboardInterrupt를 원래 처리기로 넘기는 이유는, 직접 실행하다 Ctrl+C로 멈췄을 때까지 CRITICAL 로그가 쌓이지 않게 하려는 것입니다.

함정 1: log.error(e)는 위치를 남기지 않는다

except 블록에서 가장 흔히 보이는 코드가 log.error(e)입니다. 두 방식을 같은 예외로 비교했습니다.

try:
    int("삼십")
except ValueError as e:
    log.error(e)              # 메시지 한 줄만
try:
    int("삼십")
except ValueError:
    log.exception("변환 실패")  # 메시지 + 트레이스백
log.error(e) 기록: ERROR:root:invalid literal for int() with base 10: '삼십'
log.exception 기록 줄 수: 5 / 마지막 줄: ValueError: invalid literal for int() with base 10: '삼십'

log.error(e)는 예외 메시지 한 줄뿐이라 어느 파일 몇 번째 줄인지 알 수 없습니다. log.exception()은 같은 메시지에 트레이스백 4줄이 더 붙어 총 5줄이 남았습니다. 이 함수는 except 블록 안에서만 쓰고, 그 밖에서 트레이스백을 남기려면 exc_info=를 넘깁니다.

함정 2: sys.excepthook은 스레드 예외를 못 잡는다

sys.excepthook만 걸어 두면 충분할 것 같지만, 스레드 안에서 난 예외는 여기로 오지 않습니다.

== B) sys.excepthook만 걸면 스레드 예외는?
exit: 0
b.log 크기: 0 / stderr 마지막 줄: ZeroDivisionError: division by zero

b.log는 0바이트였고 ZeroDivisionError는 stderr로만 나갔습니다. 더 곤란한 건 메인 스레드가 계속 실행돼 종료 코드가 0이었다는 점입니다. 출력을 버리는 환경이라면 스레드가 죽은 사실조차 모르고 “성공”으로 기록됩니다. 스레드나 ThreadPoolExecutor를 쓴다면 threading.excepthook도 같이 걸어야 합니다(Executor는 예외를 Future에 담아 두므로 result()를 호출하는 쪽에서 로그를 남겨야 합니다).

함정 3: 상대 경로 로그는 작업 폴더에 생긴다

스크립트는 tmp 폴더에 두고, 작업 폴더를 그 상위 폴더로 바꿔 실행해 봤습니다. filename="rel.log"와 Path(__file__).with_name("abs.log") 두 가지로 기록했습니다.

== C) 상대 경로 로그 파일 + 다른 작업 폴더에서 실행
tmp/rel.log 있음: False | exc-log/rel.log 있음: True
tmp/abs.log 있음: True

상대 경로 rel.log는 스크립트 옆이 아니라 실행 당시의 작업 폴더에 생겼습니다. 스케줄러로 실행할 때 “시작 위치”를 비워 두면 작업 폴더가 스크립트 폴더가 아닐 수 있어서, 로그를 엉뚱한 곳에서 찾게 됩니다. 완성본에서 Path(__file__).with_name("job.log")를 쓴 이유입니다.

함정 4: encoding을 빼면 cp949로 저장된다

basicConfig(filename="d.log")처럼 인코딩 없이 한글과 이모지를 기록해 봤습니다.

== D) encoding 없이 basicConfig(filename=...) + 이모지
exit: 0 | d.log를 UTF-8로 읽기: 실패 (invalid continuation byte)
d.log cp949로 읽은 내용: ['ERROR:root:한글 메시지', 'ERROR:root:완료 \\u2705', 'ERROR:root:마지막 줄']

오류도 경고도 없이 종료 코드 0으로 끝났지만, 파일은 시스템 기본값인 cp949로 저장돼 UTF-8로 열면 디코딩에 실패했습니다. 이모지(✅)는 예외 없이 \u2705라는 글자로 바뀌어 저장됐습니다. 로그를 VS Code나 다른 도구에서 UTF-8로 읽거나 서버로 옮길 계획이라면 encoding="utf-8"을 꼭 넣으세요. 이번 실험 중에도 cp949로 출력하는 자식 프로세스를 UTF-8로 읽다가 한글이 깨지는 장면을 여러 번 봤습니다.

로그를 많이 남기면 느려질까

같은 PC에서 FileHandler로 INFO 10만 줄, 예외 트레이스백 1,000건, 그리고 레벨 미달로 버려지는 DEBUG 10만 번을 각각 재고, RotatingFileHandler(1MB, 백업 3개)에 3MB 넘게 써 봤습니다.

INFO 10만 줄: 2.75초 | exception 1,000건: 0.16초 | 레벨 미달 debug 10만 번: 0.014초
bench.log 크기: 4.8MB
== F) RotatingFileHandler(maxBytes=1MB, backupCount=3)에 3MB 넘게 쓰기
  rot.log: 419,976바이트
  rot.log.1: 1,000,008바이트
  rot.log.2: 1,000,008바이트
  rot.log.3: 1,000,008바이트
항목1회차2회차
INFO 10만 줄2.75초2.72초
log.exception 1,000건0.16초0.16초
레벨 미달 DEBUG 10만 번0.014초0.016초

한 줄에 약 27마이크로초라, 파일 수백 개를 처리하는 스크립트에서 처리 단위마다 한 줄씩 남기는 정도는 부담이 없습니다. 레벨 미달 로그는 거의 공짜에 가까워서 DEBUG 로그를 코드에 남겨 두고 평소엔 INFO로만 기록하는 방식도 괜찮습니다. 회전 핸들러는 1MB마다 파일을 넘기고 backupCount=3이라 최대 4개 파일(약 3.4MB)에서 더 늘지 않았습니다. 매일 도는 스크립트라면 디스크가 차는 걱정을 덜 수 있습니다.

정리: 함정별 대응표

함정실측에서 본 현상대응
log.error(e)메시지 1줄, 위치 없음log.exception() 사용
스레드 예외b.log 0바이트, 종료 코드 0threading.excepthook 등록
상대 경로 로그작업 폴더에 생성Path(__file__) 기준 경로
encoding 생략cp949 저장, 이모지 \u2705encoding=”utf-8″ 명시

마무리

가장 작은 첫걸음은 지금 스케줄러로 돌고 있는 스크립트 하나에 위 완성본의 핸들러 설정과 excepthook 두 줄을 붙이는 것입니다. 기존 except 블록의 print(e)나 log.error(e)를 log.exception()으로 바꾸기만 해도, 다음에 조용히 죽었을 때 원인을 찾는 시간이 크게 줄어듭니다. 이번 실험에서 가장 의외였던 건 스레드 예외가 종료 코드 0으로 묻힌다는 점이었으니, 스레드를 쓰는 스크립트라면 그 부분부터 확인해 보세요.

다음 글에서는 텍스트 파일 수백 개에서 특정 단어를 한 번에 바꾸는 스크립트를, 바꾸기 전에 미리보기로 확인하는 기능까지 넣어 직접 돌려 보겠습니다.

댓글 남기기