구축형 제품은 JSON 로그 하나로 관측하고, 요청 ID로 워커까지 잇는다

구축형 제품은 고객사 서버에서 돕니다. 장애가 나면 개발사가 볼 수 있는 것은 고객사가 모아 둔 로그뿐인 경우가 많습니다. 제품에 OpenTelemetry 계측과 Prometheus /metrics를 넣어 두어도, 그 값을 받아 저장할 수집기와 메트릭 서버를 고객사가 세우지 않으면 아무도 읽지 않습니다. 반면 로그는 고객사마다 이미 모으고 있습니다. 그래서 OwlAI는 structlog로 남기는 구조화 JSON 로그 하나로 관측합니다.

로그 하나로 장애를 추적하려면 세 가지가 맞아야 합니다. 한 줄 한 줄이 기계로 거를 수 있는 사실이어야 하고, 웹이 받은 요청부터 워커가 돌린 LLM 호출까지 한 ID로 이어져야 하며, 사용자 입력과 비밀값이 로그로 새지 않아야 합니다. 이 글은 이 셋을 어떻게 맞췄는지, 그리고 제품 안에 로그 파일을 얼마나 남기는지 다룹니다.

#메트릭 서버와 트레이스 수집기는 고객사가 하나씩 더 운영해야 한다

계측을 제품에 넣는 일은 쉽습니다. 어려운 일은 받는 쪽에 있습니다. 메트릭을 쌓으려면 Prometheus 서버가, 트레이스를 쌓으려면 트레이스 수집기와 저장소가, 둘을 보려면 대시보드가 있어야 합니다. 구축형에서는 이 도구를 하나씩 고객사가 설치하고, 보관 기간을 정하고, 보안 검토를 받고, 업그레이드합니다.

로그는 이 비용이 없습니다. 표준 출력과 파일로 나가는 줄 단위 JSON은 고객사가 이미 쓰는 로그 수집기(Promtail, Fluent Bit 등)에 그대로 붙습니다. 오래 남아야 하는 사실은 로그에 맡기지 않고 데이터베이스 테이블에 둡니다. 호출마다의 토큰과 비용은 사용량 원장(「LLM 비용 원장은 청구서와 맞추고, 캐시 토큰은 응답 형식으로 센다」)에, 누가 무엇에 닿았는지는 감사 기록(「감사 기록에는 대화 대신 AI가 실행한 SQL과 도구 호출을 남긴다」)에 남습니다.

#한 줄은 이벤트 이름 하나와 필드로 쓴다

출력은 운영이든 개발이든 JSON입니다. 모든 줄에 UTC 시각, 레벨, 로거 이름, 서비스 이름, 환경이 자동으로 붙습니다.

메시지 자리에는 http.request, llm.round처럼 점으로 이은 고정 이벤트 이름만 쓰고, 값은 snake_case 필드에 따로 싣습니다. 「요청 3건 중 2건 실패」 같은 문장은 사람이 읽기는 좋지만, 수집기에서 실패 수로 거르거나 더할 수 없습니다.

레벨은 그 줄이 무엇을 말하는지로 정합니다.

폴백 분기에는 반드시 로그를 남깁니다. except 블록만이 아닙니다. LLM과 외부 호출에서 흔한 실패는 「200인데 내용이 없다」라서, if not result: 같은 분기도 폴백이면 로그를 남기고 판단 근거(측정값, 상한)를 싣습니다. 폴백이 로그를 남기지 않으면 기능은 멀쩡해 보이고 품질만 떨어집니다. 입력을 받아 계획을 돌려주는 판단 함수는 안에서 WARNING을 내지 않습니다. 루프를 돌 때마다 같은 경고가 쌓이기 때문입니다. 판단 함수는 관측값을 돌려주고, 호출한 쪽이 한 번 남깁니다.

신호가 없는 줄은 INFO에서 뺍니다. 채팅과 회의 화면은 진행 상태를 몇 초마다 폴링으로 받습니다. 이 성공 응답을 INFO로 남기면 7일 동안 회의 진행 폴링 105,028줄과 채팅 진행 폴링 22,579줄이 쌓여 백엔드 로그의 절반을 차지합니다(실운영 환경 관측). 그래서 폴링 경로의 성공 응답은 DEBUG로 내리고, 헬스 체크는 접근 로그에서 뺍니다. 폴링 경로라도 4xx 응답과 1초 넘게 걸린 응답은 INFO로 남깁니다. 회의 폴링의 409는 녹음을 멈추라는 신호여서, 이 줄이 없으면 「녹음이 왜 멈췄나」에 답할 수 없습니다.

