파이썬 실무 도구 - logging 설정 관리 ruff 포매터 운영 기준 (파이썬 고급 24단원)

이 단원에서 배우는 것

23단원에서 logkit 은 설치 가능한 패키지가 됐다. 이제 이걸 cron 에 걸어 매시간 돌린다고 하자. 어느 날 알림이 안 온다. print 로 찍던 출력은 cron 이 버렸고, 어느 서버에서 무슨 설정으로 돌았는지 알 방법이 없다. 마지막 단원은 운영 중인 코드가 스스로 상황을 설명하게 만드는 세 가지 장치를 붙인다.

• logging 을 dictConfig 로 한 곳에서 구성하고, 라이브러리와 애플리케이션의 역할을 나눈다
• 20단원의 설정 클래스를 dataclass 기반으로 정리하고 시작 시점에 검증한다
• ruff 로 포매팅·린팅을 자동화하고 pre-commit·CI 에 건다

왜 필요한가

print 는 세 가지를 못 한다. 끄지 못하고, 등급이 없고, 출처를 안 남긴다. 개발 중에는 문제가 안 되다가 운영에서 전부 문제가 된다. 디버깅용 출력을 지우려고 코드를 뒤지게 되고, 중요한 에러가 잡담 사이에 묻히고, 어느 모듈이 찍은 줄인지 몰라 검색으로 찾는다.

설정도 같다. 임계값을 코드에 박아 두면 스테이징과 운영이 달라야 할 때 코드를 고쳐 재배포해야 한다. 반대로 설정을 아무 데서나 os.environ.get 으로 읽으면 어떤 값이 필요한지 아무도 모른다. 새 서버에 배포하고 나서 세 번째 실행에서야 빠진 변수를 발견한다.

린터는 조금 다른 이유다. 코드 리뷰에서 임포트 순서나 따옴표 종류를 지적하는 데 시간을 쓰는 것은 낭비다. 기계가 판정할 수 있는 것은 기계에 넘기고, 사람은 설계와 정확성만 본다.

문법과 예제

로거의 이름 규칙

import logging

log = logging.getLogger(__name__)     # 모듈마다 이 한 줄

logkit/report.py 에서는 "logkit.report" 가 된다. 로거는 점으로 구분된 계층을 이루므로 logkit 레벨을 INFO 로 잡으면 하위 전부에 적용되고, logkit.parser 만 WARNING 으로 올려 조용히 시킬 수도 있다. 로그 한 줄만 보고도 어느 모듈이 찍었는지 알 수 있다.

구성은 한 곳에서, dictConfig 로

# src/logkit/logging_setup.py
from __future__ import annotations

import json
import logging
import logging.config
import sys


class JsonFormatter(logging.Formatter):
    """로그 수집기가 파싱하기 좋은 한 줄 JSON."""

    EXTRA_KEYS = ("path", "ms", "run_id")

    def format(self, record: logging.LogRecord) -> str:
        payload = {
            "ts": self.formatTime(record, "%Y-%m-%dT%H:%M:%S"),
            "level": record.levelname,
            "logger": record.name,
            "msg": record.getMessage(),
        }
        for key in self.EXTRA_KEYS:
            value = getattr(record, key, None)
            if value is not None:
                payload[key] = value
        if record.exc_info:
            payload["exc"] = self.formatException(record.exc_info).splitlines()[-1]
        return json.dumps(payload, ensure_ascii=False)


def build_config(json_output: bool, level: str) -> dict:
    return {
        "version": 1,
        "disable_existing_loggers": False,
        "formatters": {
            "plain": {"format": "%(asctime)s %(levelname)-7s %(name)s %(message)s"},
            "json": {"()": JsonFormatter},
        },
        "handlers": {
            "console": {
                "class": "logging.StreamHandler",
                "stream": sys.stdout,
                "formatter": "json" if json_output else "plain",
            }
        },
        "loggers": {
            "logkit": {"level": level, "handlers": ["console"], "propagate": False},
            "urllib3": {"level": "WARNING"},        # 수다스러운 라이브러리를 눌러 둔다
        },
        "root": {"level": "WARNING", "handlers": ["console"]},
    }


def setup(json_output: bool = False, level: str = "INFO") -> None:
    logging.config.dictConfig(build_config(json_output, level))

써 보면 이렇다.

from logkit.logging_setup import setup

setup(json_output=True, level="INFO")
log = logging.getLogger("logkit.report")

log.info("느린 요청 감지", extra={"path": "/api/pay", "ms": 2310})
try:
    1 / 0
