AI 응답이 느릴 때: OpenTelemetry로 검색·모델·도구 지연 나누기

“모델이 느리다”를 확인 가능한 질문으로 바꾸기

사내 문서에서 답을 찾는 AI 기능이 5초 뒤 응답했다고 하자. 이 숫자만으로는 모델을 바꿔야 할지, 검색 서버를 고쳐야 할지 정할 수 없다. 요청이 실행 대기열에 있었을 수도 있고, 검색을 두 번 했을 수도 있으며, 답변을 만든 뒤 검증하는 시간이 길었을 수도 있다.

먼저 어디부터 어디까지 5초인지 정한다. 서버가 요청을 받은 순간부터 응답을 끝낼 때까지인지, 사용자가 전송을 누른 순간부터 화면에 답이 모두 표시될 때까지인지가 다르다. 서버 바깥의 네트워크와 화면 갱신을 측정하지 않았다면 그 시간은 아직 모른다.

이 글은 OpenTelemetry로 관측 지점을 설계하고 시간표를 읽는 가이드다. 아래 수치는 직접 만든 가상 요청의 값이며 제품 벤치마크가 아니다. 계산은 검산했지만 OTel SDK·Collector를 설치하거나 실제 모델을 호출해 얻은 trace는 아니다. 특정 언어의 설치법보다, 수집한 기록에서 무엇을 판단할 수 있는지에 집중한다.

trace는 한 요청의 경로, span은 경계가 있는 작업

OpenTelemetry의 trace 설명에서 span은 시작·끝 시각, 부모 관계, 속성 등을 가진 작업 단위다. 같은 trace에 속한 span을 연결하면 요청이 어느 작업을 거쳤는지 볼 수 있다. 특정 순간만 남기고 싶다면 span event를 쓸 수 있다. 예를 들어 생성 호출 전체는 span으로, 첫 chunk를 받은 순간은 event로 표현하는 식이다.

검색을 거쳐 답을 만드는 서비스라면 다음과 같이 경계를 설계할 수 있다. 이름은 이 글의 설명용 이름이며 OTel 표준 필드나 그대로 실행할 SDK 코드가 아니다.

answer.request          요청 수신 → 서버 응답 종료
├─ prepare              인증·입력 준비
├─ retrieve             두 검색 시작 → 필요한 결과 모두 도착
│  ├─ keyword.search
│  └─ vector.search
├─ rerank               후보 재정렬
├─ generate             논리적 생성 작업 전체
│  ├─ model.attempt     개별 호출 시도
│  └─ retry.wait        재시도 대기, 있을 때만
├─ validate             답변 검사
└─ send                 남은 응답 전송

부모·자식 관계와 실행 의존 관계는 같지 않다. 두 검색이 같은 부모 아래 있어도 동시에 실행됐다는 보장은 없고, 두 자식이 끝나야 다음 단계가 시작되는지도 트리만으로 확정할 수 없다. 시작·끝 시각과 실제 코드의 기다리는 조건을 함께 읽는다. 스트리밍이라면 생성·검증·전송이 겹칠 수 있으므로 트리를 이 순서로 억지로 맞추지 않는다.

서비스가 나뉘면 ID만 로그에 적는 것으로 충분하지 않다. 송신 측이 추적 문맥을 전달하고 수신 측이 이를 받아 새 span을 연결해야 한다. 공식 context propagation 문서는 이 주입·추출과 traceparent 전파를 설명한다. HTTP 라이브러리, 비동기 작업, 큐 경계마다 실제 연결 여부를 확인한다. 외부 API가 내부 span을 제공하지 않으면 내 쪽에서 본 호출 시간까지만 알 수 있다.

5초짜리 요청에서 먼저 줄일 구간 찾기

다음은 단일 서버의 요청 수신을 0ms로 둔 가상 시간표다. 두 검색은 동시에 시작하고 둘 다 끝나야 재정렬한다. 이후 단계는 순차 실행하며, 완성된 답변을 검사한 뒤 보낸다고 가정한다. 실행 대기열이나 별도 경합은 이 예시에 없다.

작업	시작 → 종료	경과 시간
입력 준비	0 → 200ms	200ms
키워드 검색	200 → 600ms	400ms
벡터 검색	200 → 1,000ms	800ms
재정렬	1,000 → 1,300ms	300ms
모델 호출 1회	1,300 → 4,500ms	3,200ms
답변 검사	4,500 → 4,800ms	300ms
응답 전송	4,800 → 5,000ms	200ms