#요청 ID 하나가 웹 접근 로그에서 LLM 라운드까지 이어진다

웹은 HTTP 요청마다 요청 ID(requestId)를 정해 그 요청이 남기는 모든 줄에 붙입니다. 앞단 프록시가 X-Request-Id 헤더를 보냈고 ID 모양이면 그 값을 쓰고, 아니면 새로 만듭니다. 줄바꿈이 섞이거나 지나치게 긴 값은 로그 한 줄을 위조하거나 부풀릴 수 있어서 받지 않습니다. 같은 ID가 응답 헤더와 오류 응답 본문에도 실립니다. 고객사 프록시 로그와 OwlAI 로그가 같은 ID를 공유하고, 사용자가 받은 오류 응답 하나로 그 요청의 로그를 찾을 수 있습니다.

채팅 턴(질문 하나를 받아 답을 내기까지의 한 번)은 웹이 접수하고 워커가 실행합니다. 웹은 접수한 요청의 ID를 작업에 실어 큐에 넣고, 워커는 턴을 시작할 때 그 ID를 이어받아 자기 로그에 붙입니다. 워커가 남기는 줄도, 그 턴 안의 LLM 호출이 남기는 줄도 같은 요청 ID를 갖습니다. 분석처럼 HTTP 요청 없이 도는 작업에는 작업 ID(jobId)가 붙습니다.

LLM 호출 커널은 라운드(모델을 한 번 부르고 응답을 받는 왕복)마다 llm.round 이벤트를 한 줄 남깁니다. 채팅뿐 아니라 플레이북, 스키마 분석, 회의록, 문서 변환이 같은 도구 루프를 돌리므로, 모든 작업이 같은 모양의 줄을 냅니다. 채팅 턴은 라운드마다 데이터베이스에 호출 기록을 남기지만, 그 기록은 대화에 매달려 있어서 대화가 없는 작업은 넣을 수 없습니다. 라운드 관측을 로그로 낸 이유가 이것입니다.

한 줄에 실리는 필드는 네 묶음입니다.

• 무엇의 일부인가: 스택(채팅, 플레이북, 분석, 회의, 변환), 단위 종류와 ID, 노드, 부모 단위, 중첩 깊이, 라운드 번호
• 무엇을 불렀나: 프로바이더, 모델, 넘긴 도구 수와 이름 표본, 구조화 출력 여부, tool_choice
• 어떻게 끝났나: 지연 시간, 상태, 모델이 부른 도구 이름과 수, 본문 길이
• 토큰: 입력, 출력, 캐시 읽기, 캐시 쓰기

호출하는 쪽은 「이 호출이 무엇의 일부인가」를 범위로 깔아 두고, 커널은 그 범위를 읽어 필드를 채웁니다. 범위 없이 들어온 호출은 스택 이름이 unscoped로 남습니다. 범위를 빠뜨린 새 호출 경로가 생겼다는 사실 자체를 이 값으로 찾습니다.

상태는 정상, 오류, 취소, 미완료 넷입니다. 사용자가 멈췄거나 응답 대기가 만료된 취소는 오류가 아니어서 INFO로 남고, 오류는 WARNING입니다. 미완료는 응답은 왔지만 출력 상한에서 잘린 경우입니다. 예외가 나지 않아 정상과 구별되지 않는 모양이라, WARNING으로 올리고 잘린 이유를 함께 싣습니다. 모델이 같은 말을 반복하다 출력 상한에 닿고 본문은 비어 있는 라운드가 이 모양입니다(서버 쪽 상한은 「vLLM 동시성 상한은 짧은 프롬프트가 아니라 운영 입력 길이로 잰다」).

토큰 필드는 사용량 원장과 같은 함수로 셉니다(「LLM 비용 원장은 청구서와 맞추고, 캐시 토큰은 응답 형식으로 센다」). 같은 줄에 요청 앞부분의 해시도 실려 프롬프트 캐시가 왜 깨졌는지 찾는 데 쓰입니다(「시스템 프롬프트 한 줄에 캐시 읽기가 0이 된다, 바뀌는 블록은 뒤로 보낸다」). 이 이벤트는 남기다 실패해도 LLM 호출을 실패시키지 않습니다.

#사용자 입력은 로그를 쓰는 자리가 아니라 직렬화하는 자리에서 걷는다

비밀값과 사용자 원문은 로그에 남지 않습니다. 로그를 쓰는 코드마다 조심하는 것으로는 부족합니다. 라이브러리와 데이터베이스가 스스로 남기는 줄이 있기 때문입니다.

