이런 경험 있으신가요?
FastAPI 서버를 실행하면 콘솔에 이런 로그가 쉴 새 없이 올라옵니다.
INFO: 127.0.0.1:52341 - "GET /api/io/read HTTP/1.1" 200 OK
INFO: 127.0.0.1:52342 - "GET /api/io/read HTTP/1.1" 200 OK
INFO: 127.0.0.1:52342 - "GET /api/diagnostics/check-port HTTP/1.1" 200 OK
INFO: 127.0.0.1:52343 - "GET /api/io/read HTTP/1.1" 200 OK
WARNING: PLC 통신 실패 — 재연결 시도
INFO: 127.0.0.1:52344 - "GET /api/io/read HTTP/1.1" 200 OK중간에 중요한 경고가 있는데 정상 접근 로그들 사이에 파묻혀버렸습니다.
1초에 10번 폴링하는 앱이라면 분당 600줄씩 쌓여요.
처음엔 이걸 그냥 뒀습니다.
"로그야 원래 많은 거 아닌가"라는 생각으로요.
그러다 현장 운영자에게 PLCLink를 보여주는 자리에서 상태 창 화면을 열었을 때 저도 모르게 당황했습니다.
PLC 통신 실패 경고가 http 200 로그들 사이에 묻혀서 보이지도 않았거든요.
운영자가 "서버 잘 되고 있어요?"라고 물었을 때 화면 보면서 "...잘 되고 있어요"라고 대답해야 했습니다.
그때 "로그를 고쳐야겠다"는 생각이 들었어요.
용어 먼저 짚고 넘어갈게요
Python logging이란
Python의 표준 로그 기록 시스템입니다.
Logger(어디서 로그를 만드는지), Handler(어디에 출력하는지), Filter(어떤 로그를 통과시키는지)로 구성돼요.
보안 카메라 비유로 설명하면, Logger는 카메라 렌즈, Handler는 어느 모니터에 영상을 보낼지, Filter는 어떤 영상만 녹화할지 결정하는 것과 같습니다.
uvicorn.access 로거란
uvicorn이 HTTP 접근 로그를 기록하는 전용 로거입니다.
모든 HTTP 요청/응답이 여기를 통해 찍혀요.
logging.getLogger("uvicorn.access")로 접근할 수 있습니다.
이 로거에 Filter를 달면 특정 경로의 접근 로그를 선택적으로 억제할 수 있어요.
RotatingFileHandler란
파일 로그를 쓸 때 용량을 제한하는 핸들러입니다.
냉장고 비유로 설명하면, 냉장고가 꽉 차면 가장 오래된 음식을 버리고 새 음식을 넣는 것처럼, 파일이 지정한 크기를 넘으면 자동으로 새 파일로 넘어가고 최대 파일 개수를 유지합니다.
24/7 운영 환경에서 디스크가 무한히 차지 않도록 보호해요.
왜 로그를 분리해야 했나
로그를 보는 사람이 둘입니다.
현장 운영자: "서버가 켜졌는지, PLC가 연결됐는지, 알람이 발생했는지." 이것만 알면 됩니다.
HTTP 요청이 몇 번 들어왔는지 볼 이유가 없어요.
오히려 그 정보가 많을수록 진짜 중요한 것을 놓칩니다.
개발자: 모든 것을 다 봐야 합니다.
어떤 API가 몇 번 호출됐는지, 어떤 오류가 어디서 났는지. 날 것 그대로의 로그가 필요해요.
같은 로그를 두 사람에게 보여주면 둘 다 불만이 됩니다.
운영자는 너무 복잡하고, 개발자는 필터링이 많아 정보가 부족합니다.
결론은 단순합니다.
같은 로그 소스를 대상에 따라 다르게 필터링해서 보여주면 됩니다.
로그 3계층 설계
세 군데로 분리했습니다.
상태 창 (현장 운영자) → 번역된 PLCLink 이벤트만
"서버 준비 완료", "PLC 연결 성공" 등 한국어
HTTP 접근 로그 전부 숨김
SystemPage (브라우저) → PLCLink 앱 이벤트만
/api/io/read 200, /api/diagnostics 200 → 억제
실제 이벤트(PLC 상태 변경, 알람 등)만 표시
data/plclink.log → 모든 레벨 기록
HTTP 로그 포함 전부
RotatingFileHandler(5MB x 3)구현 1 : uvicorn 접근 로그 필터
특정 경로의 HTTP 접근 로그를 억제합니다. logging.Filter를 상속해서 구현해요.
import logging
import re
class _SuppressPollingRoutes(logging.Filter):
_SUPPRESS = re.compile(
r"/api/io/read|"
r"/api/diagnostics/check-port|"
r"/api/sites/\d+/canvas-widgets"
)
def filter(self, record: logging.LogRecord) -> bool:
msg = record.getMessage()
if self._SUPPRESS.search(msg):
return False # 이 로그는 출력하지 않음
return True # 나머지는 정상 출력
logging.getLogger("uvicorn.access").addFilter(
_SuppressPollingRoutes()
)이제 /api/io/read, /api/diagnostics/check-port 접근 로그는 콘솔에 찍히지 않습니다.
설정 변경, 알람 응답 같은 다른 API는 정상 기록돼요.
정규식을 쓴 이유가 있습니다.
/api/sites/1/canvas-widgets, /api/sites/2/canvas-widgets처럼 ID가 다른 같은 패턴 경로를 한 줄로 억제하기 위해서예요.
구현 2 : 상태 창에 한국어 이벤트 표시
uvicorn 내부 메시지를 한국어로 번역해서 상태 창에 표시합니다.
_KOR_EVENTS = {
"Application startup complete": "서버 준비 완료 - 브라우저로 접속 가능",
"Uvicorn running": "포트 바인딩 완료",
"PLC 통신 실패": "PLC 통신 실패",
"PLC 연결 복구": "PLC 연결 복구",
"알람 발생": "알람 발생",
"Shutting down": "서버 종료 중",
}
class _StatusWindowHandler(logging.Handler):
def __init__(self, status_window):
super().__init__()
self._win = status_window
def emit(self, record: logging.LogRecord):
msg = record.getMessage()
for eng, kor in _KOR_EVENTS.items():
if eng in msg:
self._win.append_log(kor, level=record.levelno)
return
# 사전에 없는 메시지는 무시 (HTTP 로그 포함)번역 사전에 있는 메시지만 상태 창에 나옵니다.
HTTP 접근 로그는 사전에 없으니까 별도 필터 없이 자동으로 걸러져요.
나중에 표시하고 싶은 이벤트가 생기면 사전에 한 줄 추가하면 됩니다.
현장 운영자 입장에서는 "서버 준비 완료"라는 한 줄만 봐도 충분합니다.
영문 uvicorn 메시지보다 훨씬 직관적이에요.
구현 3 : 파일 로그 전체 기록
개발과 디버깅을 위해 모든 로그를 파일로 남깁니다.
from logging.handlers import RotatingFileHandler
def setup_file_logging(log_path: Path):
handler = RotatingFileHandler(
log_path,
maxBytes=5 * 1024 * 1024, # 5MB
backupCount=3, # 최대 3개 파일
encoding="utf-8",
)
handler.setLevel(logging.DEBUG)
handler.setFormatter(logging.Formatter(
"%(asctime)s %(levelname)-8s %(name)s %(message)s"
))
logging.getLogger().addHandler(handler)
logging.getLogger().setLevel(logging.DEBUG)5MB가 차면 plclink.log.1로 이름이 바뀌고 새 파일이 생깁니다.
최대 3개를 유지하니까 약 15MB의 로그 기록이 항상 남아있어요.
상태 창과 SystemPage에는 중요한 이벤트만 올라가지만, 파일에는 모든 것이 기록됩니다.
현장에서 "어제 오후에 뭔가 이상했는데요"라는 말을 들으면 파일 로그를 열면 됩니다.
정리
| 대상 | 보이는 것 | 안 보이는 것 |
|---|---|---|
| 상태 창 (운영자) | 한국어 이벤트 | HTTP 접근 로그 전부 |
| SystemPage (브라우저) | PLCLink 앱 이벤트 | 폴링 API 200 로그 |
| plclink.log (개발자) | 모든 로그 전부 | 없음 |
마치며
"로그는 많을수록 좋다"는 생각을 갖고 있었어요.
정보가 많으면 뭔가 놓치지 않을 것 같으니까요.
현장에서 운영자에게 상태 창을 보여줬다가 경고가 묻혀있던 걸 보고 나서 생각이 바뀌었습니다.
정보가 너무 많으면 중요한 것을 놓칩니다.
분당 600줄의 HTTP 로그는 정보가 아니라 노이즈였어요.
로그를 대상에 맞게 나누는 것은 단순히 보기 좋게 하는 게 아닙니다.
현장 운영자가 진짜 이벤트를 놓치지 않게 하고, 개발자가 디버깅할 때 필요한 정보를 모두 가질 수 있게 하는 거예요.
두 가지가 충돌하지 않습니다. 같은 소스에서 각각에게 맞는 필터를 적용하면 됩니다.