두 검색의 작업 시간을 더하면 1,200ms지만 요청은 그 구간에서 800ms를 기다린다. 같은 시간에 진행된 400ms를 두 번 세면 안 된다. 이 가정에서 전체 시간은 다음과 같다.

전체 = 200 + max(400, 800) + 300 + 3,200 + 300 + 200
     = 5,000ms

이때 완료 시점을 결정하는 경로는 입력 준비 → 벡터 검색 → 재정렬 → 모델 → 검사 → 전송이다. 이런 의존 관계상 가장 오래 걸리는 경로를 임계 경로라고 부른다. 여기서는 벡터 검색이 끝나야 다음 단계로 갈 수 있다. 키워드 검색은 먼저 끝나고 400ms의 여유가 있다.

따라서 세 개선안의 효과도 달라진다. 아래는 다른 단계의 시간과 결과 품질이 같다는 가정에서 한 계산이지, 개선 후의 실측 예측이 아니다.

바꾸는 한 가지	계산한 전체 시간	줄어드는 대기
키워드 검색 400 → 100ms	5,000ms	0ms
벡터 검색 800 → 400ms	4,600ms	400ms, 8%
모델 호출 3,200 → 1,600ms	3,400ms	1,600ms, 32%

첫 개선은 검색 서버의 자원 사용을 줄이는 데 가치가 있을 수 있지만, 이 요청의 대기는 줄이지 않는다. 두 번째에서는 벡터 검색을 400ms보다 더 줄여도 이제 키워드 검색의 400ms를 기다린다. 병목은 이동한다.

어느 쪽이든 모델 교체나 후보 축소로 답변 품질이 떨어지면 같은 업무의 개선이라고 볼 수 없다. 검색 두 개가 자원을 경쟁하거나 먼저 도착한 결과만 쓰는 구조, 검색 중 생성이 시작되는 구조에서는 위 식이 성립하지 않는다. 시간을 줄이기 전에 어떤 결과를 기다리는지부터 적어야 하는 이유다.

부모 시간을 빼서 CPU 시간을 구하면 안 되는 이유

위 retrieve 부모 span은 800ms이고 자식 합계는 1,200ms다. 부모에서 자식 시간을 단순히 빼면 −400ms가 나온다. 이는 계산 오류의 신호이지 “검색 조립이 마이너스 시간”을 썼다는 뜻이 아니다.

부모 구간 안에 들어온 직접 자식들의 시간 구간을 합집합으로 합치면, 자식이 덮은 벽시계 구간은 800ms다. 남은 0ms는 이 예시에서 자식으로 덮이지 않은 구간이 없다는 뜻일 뿐이다. 부모가 CPU를 전혀 쓰지 않았다는 증거는 아니다. 남는 구간이 있더라도 CPU 연산, 비계측 I/O, 실행 대기, 계측 누락 중 무엇인지는 별도 관측이 필요하다. 여러 호스트의 시각이 어긋나면 먼저 시계·전파 문제를 확인한다.

첫 chunk가 도착한 시간과 첫 답변이 보인 시간

“첫 응답이 빨라졌다”는 보고에서도 측정 경계가 필요하다. 첫 네트워크 조각에 표시할 답변이 없을 수 있고, 서버가 받은 답변이 아직 브라우저에 전달되지 않았을 수도 있기 때문이다.

2026-10-10 확인한 GenAI client inference 규약은 gen_ai.client.inference.time_to_first_chunk를 클라이언트가 생성 요청을 보낸 때부터 첫 chunk를 받은 때까지로 정의한다. 스트리밍 호출에 쓰는 지표이며 단위는 초다. 서버의 첫 토큰 지표는 모델 서버에서 첫 토큰을 생성하는 시간으로, 앱의 화면 표시 지연과 측정 범위가 다르다. 여기서 클라이언트는 모델을 호출하는 백엔드일 수도 있다.

이 GenAI 규약은 확인한 커밋에서 Development 상태다. 명칭을 장기 고정 계약으로 가정하지 말고 도입할 계측 라이브러리의 버전·실제 출력과 대조한다. 기존 OTel 사이트의 GenAI 페이지가 별도 공식 저장소로 이동한 것도 확인했다.

앞의 모델 호출에만 스트리밍을 적용한 변형을 생각해 보자. 호출은 1,300ms에 시작하고 첫 chunk는 1,900ms, 표시 가능한 첫 답변 내용은 백엔드에 2,300ms에 도착한다고 가정한다.

