내가 만든 것

이 에이전트는 의도적으로 작게 설계되었습니다. 주제를 입력하면 세 가지 작업을 수행합니다. 먼저 LLM에게 주제를 세 가지 하위 질문으로 나누도록 요청하고, 각각의 질문에 대해 별도의 LLM 호출로 답변을 구한 다음, 마지막으로 답변들을 하나의 짧은 요약으로 결합하기 위해 한 번 더 호출합니다. 이 에이전트는 FastAPI로 구축되었으며 OpenAI의 gpt-4o-mini를 사용합니다.

단일 요청에 대해 총 5번의 LLM 호출이 발생합니다. 항상 합리적인 답변을 반환했기 때문에 기능적으로는 "완료"된 상태였습니다. 하지만 일반적인 HTTP 로그는 전체 요청에 10초가 걸렸다는 사실만 알려줄 뿐, 그 5번의 호출 중 어떤 것이 시간을 잡아먹었는지, 각 호출에서 토큰을 얼마나 소모했는지, 혹은 그중 일부를 동시에 실행할 수 있었는지에 대해서는 알려주지 않습니다. 그것이 바로 제가 메우고 싶었던 간극이었으며, 이것이 바로 트레이싱 (Tracing)이 존재하는 이유입니다. 즉, 하나의 요청 내부를 단계별로 들여다보는 것입니다.

Windows (WSL 2)에서 SigNoz 설정하기

따라하기 위해 필요한 것: WSL 2(저는 Ubuntu를 사용했습니다)가 설치된 Windows, Docker, Python 3, 그리고 OpenAI API 키.

저는 전체 스택을 제 컴퓨터에 두고 싶었기 때문에 클라우드 버전 대신 SigNoz를 셀프 호스팅 (Self-hosted)했습니다. Windows에서 이는 WSL 2 내부에서 작업함을 의미하며, 제가 처음 배운 사실은 내가 가지고 있다고 생각하는 Docker가 항상 사용할 수 있는 Docker는 아니라는 점이었습니다.

저는 Docker Desktop을 설치해 두었지만, Ubuntu WSL 배포판 내부에서 docker를 실행했을 때 다음과 같은 메시지가 나타났습니다:

The command 'docker' could not be found in this WSL 2 distro.

Docker Desktop은 엔진을 별도의 WSL 배포판에 보관하며, 제 경우에는 Ubuntu와 연결되어 있지 않았습니다. Docker Desktop 통합 기능과 씨름하는 대신, 저는 Ubuntu 내부에 Docker를 네이티브로 설치했습니다:

curl -fsSL https://get.docker.com | sh
sudo usermod -aG docker $USER

wsl --shutdown을 실행한 후 Ubuntu를 다시 열자, docker ps 명령어가 마침내 깨끗하고 비어 있는 테이블을 반환했습니다. 이는 데몬 (Daemon)에 실제로 접근할 수 있다는 신호였습니다.

그다음 SigNoz 자체를 설치합니다. Foundry CLI를 사용합니다 (현재 설치 방법이며, 이전의 install.sh 스크립트는 더 이상 사용되지 않습니다):

curl -fsSL https://signoz.io/foundry.sh | bash

설치를 설명하는 casting.yaml을 생성하고, foundryctl cast -f casting.yaml을 실행했습니다. 몇 분간의 이미지 풀링(image pulls) 후, docker ps를 통해 전체 스택이 정상(healthy)임을 확인했습니다: 8080 포트의 SigNoz, 4317/4318 포트의 OTel collector. 한 가지 특이사항은 signoz-mcp 컨테이너가 unhealthy로 표시된다는 점인데, 이는 실제 실패가 아닌 외관상의 헬스체크(healthcheck) 문제입니다.

[SCREENSHOT: empty SigNoz workspace, "you're not sending any data yet"]

전체적인 구성 방식은 다음과 같습니다:

   POST /research
        │
        ▼
...

신뢰하기 전에 파이프라인 테스트하기

실제 앱에 계측(instrumentation)을 적용하기 전에, 텔레메트리 파이프라인(telemetry pipeline)이 실제로 작동하는지 확인하고 싶었습니다. 그래서 Docker 네트워크를 통해 telemetrygen을 사용하여 컬렉터(collector)로 직접 몇 개의 테스트 트레이스(traces)를 보냈습니다:

docker run --rm --network signoz-network \
  ghcr.io/open-telemetry/opentelemetry-collector-contrib/telemetrygen:latest \
  traces --otlp-endpoint signoz-ingester-1:4317 --otlp-insecure --traces 5