except ZeroDivisionError:
    log.exception("집계 실패", extra={"run_id": "r-2026-08-25"})
log.debug("이건 안 나온다")

{"ts": "2026-08-25T21:25:28", "level": "INFO", "logger": "logkit.report", "msg": "느린 요청 감지", "path": "/api/pay", "ms": 2310}
{"ts": "2026-08-25T21:25:28", "level": "ERROR", "logger": "logkit.report", "msg": "집계 실패", "run_id": "r-2026-08-25", "exc": "ZeroDivisionError: division by zero"}

설계 규칙 세 가지를 못박아 둔다.

• 구성은 애플리케이션 진입점에서 한 번만. cli.py 의 main() 첫 줄이다. 라이브러리 모듈은 getLogger 만 하고 핸들러를 붙이지 않는다.
• extra 로 구조화된 값을 넣는다. 메시지 문자열에 값을 섞으면 나중에 ms > 2000 같은 조건으로 검색할 수 없다.
• 예외는 log.exception. except 블록 안에서 부르면 스택트레이스가 자동으로 붙는다. log.error(str(e)) 는 어디서 났는지를 통째로 버린다.

배포 대상에 따라 핸들러만 갈아 끼운다. 컨테이너나 systemd 아래라면 표준 출력에 그냥 쓰는 것이 정답이다. 파일 회전은 로그 수집기나 logrotate 에 맡긴다. 직접 파일에 쓸 때는 이렇게 한다.

"file": {
    "class": "logging.handlers.TimedRotatingFileHandler",
    "filename": "/var/log/logkit/app.log",
    "when": "midnight",
    "backupCount": 14,
    "encoding": "utf-8",
    "formatter": "json",
}

등급 기준

등급	쓰는 때	운영에서
DEBUG	개발자가 흐름을 따라갈 값	끈다. 켜면 성능이 눈에 띄게 준다
INFO	정상 흐름의 이정표. 시작·완료·건수	켠다. 사후 조사의 근거가 된다
WARNING	계속 돌지만 이상함. 재시도, 폴백	켠다. 쌓이면 조사한다
ERROR	이 작업은 실패했다	알림 대상
CRITICAL	프로세스를 계속할 수 없다	즉시 호출

기준을 세우는 질문은 하나다. "이 줄이 새벽 3시에 사람을 깨울 만한가." 아니면 ERROR 가 아니다. 재시도해서 성공한 것은 WARNING 이고, 사용자 입력이 잘못된 것은 대개 INFO 다. ERROR 가 남발되면 아무도 안 본다.

설정: dataclass + 환경변수

20단원에서 디스크립터로 만들었던 설정을 실무형으로 정리한다. 대부분의 경우 이쪽이 낫다. 타입체커가 필드를 이해하고, IDE 가 자동완성하고, 읽는 사람이 마법을 몰라도 된다.

# src/logkit/config.py
from __future__ import annotations

import os
from dataclasses import dataclass, field


class ConfigError(Exception):
    pass


def _env(key: str, default: str | None = None) -> str:
    value = os.environ.get(key, default)
    if value is None:
        raise ConfigError(f"{key} 가 설정되지 않았다")
    return value


@dataclass(frozen=True, slots=True)
class Settings:
    endpoint: str
    limit_ms: int = 1000
    threshold: float = 0.05
    workers: int = 4
    json_logs: bool = False
    log_level: str = "INFO"
    token: str = field(default="", repr=False)       # repr 에 안 찍힌다

    @classmethod
    def from_env(cls) -> "Settings":
        return cls(
            endpoint=_env("LOGKIT_ENDPOINT"),
            limit_ms=int(_env("LOGKIT_LIMIT_MS", "1000")),
            threshold=float(_env("LOGKIT_THRESHOLD", "0.05")),
            workers=int(_env("LOGKIT_WORKERS", "4")),
            json_logs=_env("LOGKIT_JSON_LOGS", "false").lower() in {"1", "true", "yes"},
            log_level=_env("LOGKIT_LOG_LEVEL", "INFO").upper(),
            token=_env("LOGKIT_TOKEN", ""),
        )

>>> Settings.from_env()
Settings(endpoint='https://alert.example.com/i', limit_ms=1000, threshold=0.05,
         workers=4, json_logs=True, log_level='INFO')
>>> # LOGKIT_ENDPOINT 를 지우면
ConfigError: LOGKIT_ENDPOINT 가 설정되지 않았다

얻는 것을 정리하면 이렇다.