• 모델 호출 기준 첫 chunk 대기: 1,900 − 1,300 = 600ms, 규약의 초 단위로는 0.6초.
• 서버 요청 수신 기준 첫 답변 내용 확보: 2,300ms. 여기에 앞선 입력 준비·검색·재정렬이 이미 포함된다.
• 브라우저에 첫 답변 내용이 보인 시점: 브라우저 측 관측이 없으면 unknown.

검사가 끝난 뒤에만 전송하는 원래 설계라면 첫 chunk가 빨라져도 그 순간 사용자에게 보낼 수 없다. 반대로 일부 내용을 바로 보내는 설계에서는 체감 대기가 줄 수 있다. “처리 중”이라는 표시와 실제 답변의 첫 내용을 구분하고, 전송 클릭·첫 내용 표시·최종 표시를 같은 클라이언트 시계에서 따로 재면 이 차이를 볼 수 있다. 이는 앱에서 정할 측정 설계이며 OTel이 자동으로 보장하는 화면 지표가 아니다.

최종 성공 뒤에 숨은 재시도와 도구 대기

모델의 마지막 성공 호출이 3,200ms였다는 기록만 있으면 앞의 요청과 같아 보인다. 하지만 첫 시도가 2,000ms 뒤 시간 초과되고, 300ms 기다린 다음 같은 길이의 두 번째 시도가 성공했다면 어떨까.

논리적 생성 작업 = 실패한 시도 2,000 + 대기 300 + 성공한 시도 3,200
                 = 5,500ms
요청 전체       = 원래 5,000 + 추가된 2,000 + 300
                 = 7,300ms

최종 성공은 유지되지만 사용자는 2,300ms 더 기다린다. 논리적 작업 전체와 개별 시도를 구분하고, 시도 순번·종료 상태·재시도 대기를 남겨야 원인을 찾을 수 있다. SDK가 내부적으로 재시도하는 경우에는 바깥 호출 span 하나에 대기가 포함될 수도 있다. 실제 계측이 어디까지 감싸는지 확인하고, 정보가 없으면 시도별 시간을 추정해서 채우지 않는다.

주문 조회 같은 도구도 같은 방식으로 읽는다. 아래는 관측 결과를 다음 조사로 연결하는 판단표다. 원인을 확정하는 자동 규칙은 아니다.

보이는 현상	다음에 확인할 것
도구 호출 시작 전 빈 구간이 김	앱 대기열·동시 실행 제한·직전 단계의 비계측 작업
외부 호출 span 자체가 김	연결·전송·서버 처리 중 어디까지 분리 계측됐는지
마지막 호출은 짧은데 논리적 작업은 김	앞선 실패·재시도·backoff·다른 도구 의존성
첫 내용은 빠르지만 완료가 늦음	출력량·후속 도구·검사·전송, 취소 여부
자식 span이 갑자기 별도 trace로 나타남	프로세스·큐 경계의 문맥 전파와 샘플링 설정

취소·시간 초과는 성공 지연에서 누락시키지 말고 건수와 종료 이유를 따로 본다. 도구가 상태를 바꾸는 작업이라면 빠른 재시도 자체가 해결책은 아니다. 응답 유실 뒤 중복 실행 문제는 에이전트의 완료·복구 기준에서 별도로 다룬다.

원문을 모으기 전에 진단에 필요한 속성부터 고르기

시간이 어디에 쓰였는지 찾으려고 모든 프롬프트·답변·도구 인자를 복사할 필요는 없다. GenAI의 내용 수집 지침은 지시·입력·출력을 기본으로 수집하지 않고 선택적으로 켜는 방향을 설명한다. 그렇다고 모든 계측 라이브러리의 현재 기본값이 같다는 뜻은 아니다. 실제 export되는 데이터를 확인해야 한다.

진단용 속성은 아래처럼 시작할 수 있다. 이 표는 애플리케이션 설계 제안이며 표준 필드 목록이 아니다.

목적	우선 남길 정보	기본 수집에서 뺄 정보
요청 경로 연결	trace/span 식별자, 서비스·작업 이름	고객 이름을 넣은 span 이름
같은 조건끼리 비교	배포·모델·설정 버전, 캐시 적중 여부	프롬프트·검색 문서·답변 원문
크기 영향 확인	가용한 입력·출력 토큰 수, 검색 후보 수	문서 본문, 조회 대상의 개인 식별값
실패와 재시도 구분	정해진 상태 코드, 시도 수, 종료 이유	원문이 섞일 수 있는 예외 메시지 전체