약 30초 이내에 SigNoz에 5개의 트레이스를 가진 telemetrygen 서비스가 나타났습니다. 이를 통해 컬렉터에서 ClickHouse를 거쳐 UI에 이르기까지 전체 경로가 작동하고 있음을 확인했습니다. 이 작업은 나중에 큰 도움이 되었습니다. 제 앱의 데이터가 느리게 나타났을 때, 파이프라인은 정상이며 문제는 제 설정(config)에 있다는 것을 이미 알고 있었기 때문입니다.

[SCREENSHOT: telemetrygen traces in SigNoz (optional)]

에이전트 계측하기

SigNoz가 실행 중인 상태에서, 에이전트가 실제로 데이터를 전송하도록 만들어야 했습니다. OpenTelemetry에는 두 가지 수준의 계측이 있으며, 저는 두 가지를 모두 사용했습니다.

첫 번째는 적은 노력으로 얻을 수 있는 이점인 자동 계측(auto-instrumentation)입니다. 코드 변경 없이 몇 가지 설치와 래퍼(wrapper) 명령만으로 가능합니다:

pip install opentelemetry-distro opentelemetry-exporter-otlp opentelemetry-instrumentation-fastapi
opentelemetry-bootstrap -a install

그 다음, 일반적인 uvicorn 대신 OpenTelemetry 래퍼를 통해 앱을 실행했습니다:

opentelemetry-instrument uvicorn app:app --port 8001

사람들이 흔히 실수하는 세부 사항 하나는 다음과 같습니다. 제 앱은 Docker 내부가 아니라 WSL 호스트에서 실행되므로, 텔레메트리 (telemetry) 엔드포인트는 Docker 네트워크 내부에서 사용하는 컨테이너 이름인 signoz-ingester-1이 아니라 localhost:4318이어야 합니다. 이를 잘못 설정하면 오류 메시지 없이 데이터가 전혀 나타나지 않는 '조용한 실패 (silent failure)'가 발생합니다.

그것만으로도 들어오는 FastAPI 요청과 OpenAI 호출이 SigNoz로 전달되었습니다. 하지만 자동 계측 (auto-instrumentation)은 "chat gpt-4o-mini"가 다섯 번 나타나는 것과 같은 일반적인 스팬 (span)들만 제공합니다. 이는 각 호출이 제 파이프라인의 어느 단계에 속하는지 알려주지 못합니다. 그래서 저는 각 단계를 라벨링하고 제가 실제로 중요하게 생각하는 수치들을 첨부하기 위해 수동 스팬 (manual spans)을 추가했습니다:

