Logging 과 Observability

Production server 에는 관측 수단이 세 갈래로 필요해. 셋 다 일찍 붙이면 싸고, 나중에 끼워 넣으면 아파.

Server 쪽 구조화된 log. Stderr 나 옆에 둔 파일에 JSON 한 줄씩, 최소한 이건 남겨 — 시각, 요청 id, method, 걸린 시간, 성공 여부. 사고를 조사할 때 바닥이 되는 기록이야.
Protocol 수준 logging. MCP 는 logging capability 를 정의해뒀어. 양쪽이 이걸 밝히면 client 가 log 를 구독할 수 있고, server 는 notifications/message event 로 내보내. Host 쪽에서 붙이는 문제를 디버깅할 때 쓸모 있어.
지표와 추적. tools/call 을 이름과 결과별로 세는 counter, 걸린 시간의 분포, 그리고 tool 이 부르는 HTTP 호출까지 따라가는 요청별 추적 구간. OpenTelemetry 가 무난한 기본값이고, tool 별 counter 하나가 가장 쓸모 있어.

새로 운영을 맡은 사람이 잘 헷갈리는 게 있어. Security track 의 audit log 는 여기 셋과 별개 야. 덧붙이기만 하고, 바꿀 수 없고, 디버깅이 아니라 규정 준수와 사후 조사를 위한 거지. 두 흐름을 갈라놔 — 파일도 다르게, 정리 주기도 다르게. 그래야 일상적인 log 정리 cron 에 audit 기록이 쓸려가지 않아.

Code

Tool wrapper 의 구조화 per-request logging·python

import logging, time, json, sys

logger = logging.getLogger("mcp")
handler = logging.StreamHandler(sys.stderr)
handler.setFormatter(logging.Formatter('%(message)s'))
logger.addHandler(handler)

def trace(method):
    async def wrapped(*args, **kwargs):
        start = time.perf_counter()
        ok, err = True, None
        try:
            return await method(*args, **kwargs)
        except Exception as e:
            ok, err = False, repr(e); raise
        finally:
            logger.info(json.dumps({
                "ts": time.time(), "tool": method.__name__,
                "latency_ms": round((time.perf_counter()-start)*1000, 2),
                "ok": ok, "error": err,
            }))
    return wrapped

Client 에서 MCP protocol log 구독·python

async with ClientSession(read, write) as s:
    init = await s.initialize()
    if init.capabilities.get("logging"):
        await s.set_logging_level("info")
        # Session 이 notifications/message event emit; sink 로 pipe.

Exercise

최소 server 에 tool 별 응답 시간을 남기는 log 한 줄을 붙여. Tool 마다 열 번씩 불러봐. Log 를 jq 로 흘려서 tool 별 평균 응답 시간을 계산해. 거기 찍힌 숫자가 출발선이야 — production 에 가까워지면 제일 먼저 만들게 될 차트가 이거야.

Code

External links

Exercise

Progress

댓글 0