• frozen=True — 실행 중에 설정이 바뀌지 않는다. "어디선가 값을 덮어썼다" 부류의 버그가 원천 차단된다.
• 필요한 환경변수 목록이 파일 하나에 다 있다. 배포 문서를 이 클래스에서 뽑을 수 있다.
• repr=False — 토큰이 로그나 에러 리포트에 새지 않는다. 설정 객체를 통째로 로깅하는 일이 흔하므로 실질적인 방어다.
• 시작 시점에 전부 검증된다. main() 첫 줄에서 부르면 잘못된 배포가 3초 안에 실패한다.

진입점은 이렇게 정리된다.

def main(argv: list[str] | None = None) -> int:
    settings = Settings.from_env()                       # 1. 설정 먼저 (실패는 여기서)
    setup(settings.json_logs, settings.log_level)        # 2. 로깅 구성
    log = logging.getLogger("logkit.cli")
    log.info("시작", extra={"run_id": os.environ.get("RUN_ID", "local")})
    ...

설정 항목이 20개를 넘거나 중첩 구조가 필요하면 pydantic-settings 를 쓴다. .env 파일 로딩, 타입 강제, 검증 메시지를 다 해 준다. 다만 의존성이 하나 늘어나므로, 항목이 열 개 남짓인 CLI 도구에는 위 코드로 충분하다.

비밀 값은 별도 원칙이 있다. 코드·git·이미지에 넣지 않는다. 환경변수로 주입하되 docker run -e TOKEN=... 처럼 명령행에 쓰면 ps 로 보이므로 파일이나 시크릿 매니저를 쓴다. 그리고 .env 는 .gitignore 에 넣고, 대신 값이 빈 .env.example 을 커밋한다.

ruff — 린터와 포매터를 하나로

예전에는 black(포맷) + isort(임포트 정렬) + flake8(린트) 세 개를 조합했다. ruff 는 이 셋을 하나로 대체하고 러스트로 구현되어 수십 배 빠르다. 새 프로젝트라면 ruff 만 쓰면 된다.

# pyproject.toml (23단원 파일에 이어서)
[tool.ruff]
line-length = 100
target-version = "py311"
src = ["src", "tests"]

[tool.ruff.lint]
select = [
    "E", "F",     # pycodestyle 오류, pyflakes — 기본
    "I",          # 임포트 정렬 (isort)
    "UP",         # 낡은 문법을 최신으로 (pyupgrade)
    "B",          # 흔한 버그 패턴 (bugbear)
    "SIM",        # 단순화 가능한 코드
    "RUF",        # ruff 고유 규칙
]
ignore = ["E501"]        # 줄 길이는 포매터가 처리한다

[tool.ruff.lint.per-file-ignores]
"tests/*" = ["S101"]     # 테스트에서 assert 는 정상

ruff format .        # 포맷 (black 호환)
ruff check .         # 린트
ruff check --fix .   # 자동 수정 가능한 것은 고친다

B(bugbear) 규칙군은 스타일이 아니라 진짜 버그를 잡는다. 대표적인 것이 가변 기본 인자다.

def collect(entries, seen=[]):    # B006: 기본값이 함수 정의 시점에 한 번만 만들어진다
    seen.extend(entries)          # 호출할 때마다 이전 호출의 결과가 남아 있다
    return seen

5단원에서 다룬 가변 기본값 함정이다. 스타일 문제가 아니라 실제 버그인데, 린터가 커밋 전에 자동으로 잡아 준다. 이런 규칙 몇 개만으로도 도입 값어치가 나온다.

pre-commit 과 CI

# .pre-commit-config.yaml
repos:
  - repo: https://github.com/astral-sh/ruff-pre-commit
    rev: v0.6.9
    hooks:
      - id: ruff
        args: [--fix]
      - id: ruff-format
  - repo: https://github.com/pre-commit/pre-commit-hooks
    rev: v4.6.0
    hooks:
      - id: trailing-whitespace
      - id: end-of-file-fixer
      - id: check-added-large-files

pip install pre-commit
pre-commit install          # 이후 git commit 마다 자동 실행
pre-commit run --all-files  # 도입 첫날 한 번

주의할 점이 하나 있다. pre-commit 만 믿으면 안 된다. git commit --no-verify 로 건너뛸 수 있고, 훅을 설치하지 않은 동료가 있다. 판정은 CI 에서 하고, pre-commit 은 CI 실패를 미리 알려 주는 편의로 취급한다.

# .github/workflows/ci.yml (일부)
- run: pip install -e ".[dev]"
- run: ruff format --check .
- run: ruff check .
- run: pytest

--check 는 포맷을 고치지 않고 어긋나면 실패시킨다. CI 가 코드를 고쳐 커밋하는 구성은 피하는 편이 낫다.