식별자·토큰 수만 남겨도 자동으로 익명 데이터가 되는 것은 아니다. 접근 권한과 보관 기간을 정하고, 해시한 사용자 ID 역시 작은 후보 집합에서 다시 알아낼 수 있음을 고려한다. OpenTelemetry의 민감정보 처리 지침도 최소 수집과 해시의 한계를 설명한다. 원문 비교가 꼭 필요한 정확도 조사라면 운영 지연 기록과 목적·권한을 분리한다.

메트릭에 요청 ID나 원문을 라벨로 넣으면 값의 종류가 요청마다 늘어난다. 집계는 제한된 작업 이름·버전·상태 같은 차원으로 설계하고, 개별 요청의 상세 추적은 trace에서 찾는 편이 낫다. baggage에 고객 정보나 비밀값을 실어 모든 하위 호출로 전파하지 않는다. 전파 자체의 경계도 공식 문서의 보안 항목처럼 확인한다.

한 건을 설명하는 trace와 전체를 비교하는 지표

느린 요청 한 건을 찾았다고 전체 요청의 병목을 찾은 것은 아니다. 같은 작업·버전·입출력 길이 조건에서 얼마나 자주 그 경로가 나타나는지도 봐야 한다. p95는 관측값의 약 95%가 그 이하에 놓이는 지연 수준을 나타내지만, 대상 기간·표본·성공 및 실패 처리 방식이 없으면 숫자의 의미가 흐려진다. 단계별 p95를 더해 전체 요청의 p95로 쓰지 않는다. 각 단계에서 느린 요청이 서로 다를 수 있기 때문이다.

가상의 순차 작업 A·B를 거친 요청 100건을 생각해 보자. 90건은 A·B가 각각 1ms, 5건은 A만 100ms, 나머지 5건은 B만 100ms다. 오름차순 95번째 값을 p95로 정하면 A와 B의 p95는 각각 1ms지만, 전체 요청의 p95는 101ms다. 이는 분포의 차이를 보여 주는 검산 예이며 실제 지연 통계가 아니다.

OTel의 샘플링 설명에서 head sampling은 초기에 보관 여부를 결정하고, tail sampling은 뒤에 모인 span을 보고 지연·오류 같은 조건으로 선택할 수 있다. 후자는 늦게 온 기록을 기다리고 보관하는 운영 비용이 있다. 앞단에서 버린 trace를 뒤 단계가 되살릴 수도 없다.

느린 요청을 우선 남긴 trace 묶음의 p95나 오류 비율을 전체 서비스의 값으로 읽으면 선택 편향이 생긴다. 전체 추세는 수집 범위가 명확한 요청 수·실패/취소 수·지연 히스토그램으로 보고, trace는 원인 후보를 설명하는 데 쓴다. 메트릭 자체도 전송 누락과 수집 범위를 확인해야 한다. trace가 없다는 사실을 빠른 성공으로 기록하지 않는다.

다음 담당자가 다시 추측하지 않도록 남길 기록

다음 양식을 느린 요청 하나에 채워 두면 “모델이 느리다” 대신 검증할 변경 하나를 넘길 수 있다. 실제 고객 원문은 넣지 않는다.

작업 / 배포·모델·계측 버전 / 관측 기간:
측정 시작과 끝 / 같은 시계로 잰 범위:
전체 완료 / 첫 chunk / 첫 내용 표시 (없으면 unknown):
부모·자식 관계 / 실제로 기다리는 결과:
완료를 늦추는 경로 / 겹치는 작업 / 비계측 구간:
시도 수 / 실패·취소 / backoff / 외부 내부정보 제공 여부:
샘플링·수집 누락 / 비교 집단의 요청 수와 입력·출력 조건:
바꿀 한 가지 / 유지할 품질 기준 / 확인할 지표:
예상과 다른 결과가 나오면 되돌릴 조건:

앞의 5초 사례라면 “벡터 검색을 400ms로 줄이면 다른 조건이 같을 때 400ms 단축될 수 있다”가 시험할 가설이다. 같은 질문 묶음에서 근거 정확도와 실제 전체 지연을 다시 측정해야 채택할 수 있다. 빨라졌지만 답이 틀리면 RAG의 오류 단계 진단으로, 모델 구간과 문맥 길이의 관계를 더 좁혀야 하면 추론 메모리와 KV 캐시로 이어서 읽을 수 있다.

다음 장애 때 이 시간표와 양식이 필요하다면 글 위의 저장 기능으로 다시 찾을 수 있다. 후속 글은 AI 시스템 주제 모음과 RSS에서 확인할 수 있다. 이 글이 제공하는 것은 측정 경계와 판단 방법이며, 특정 서비스의 병목이나 개선 효과는 해당 서비스에서 수집한 증거로 결정해야 한다.