큐 라이브러리(Procrastinate)는 잡을 시작하고 끝낼 때마다 잡의 인자 전체를 메시지와 필드에 싣습니다. 채팅 턴 잡의 인자에는 사용자의 질문 원문이 들어 있습니다. 태스크마다 인자를 줄이면 새 태스크가 생길 때마다 다시 샙니다. 그래서 표준 출력과 파일이 함께 쓰는 JSON 직렬화 한 곳에서 큐 로그를 허용 목록으로 거릅니다. 남는 것은 태스크 이름, 잡 ID, 큐, 상태, 시도 횟수 같은 잡 정보이고, 반환값도 걷습니다. 라이브러리가 필드를 늘려도 새 필드는 허용 목록에 없으므로 빠집니다.

메타스토어 PostgreSQL은 1초 넘게 걸린 문장을 로그에 남기는데, 기본값으로 두면 바인드 파라미터 값까지 함께 남깁니다. 사용자 질문과 프롬프트가 DB 로그를 거쳐 수집기에 쌓이는 경로입니다. 그래서 compose 파일에서 log_parameter_max_length=0으로 고정합니다. 접근 로그는 주소의 쿼리 문자열을 남기지 않고, 경로에 토큰이 들어가는 주소는 그 자리를 가려서 남깁니다.

#제품 안의 로그 파일은 수집기가 가져갈 때까지의 완충이다

로그는 두 곳에 남습니다. 컨테이너 로그는 도커 json-file 드라이버로 20MB씩 5개까지 돌려 씁니다. 컨테이너를 지우면 함께 사라지므로 배포 직후 확인하는 용도입니다.

영속 사본은 호스트 디렉터리(기본 /var/log/owlai/<서비스>)에 파일로 남고, 컨테이너를 새로 만들어도 남습니다. 파일은 프로세스마다 따로 씁니다. 웹은 여러 프로세스로 도는데, 한 파일을 함께 쓰면 로그 로테이션이 프로세스끼리 부딪혀 줄을 잃습니다. 파일 이름에 프로세스 ID와 컨테이너 호스트 이름을 함께 넣어, 같은 서비스를 여러 벌 띄워도 이름이 겹치지 않습니다. 파일 하나는 20MB에서 돌리고 5개를 더 보관하며, 기동할 때 14일 넘게 쓰지 않은 지난 프로세스의 파일을 지웁니다. 디렉터리에 쓸 수 없으면 경고를 한 줄 남기고 표준 출력만으로 계속 돕니다.

몇 달 단위의 조회는 이 파일이나 표준 출력을 가져간 고객사 수집기에서 합니다. 보관 기간은 고객사가 정하고, 컨테이너를 몇 번 새로 만들든 배포를 넘어 조회할 수 있습니다.

#설계에서 고른 것

• 메트릭 시계열 대신 로그 집계를 골랐습니다. 시계열 저장소는 「지난 한 시간의 평균 지연」 같은 질의에 바로 답합니다. 하지만 메트릭 서버를 제품에 넣으면 고객사는 관측 도구를 하나 더 운영합니다. 같은 값은 접근 로그의 경과 시간과 llm.round의 지연 필드를 고객사 수집기에서 집계해 얻습니다.
• 분산 트레이싱 대신 요청 ID를 골랐습니다. 웹, 큐, 워커를 잇는 것은 요청 ID 하나이고, 라운드마다의 시간은 llm.round가 줍니다. 「어느 요청이 어디서 얼마나 걸렸나」를 수집 백엔드 없이 답합니다. 구간을 이어 그린 트레이스 화면은 없고, 그 자리는 로그 검색이 채웁니다.
• 제품 안의 로그 파일은 프로세스마다 120MB로 묶었습니다. 로그가 호스트 디스크를 채워 서비스를 멈추는 일을 막는 대신, 수집기가 가져가지 않은 오래된 줄은 사라집니다. 오래 남아야 하는 사실은 처음부터 테이블에 남깁니다.
• llm.round의 도구 이름은 40개까지만 표본으로 싣고 개수는 따로 남깁니다. 도구 카탈로그 전체를 라운드마다 찍으면 로그가 프롬프트만큼 커집니다. 표본 밖 도구의 정의가 바뀐 것은 해시가 잡습니다.

고객이 설치하고 운영하는 제품이고, 고객사마다 쓰는 로그 수집기가 이미 있으며, 오래 남겨야 하는 사실을 따로 테이블에 둘 수 있다면 같은 선택을 옮겨 볼 만합니다.