QueueHandler 로 멀티프로세스 로그를 한 곳에 모으는 구성 등 실제 레시피는 Logging Cookbook에 정리돼 있다.

실무에서 자주 틀리는 것

1. f-string 으로 로그를 찍는다

log.debug(f"엔트리 파싱: {entry!r}, 누적 {len(hits)}건")     # 나쁨
log.debug("엔트리 파싱: %r, 누적 %d건", entry, len(hits))    # 좋음

f-string 은 로그 레벨과 무관하게 항상 포맷팅된다. DEBUG 를 끈 운영 환경에서도 repr(entry) 가 매번 실행되고 문자열이 만들어진 뒤 버려진다. 17단원의 파서처럼 500만 번 도는 루프 안이라면 이 비용이 그대로 응답 시간이 된다. %s 스타일로 넘기면 실제로 출력될 때만 포맷팅된다.

비용 말고 다른 이유도 있다. 로그 수집기가 "엔트리 파싱: %r, 누적 %d건" 이라는 템플릿을 그룹 키로 쓸 수 있어서, 같은 종류의 로그를 묶어 세는 것이 가능해진다. f-string 은 매 줄이 다른 문자열이라 그룹핑이 안 된다.

2. 라이브러리 모듈에서 basicConfig 를 부른다

# src/logkit/parser.py 안에서
logging.basicConfig(level=logging.DEBUG)      # 절대 금지

basicConfig 는 루트 로거를 건드린다. logkit 을 임포트한 남의 애플리케이션의 로깅 구성이 통째로 바뀌고, 갑자기 DEBUG 로그가 쏟아진다. 게다가 basicConfig 는 이미 핸들러가 있으면 조용히 아무것도 안 하므로(force=True 없이는) 호출 순서에 따라 되기도 하고 안 되기도 한다. 재현 안 되는 "로그가 안 나와요"의 흔한 원인이다.

규칙은 명확하다. 구성은 애플리케이션이, 라이브러리는 getLogger 만. 라이브러리가 "핸들러가 없다"는 경고를 피하고 싶으면 __init__.py 에 이 한 줄만 넣는다.

logging.getLogger("logkit").addHandler(logging.NullHandler())

3. 로그에 비밀 값과 개인정보가 그대로 들어간다

log.info("알림 전송", extra={"payload": payload})   # payload 에 토큰이 있다면?
log.debug("요청 헤더: %s", request.headers)          # Authorization 이 통째로

한 번 로그 수집 시스템에 들어간 값은 지우기가 매우 어렵고, 그 시스템에는 대개 개발팀 전원이 접근할 수 있다. 방어는 찍는 쪽에서 한다. 위 Settings 의 repr=False 가 한 가지 방법이고, 더 확실한 것은 필터를 하나 두는 것이다.

SECRET_KEYS = {"token", "authorization", "password", "cookie"}


def redact(d: dict) -> dict:
    return {k: ("***" if k.lower() in SECRET_KEYS else v) for k, v in d.items()}


log.info("알림 전송", extra={"payload": redact(payload)})

주민번호·이메일·전화번호도 같다. 국내 서비스라면 개인정보를 로그에 남기는 것 자체가 규제 대상이 될 수 있으니, 식별자 대신 해시나 내부 ID를 찍는다.

4. extra 키가 LogRecord 의 예약어와 충돌한다

log.info("규칙 실행", extra={"name": "slow_ratio"})

KeyError: "Attempt to overwrite 'name' in LogRecord"

name, message, module, args, levelname, filename 등은 LogRecord 가 이미 쓰는 이름이다. extra 에 넣으면 예외가 난다. 최악은 이 예외가 정상 흐름이 아니라 에러 처리 경로에서 처음 터지는 경우다. 장애를 기록하려던 코드가 새 예외를 만들어 원래 에러를 덮는다. 접두사를 붙이는 습관으로 예방한다.

log.info("규칙 실행", extra={"rule_name": "slow_ratio"})

5. 린터 설정을 처음부터 최대로 켠다

기존 프로젝트에 ruff 를 도입하면서 규칙을 전부 켜면 경고 3,000개가 나오고, 팀은 그날로 # noqa 를 붙이기 시작한다. 시작은 ["E", "F", "I"] 정도로 하고, CI 를 초록으로 만든 다음 한 번에 하나씩 늘린다. 포맷 전체 적용 커밋은 기능 변경과 분리하고, .git-blame-ignore-revs 에 그 커밋 해시를 넣어 git blame 이 오염되지 않게 한다.

