AI 코딩 사용량 측정의 30초 타임아웃 문제
AI 코딩 세션의 사용량과 비용을 기록하던 중 이상한 점을 발견했다. 한 세션에 비용 항목이 아예 없었던 것이다.
처음에는 측정 도구가 실패한 것이라고 생각했다. 하지만 같은 Claude Code 세션에 agent-cost를 직접 실행해 보니 36.454초 만에 정상 완료됐다. 반면 spec-lane 어댑터를 통해 같은 측정을 수행하자 30.019초 후 실패했다.
원인은 단순했다. 호출자 쪽에 30초 타임아웃이 걸려 있었기 때문이다.
타임아웃 자체보다 더 중요했던 것은 그 이후에 일어난 일이었다. 실패한 측정은 $0 기록을 남기지 않았다. 아예 측정 기록이 생성되지 않았다.
그 차이가 이번 사건의 핵심 교훈이 되었다.
측정 실패 != $0 무언가를 측정하지 못한 것은 그것을 0으로 측정한 것과 같지 않다.
같은 세션이 직접 실행에서는 성공하고 어댑터를 통하면 실패했다
먼저 Issue #42의 세션을 agent-cost로 직접 다시 실행해 보았다:
agent-cost measure \
--format json \
--session-id <session-id>결과는 다음과 같았다:
exit: 0
wall: 36.454s
JSON parse: success
protocol: measure/v1측정에는 30초가 넘게 걸렸지만, 정상적으로 완료됐다.
그다음에는 수정 전 Git 리비전 cca0338...으로 만든 AgentCostTelemetryAdapter를 통해 같은 세션을 전달했다.
30.019s
TelemetryImportFailed
Command failed이번에는 30초 지점쯤에서 멈췄다.
비교해 보면:
| 경로 | 결과 | 시간 |
|---|---|---|
| 직접 agent-cost 측정 | 성공 | 36.454초 |
| 수정 전 어댑터 | 타임아웃 | 30.019초 |
| 수정 후 어댑터 | 성공 | 35.410초 |
수정 전 어댑터에는 기본값이 이렇게 설정돼 있었다:
this.timeoutMs = opts.timeoutMs ?? 30_000;즉, 실제 측정은 약 36초 만에 끝날 수 있었지만, 호출자는 30초가 지나자 이를 강제로 종료한 것이다.
또 다른 문제도 있었다. 오류 메시지가 단지 Command failed뿐이었다는 점이다. 타임아웃이 발생했는지, 또는 30초 후 프로세스가 중단됐는지를 알 수 없었다.
그 메시지만으로는 agent-cost 내부에서 실패한 것인지, 아니면 호출자가 부여한 제한 시간 때문에 종료된 것인지 구분하기 어려웠다.
기록이 없다는 것은 0달러 기록이 아니라는 뜻이다
나는 실패한 측정이 무엇을 남기는지 확인하고 싶었다.
이 부분에서는 의도적으로 짧은 타임아웃을 설정한 별도의 통제된 재현을 사용했다. 이는 위의 시간 비교에서 사용한 실제 세션과는 다른 것이다.
lane calibrate가 측정 도중 실패했을 때 결과는 다음과 같았다:
CalibrationObservation: 0
cost_ledger: 0다음과 같은 기록을 남기지는 않았다:
{
"cost_usd": 0
}그냥 기록이 없었다.
소스 코드도 그 동작과 일치했다. adapter.measure()가 실패하면, 명령은 관측치를 생성하기 전에, 그리고 비용 원장을 기록하기 전에 반환된다.
빈 원장을 대상으로 emit-metrics를 실행하면 다음이 출력됐다:
built 0 record(s), coverage.status=no_data여기서 no_data는 "측정된 비용이 0이었다"는 뜻이 아니다. 측정된 기록 자체가 없다는 뜻이다.
수치가 집계되기 시작하면 이 차이는 중요해진다. 100개의 작업 중 실패한 측정 10개가 조용히 $0으로 바뀐다면, 결과 평균은 실제 근거보다 더 낮아 보일 수 있다.
0은 하나의 값이다. 측정 증거가 없다는 것은 다른 상태다.
수정은 30초를 180초로 바꾸는 것보다 더 큰 의미가 있었다
PR #43은 기본 타임아웃을 30초에서 180초로 변경했다:
DEFAULT_AGENT_COST_TIMEOUT_MS = 180_000또한 CLI 오버라이드도 추가했다:
--agent-cost-timeout-ms <n>이 옵션은 다음 네 가지 명령에서 사용할 수 있다:
calibrate
emit-metrics
next
usage-import
허용 범위는 1ms부터 3_600_000ms까지다.
타임아웃 오류도 더 명확해졌다. 예를 들어, 의도적으로 200ms 타임아웃을 주면 이제 다음과 같이 보고된다:
timed out after 200 ms (killed with SIGTERM)이제는 측정 명령 자체가 실패한 것인지, 아니면 호출자가 기한 때문에 강제로 종료한 것인지 훨씬 쉽게 구분할 수 있다.
다만 여기에도 한계는 있다. 180초는 엄격한 벽시계 보장이 아니다. 구현은 타임아웃에 도달하면 SIGTERM을 보낸다. 그 신호를 받은 뒤에도 즉시 종료하지 않는 자식 프로세스는 명목상의 타임아웃을 넘어 계속 실행될 수 있다.
수정 후에는 38초짜리 실행도 측정을 보존했다
타임아웃을 늘리는 것은 측정이 실제로 끝나고 그 증거가 저장될 수 있을 때만 의미가 있다.
나는 기본 180초 타임아웃을 사용하는 v0.10.1 CLI로 또 다른 과거 세션과 lane 스냅샷을 다시 실행했다.
exit: 0
wall: 38.01s이번에는 성공적으로 반환되는 데서 끝나지 않았다:
CalibrationObservation: 1
cost_ledger: scope=lane
emit-metrics: coverage.status=complete관측치가 생성됐고, 비용 원장이 기록됐으며, 메트릭 커버리지는 complete에 도달했다.
또한 약 39초의 성공적인 실행을 보고하는 과거 PR 기록도 있습니다. 저는 이를 별도로 다룹니다. 정확한 과거 wall time이 담긴 원시 로그는 더 이상 남아 있지 않으므로, 그 보고된 값은 독립적으로 재현한 38.01초 실행과 같은 증거가 아닙니다.
측정을 완료했다고 해서 숫자가 맞다는 뜻은 아니다
수정을 확인하는 동안 또 하나의 경계가 중요하다는 점이 드러났습니다.
여기서 제가 확인한 것은 측정 프로세스가 완료되고, 프로토콜 페이로드를 반환하며, 결과를 보존할 수 있다는 점입니다.
그것은 다음을 모두 증명하지는 않습니다.
- 추정 달러 금액이 정확하다는 것
- 가격 카탈로그가 정확하다는 것
- 세션이 올바른 작업에 귀속되었다는 것
사실 과거 기록과 새로 재현한 실행은 서로 다른 토큰 수와 추정 비용을 만들어냈습니다. 또한 서로 다른 agent-cost 버전을 사용했습니다.
저는 이 timeout 작업의 일부로 그 차이의 원인을 조사하지는 않았습니다.
측정 완료, 비용 정확성, 작업 귀속은 서로 다른 주장입니다. 성공적인 실행이 입증하는 것은 첫 번째뿐입니다.
exit 0이더라도 측정이 완료되지 않았을 수 있다
기억해 둘 만한 또 하나의 엣지 케이스가 있었습니다.
calibrate는 측정에 실패하면 종료 코드 2로 종료합니다. 하지만 usage-import는 다른 계약을 갖고 있습니다.
일부 측정 실패 사례에서는 다음을 기록합니다:
measurement-incomplete
matched: false그리고 ledger 항목은 쓰지 않으면서도 exit 0을 반환합니다.
따라서 이것도 안전한 동치 관계는 아닙니다.
exit 0 == measurement succeeded종료 코드, 측정 상태, 보존된 증거는 각각 따로 해석해야 합니다.
알 수 없는 값을 0으로 합치지 말 것
직접적인 버그는 30초 timeout이었습니다. 하지만 제게 더 유용했던 교훈은 상태 표현에 관한 것이었습니다.
측정 시스템에서 다음은 서로 바꿔 쓸 수 없습니다.
0
unknown
failed
not measured이들을 모두 0으로 합쳐 버리면 집계는 쉬워집니다. 하지만 실제로 무슨 일이 일어났는지에 대한 정보도 함께 사라집니다.
이것은 AI 코딩 비용을 넘어선 문제이기도 합니다. 테스트 결과, 평가 점수, 사용량 지표, 관찰 가능성 파이프라인 모두 같은 문제에 부딪힐 수 있습니다.
Issue #42에서 제가 가져온 규칙은 여전히 가장 간단한 설명입니다.
측정 실패 != $0
엔지니어링 워크플로우의 더 많은 부분이 자동화될수록, “값이 0이었다”와 “값을 얻지 못했다”의 차이를 보존하는 일은 덜 중요한 것이 아니라 더 중요해집니다.
참고 자료
원래 이슈에 보고된 버전에 대한 참고
Issue #42에는 과거 실행 시간이 다음과 같이 기록되어 있습니다:
lane 0.9.1, cca0338 on main하지만 Git에서 cca0338...는 v0.10.0 태그에 대해 peel된 커밋이며, 해당 리비전의 packages/cli/package.json은 버전 0.10.0을 보고합니다.
이 글의 30.019초 재현은 cca0338... 소스 리비전으로 빌드되었습니다.
과거 실행 파일이 왜 0.9.1을 보고했는지는 확인하지 못했으므로, 원래 사건이 v0.10.0 CLI에서 발생했다고는 주장하지 않습니다.
출처
- 원문: https://dev.to/shikiyusuke/the-cost-wasnt-0-my-ai-coding-measurement-timed-out-at-30-seconds-198e (2026-10-11 · Yusuke Shiki)