def ask_llm(step_name: str, prompt: str) -> str:
    with tracer.start_as_current_span(step_name) as span:
        resp = client.chat.completions.create(
...

이제 모든 LLM 스팬 (span)은 실제 토큰 수와 달러 비용을 포함하며, 파이프라인 단계(plan_questions, answer_questions, combine_summary)가 익명의 HTTP 호출 대신 이름이 지정된 스팬 (span)으로 트레이스 (trace)에 나타납니다. (제 실행 결과에 따르면, 단일 연구 요청의 토큰 비용은 약 $[llm.cost_usd\ 스팬에서 채워 넣을 값]였습니다.)

[IMG:1]

[IMG:2]

내부 들여다보기: 계단형 구조

커스텀 스팬 (custom spans)이 흐르기 시작하자, 저는 SigNoz에서 /research 트레이스 (trace) 하나를 열었고 마침내 그 10초가 어디로 사라졌는지 확인할 수 있었습니다. 플레임 그래프 (flame graph)는 로그가 결코 해낼 수 없는 방식으로 그 사실을 명확하게 보여주었습니다.

다섯 번의 LLM 호출은 서로 겹치지 않았습니다. 그것들은 완벽한 계단 모양으로 하나씩 차례대로 실행되고 있었습니다. plan_questions가 완료된 후에 첫 번째 답변 호출이 시작되었고, 그다음 두 번째, 그다음 세 번째, 그다음 결합 (combine) 단계가 이어졌습니다. 각 단계는 이전 단계가 끝나기를 기다렸습니다.

수치가 그 이야기를 들려주었습니다:

• 전체 요청: 10.48s
• answer_questions 단독: 6.54s, 전체 요청의 절반 이상 차지
• 그 내부에서, 세 번의 별도 답변 호출이 연속해서 실행됨 (대략 2.76s, 1.33s, 그리고 2.45s)

그리고 여기서 깨달음을 얻은 지점이 있습니다. 바로 그 세 번의 답변 호출이 완전히 독립적이라는 사실입니다. 하나의 하위 질문에 답변하는 것이 다른 질문의 답변에 의존하지 않았습니다. 단지 제가 단순한 for 루프를 작성했기 때문에 한 번에 하나씩만 실행되고 있었던 것입니다. 그것은 코드를 작성하는 가장 자연스러운 방식이지만, 동시에 가장 낭비적인 방식이기도 했습니다. 제 에이전트는 아무 이유 없이 LLM을 줄 세워 기다리게 만들고 있었습니다.

저는 이 버그를 계획하지 않았습니다. 트레이스(trace)가 저에게 보여주기 전까지는 그것이 존재하는지조차 몰랐습니다. 이것이 바로 제가 트레이싱(tracing)에 매료된 이유입니다. 비효율성은 코드 리뷰나 로그에 들어있던 것이 아니었습니다. 그것은 폭포(waterfall) 차트의 형태 속에 너무나 명백하게 자리 잡고 있었습니다.

[SCREENSHOT: BEFORE 트레이스, 10.48s 계단형 구조]

해결책: 줄 서서 기다리는 것을 멈추기

해결책은 트레이스가 보여준 결과로부터 직접적으로 도출되었습니다. 세 번의 답변 호출이 독립적이라면, 하나씩 실행되어서는 안 됩니다. 동시에 실행되어야 합니다. 저는 순차적인 for 루프를 스레드 풀(thread pool)로 교체하여 세 호출 모두가 병렬(parallel)로 실행되도록 했습니다.

with ThreadPoolExecutor(max_workers=3) as pool:
    futures = [
        pool.submit(ask_llm_ctx, ctx, f"llm.answer_{i+1}", f"Answer in 2 sentences: {question}")
...

하지만 여기서 진짜 주의해야 할 점(gotcha)을 만났습니다. 스레드가 사용된 무언가를 트레이싱한다면 반드시 알아두어야 할 내용입니다. OpenTelemetry의 트레이스 컨텍스트(trace context)는 새로운 스레드로 자동으로 넘어가지 않습니다. 병렬 버전을 처음 실행했을 때, 세 개의 답변 스팬(span)은 요청 아래에 중첩되지 않고 각각 별개의 트레이스로 분리되어 떠다녔으며, 폭포 차트는 무너져 버렸습니다.

해결책은 스레드를 생성하기 전에 현재 컨텍스트를 캡처하고, 각 워커(worker) 내부에서 이를 다시 연결(re-attach)하는 것이었습니다.

def ask_llm_ctx(ctx, step_name, prompt):
    token = attach(ctx)
    try:
...

이 조치를 취한 후, 동일한 요청을 다시 실행하고 새로운 트레이스를 열었습니다. 계단형 구조는 사라졌습니다. 이제 세 번의 답변 호출이 동시에 시작되어 서로 겹쳐졌습니다. answer_questions는 6.54s에서 약 1.65s로 단축되었는데, 이는 세 호출의 합계가 아니라 가장 느린 단일 호출의 길이에 맞춰진 결과였습니다.

전체 요청 시간은 10.48s에서 5.62s로 약 46% 단축되었습니다. 이는 오직 트레이스 (trace)를 통해 어디를 수정해야 할지 알 수 있었기에 가능했던 변화였습니다.

수정 후의 전체 엔드포인트 코드는 다음과 같습니다. 이를 통해 직접 재현해 보실 수 있습니다 (원본과의 유일한 실제 차이점은 2단계가 일반적인 for 루프 대신 스레드 풀 (thread pool)에서 실행된다는 점입니다):

from concurrent.futures import ThreadPoolExecutor
from opentelemetry import trace
from opentelemetry.context import attach, detach, get_current
...

[IMG:1] (수정 후의 트레이스, 5.62s, 겹쳐진 호출들. 대조를 위해 이전의 계단식 구조 바로 옆에 배치하세요.)

단일 트레이스를 넘어: 대시보드와 알림

하나의 트레이스는 문제를 보여주었지만, 트레이스는 단일 요청에 불과합니다. 시간에 따른 동작을 관찰하기 위해, 저는 트레이스 데이터에서 POST /research의 p95 지연 시간 (p95 latency)을 도식화하는 대시보드 패널을 구축했습니다 (p95(durationNano)를 사용하고 해당 서비스로 필터링함).

느린 순차적 버전과 빠른 병렬 버전을 모두 실행했기 때문에, 이 패널은 하나의 선에 전체 이야기를 담아냈습니다. 지연 시간이 약 10초 근처에 머물다가, 수정 후 5초 근처로 떨어져 안정화되는 모습이 나타났습니다. 방금 수행한 최적화가 일회성 사건이 아닌 하나의 추세 (trend)로 시각화된 것입니다.

그 다음으로 가드레일 (guardrail)을 추가했습니다. 5분 창 (window) 내에서 p95 지연 시간이 최소 한 번이라도 8초를 초과하면 발동하는 트레이스 기반 알림 (trace-based alert)입니다. 아이디어는 간단합니다. 만약 순차적 지연 현상이 다시 나타난다면 (잘못된 리팩터링 (refactor)이나 새로운 블로킹 호출 (blocking call) 등으로 인해), 사용자가 알기 전에 제가 먼저 알고 싶기 때문입니다. 저는 이를 테스트 웹훅 (webhook)에 연결하고, 실제로 알림이 전달되는지 확인하기 위해 테스트 알림을 발송했습니다.

이 과정을 따라오시는 분들을 위해 한 가지 짚고 넘어갈 작은 팁이 있습니다. SigNoz는 알림 채널 (notification channel)을 연결하지 않으면 알림 규칙 (alert rule)을 저장할 수 없으므로, 채널을 먼저 만든 후 규칙을 생성하십시오.

[IMG:2] (지연 시간 대시보드, ~10s에서 ~5s로 떨어지는 p95 선)

[IMG:3] (설정된 알림 규칙)

시작하기 전의 나에게 해주고 싶은 말

이번 과정을 통해 실제로 얻은 몇 가지 교훈은 다음과 같습니다:

자동 계측 (Auto-instrumentation)은 형태를 보여주지만, 커스텀 스팬 (custom spans)은 정답을 제공합니다. 래퍼 (wrapper)를 통해 몇 분 만에 데이터가 흐르기 시작했지만, 그것은 일반적이었습니다: 이름 없는 다섯 개의 LLM 호출일 뿐이었죠. 통찰력은 제가 직접 이름을 붙인 스팬 (spans)을 추가하고 토큰 (token) 및 비용 (cost) 수치를 연결한 후에야 나타났습니다. 노력이 적게 드는 버전을 먼저 시도해 볼 가치는 있지만, 진정한 가치는 그곳에 있지 않습니다.

트레이스 (trace)는 코드 리뷰가 보여주지 못하는 것을 보여줄 수 있습니다. 저는 그 for 루프를 수없이 읽었지만 한 번도 의심하지 않았습니다. 플레임 그래프 (flame graph)에서 계단 모양을 보고 나서야 그 호출들이 독립적이며 병렬로 실행될 수 있다는 사실을 깨달았습니다. 버그는 코드 속에 숨겨져 있었던 것이 아닙니다. 그것은 타이밍 (timing) 속에 숨겨져 있었고, 타이밍이야말로 트레이스 (trace)가 가시화해 주는 바로 그 요소입니다.

Windows에서는 Docker를 WSL 주변이 아니라 WSL 내부에 설치하세요. Docker Desktop의 WSL 통합 기능과 씨름하는 것은 그만한 가치가 없었습니다. Ubuntu 내부에 네이티브로 설치하는 것이 더 간단했고 그냥 잘 작동했습니다.

텔레메트리 (telemetry) 파이프라인을 구축하기 전에 먼저 검증하세요. 실제 무언가를 계측하기 전에, telemetrygen으로 몇 개의 테스트 트레이스 (traces)를 보내 SigNoz에 잘 도착하는지 확인했습니다. 그 5분간의 점검 덕분에, 나중에 앱의 데이터가 나타나지 않았을 때 파이프라인은 문제가 없고 제 설정이 문제라는 것을 확신할 수 있었습니다.

마무리하며

저는 터미널에서 docker조차 실행하지 못하는 상태로 밤을 시작했지만, 트레이스 (trace)를 통해 제 AI 에이전트가 왜 필요 이상으로 두 배나 느렸는지 정확히 파악하고, 동일한 도구로 수정 사항이 제대로 작동하는 것을 확인하며 밤을 마쳤습니다. 에이전트의 출력값은 변하지 않았습니다. 변한 것은 제가 마침내 그것이 무엇을 하고 있는지 볼 수 있게 되었다는 점입니다. 그것이 핵심입니다. 볼 수 없는 것은 고칠 수 없으며, 다단계 AI 에이전트의 경우 트레이스 (trace)가 바로 그것을 볼 수 있게 해주는 방법입니다.

같은 시도를 해보고 싶다면, 제가 사용한 모든 것은 오픈 소스이며 자체 호스팅이 가능합니다: SigNoz, OpenTelemetry, 그리고 OpenAI Python SDK입니다. SigNoz를 자체 호스팅하고, 이미 보유하고 있는 실제 앱 하나를 계측한 뒤, 단 하나의 트레이스 (trace)를 열어보세요. 여러분도 예상치 못한 무언가를 발견하게 될 것이라고 확신합니다.