# .git-blame-ignore-revs
# ruff format 일괄 적용
8f2c1a9b4d5e6f7a8b9c0d1e2f3a4b5c6d7e8f90

git config blame.ignoreRevsFile .git-blame-ignore-revs

스스로 확인하기

1. 18단원처럼 ProcessPoolExecutor 로 워커를 4개 띄웠다. 각 워커의 로그는 어떻게 되는가? 파일 핸들러를 쓰면 무슨 문제가 생기는가?
2. 운영에서 특정 요청만 DEBUG 로그를 보고 싶다. 전체를 DEBUG 로 바꾸지 않고 하는 방법은?
3. 아래 코드의 문제 두 가지를 찾아라.

   def process(path, results=[]):
       try:
           results.extend(parse_file(path))
       except Exception as e:
           logging.error(f"실패: {e}")
       return results

정답

1. spawn 방식이면 워커는 새 인터프리터라 로깅 구성이 없는 상태로 시작하므로, 워커 안의 로그가 아예 안 나오거나 루트 로거의 기본 동작(WARNING 이상만 stderr)으로 나온다. 워커 진입 시점에 setup() 을 다시 불러야 한다(ProcessPoolExecutor(initializer=setup) 이 이 용도다). 파일 핸들러는 더 나쁘다. 여러 프로세스가 같은 파일에 쓰면 줄이 섞이고, RotatingFileHandler 는 회전 시 파일을 바꿔치기하므로 다른 프로세스가 삭제된 파일에 계속 쓰게 된다. 안전한 구조는 워커가 표준 출력에만 쓰고 수집은 밖에서 하는 것, 또는 QueueHandler 로 부모 프로세스의 리스너 하나에 모으는 것이다.
2. 세 가지 접근이 있다. (1) 로거 계층을 이용한다 — 전체는 INFO 로 두고 logkit.parser 만 DEBUG 로 내린다. 범위가 모듈 단위로 좁혀진다. (2) 샘플링 필터 — logging.Filter 를 붙여 run_id 가 특정 값이거나 난수가 1% 안에 들 때만 DEBUG 를 통과시킨다. (3) 런타임 조정 — 시그널 핸들러(SIGUSR1)나 관리용 HTTP 엔드포인트로 logging.getLogger("logkit").setLevel(...) 을 호출해 재시작 없이 바꾼다. 운영에서는 (1)+(3) 조합이 가장 실용적이다.
3. (1) 가변 기본 인자 results=[]. 리스트가 함수 정의 시점에 한 번만 만들어지므로 두 번째 호출부터 이전 결과가 그대로 쌓인다. ruff 의 B006 이 잡는다. results=None 으로 받고 안에서 results = [] if results is None else results 로 만든다. (2) f-string 로깅에 스택트레이스 유실. logging.error(f"실패: {e}") 는 예외 메시지만 남기고 어디서 났는지를 버린다. logging.exception("실패: %s", path) 로 바꾸면 스택트레이스가 붙는다. 덧붙여 모듈 로거 대신 logging.error(루트 로거)를 직접 부른 것도 문제다. log = logging.getLogger(__name__) 을 쓴다. 고친 코드는 이렇다.

   log = logging.getLogger(__name__)
   
   
   def process(path: str, results: list | None = None) -> list:
       results = [] if results is None else results
       try:
           results.extend(parse_file(path))
       except OSError:
           log.exception("파싱 실패: %s", path)
       return results

   except Exception 을 except OSError 로 좁힌 것도 의도적이다. 넓게 잡으면 오타로 인한 NameError 까지 삼켜서 "실패" 로그만 조용히 쌓인다.

고급 과정을 마치며

17단원부터 이 단원까지 logkit 하나를 만들면서 다룬 것을 다시 보면, 문법은 거의 없다. 이터레이터로 메모리를 통제했고, GIL 을 이해해 병렬화 수단을 골랐고, asyncio 로 대기 비용을 없앴고, 디스크립터를 배우고는 대개 쓰지 않기로 했고, 프로파일러로 직관이 틀렸음을 확인했고, 테스트로 고칠 수 있는 상태를 만들었고, 패키징으로 남에게 줄 수 있는 물건으로 바꿨고, 로깅으로 운영에서 설명 가능한 코드로 만들었다.

고급 단계에서 실제로 갈리는 것은 아는 문법의 개수가 아니라 선택의 근거를 댈 수 있는가다. "왜 프로세스를 썼나", "왜 메타클래스를 안 썼나", "왜 그 최적화를 되돌렸나"에 측정값과 트레이드오프로 답할 수 있으면 이 과정의 목적은 달성된 것이다.