toki/iop

toki c578442a6c docs(handoff): 스트리밍 세션 정지 진단을 인계한다

2026-08-13 09:16:34 +09:00

14 KiB

Raw Blame History

handoff_version	handoff_status	created_at	target	local_source_revision	observed_dev_revision
1	implementation-not-started	2026-08-13	dev OpenAI-compatible ornith:35b streaming session stall	`b205433a32`	`fd32abb4b6`

Handoff: `ornith:35b` streaming session stall과 terminal 지연

현재 타겟

증상: Chronos agent-task에서 Pi iop/ornith:35b worker가 failed:session-stall:143으로 세 번 연속 종료된다.
범위: IOP dev OpenAI-compatible Chat Completions provider tunnel, Stream Evidence Gate, Node/provider liveness timeout 정합성.
상태: 진단만 수행했다. 코드, 설정, 배포는 변경하지 않았다.
다음 세션 첫 진입점:
1. apps/edge/internal/openai/stream_gate_runtime.go
2. apps/edge/internal/openai/stream_gate_tunnel_codec.go
3. apps/node/internal/adapters/openai_compat/provider_tunnel.go
4. packages/go/execution/liveness.go

환경 정정

초기 조사에서 dev-corp를 열어 DGX Spark 설정을 본 것은 잘못된 환경 선택이었다. Spark 관련 해석은 이 장애의 근거로 사용하지 않는다.

실제 Pi가 호출한 dev Edge 런타임을 기준으로 다시 확인했다.

dev에는 gx10-vllm-node, onexplayer-lemonade-node, rtx5090-lemonade-node가 등록돼 있다.
현재 배포 설정에서 gx10-vllm은 laguna-s:2.1에 연결돼 있다.
현재 ornith:35b는 onexplayer-lemonade와 rtx5090-lemonade에 연결돼 있다.
이번 세 실패의 마지막 요청은 모두 실제 provider onexplayer-lemonade로 dispatch됐다.
제품 의도가 ornith:35b도 GX10에서 실행되는 것이라면, 현재 배포 route/catalog가 그 의도와 다르다. 구현 전에 운영 의도와 현재 binding을 먼저 확정해야 한다.

확정된 관측

Chronos dispatcher의 세 attempt는 모두 native session이 active이고 pending tool call이 없는 상태에서 약 180초 동안 새 출력이 없어 dispatcher가 SIGTERM을 보냈다. Unix exit 143은 이 SIGTERM의 결과이며 provider가 직접 반환한 오류 코드가 아니다.

Attempt	마지막 IOP 요청	StreamGate 관측	Chronos 종료
21	입력 추정 `40,665` tokens, `onexplayer-lemonade`	네 번 release 후 terminal 없음	silence `180.048s`, dispatcher `SIGTERM`
22	입력 추정 `40,830` tokens, `onexplayer-lemonade`	두 번 release 후 terminal 없음	silence `180.063s`, dispatcher `SIGTERM`
23	`40,995`-token turn은 약 `224.7s` 뒤 정상 terminal; 다음 `41,080`-token turn도 같은 provider	다음 turn은 `response_start`만 staging되고 delta/terminal 없음	silence `180.070s`, dispatcher `SIGTERM`

Chronos 측 마지막 출력 시각과 IOP의 마지막 release_committed 시각이 밀리초 수준으로 일치한다. IOP 이후 Pi/dispatcher 구간에서 출력이 별도로 유실된 정황은 없다.

Stream Evidence Gate 판정

dev Edge에서 stream_evidence_gate.enabled=true이며 다음 정책이 ornith:35b에만 selector로 적용된다.

filter: repeat_guard
enforcement: blocking
hold: 500 Unicode runes
filter timeout: 5000ms

그러나 실패 시간대의 raw-free filter observation은 모두 다음과 같다.

openai.repeat_guard: pass, repeat_rolling_clear
attempt 23의 정상 완료 turn: openai.repeat_guard.action도 pass, repeat_action_clear
violation, fatal, recover, continuation dispatch는 없음

따라서 반복 검증 판정이 요청을 차단하거나 recovery loop에 넣은 것이 직접 원인은 아니다.

다만 500-rune rolling hold는 증상을 확대한다. 이 값은 항상 마지막 500 runes를 보류한다는 뜻이 아니다. pending이 500 runes 미만이면 평가와 release를 기다리고, 500 이상이 되면 filter를 평가해 pass 시 그 epoch의 pending 전체를 즉시 release한다. terminal trigger가 오면 500 미만이어도 평가한다. 따라서 provider가 다음 delta나 terminal trigger를 보내지 않으면 현재 sub-threshold pending tail만 caller에게 release되지 않는다. caller가 180초 후 종료되면 그 tail도 정상 terminal 없이 폐기된다.

종료 신호 경계와 현재 관측 공백

OpenAI-compatible stream에는 서로 다른 계층의 종료 신호가 있다.

choices[].finish_reason: 모델 생성이 끝났다는 논리적 완료 신호
SSE data: [DONE]: OpenAI stream framing의 완료 신호
upstream response EOF와 Node tunnel END: 실제 transport 완료 신호
StreamGate Core terminal: codec/runtime이 위 신호를 normalized terminal로 변환한 결과

현재 codec은 finish_reason chunk를 terminal trigger로 만들지 않고 wire-only frame으로 staging한다. [DONE] 또는 tunnel END가 와야 Core terminal 경로가 실행된다. 그러므로 finish_reason은 도착했지만 [DONE]/EOF/END가 지연되거나 누락되면, 500-rune 미만 pending tail과 staged finish frame이 함께 보류될 수 있다.

기존 raw-free observation으로 확인된 것은 실패 요청에서 Core terminal 및 tunnel END가 관측되지 않았다는 사실까지다. 실패 요청에 finish_reason이 먼저 도착했는지, [DONE]이 codec에 도착했지만 변환 중 유실됐는지는 현재 로그만으로 확정할 수 없다. 따라서 이 경계는 확정 원인이 아니라 코드상 유력한 버그 후보로 취급한다.

현재 원인 판정

확인됨

요청은 Edge admission을 통과했고 provider tunnel의 response start와 일부 body를 받았다.
실패한 turn에서 repeat_guard는 모두 pass했다.
마지막 release 뒤 Node tunnel의 END, provider error terminal 또는 Core terminal이 오지 않았다.
attempt 23의 다음 turn은 response start 뒤 body 자체가 오지 않았다.
세 요청 모두 약 40.7k~41.1k input-token 장문맥이고 실제 provider는 onexplayer-lemonade였다.

유력하지만 추가 분리가 필요함

onexplayer-lemonade backend가 장문맥 생성 중 진행을 멈췄거나, Node의 upstream HTTP reader/tunnel relay가 body 또는 EOF/END를 전달하지 못했을 가능성이 높다. 현재 Edge observation만으로는 provider backend와 Node relay 중 정확한 소유자를 단정할 수 없다.

timeout 정합성 결함

Chronos dispatcher session silence timeout: 180s
IOP Node response_stall_timeout_ms: 배포 설정에서 생략됨
생략 시 IOP 기본 response stall timeout: 300000ms
dev Edge OpenAI request timeout: 3600s

따라서 Chronos가 180초에 Pi를 종료해 버리고, IOP Node의 300초 liveness watchdog은 typed response_stalled terminal을 만들 기회를 얻지 못한다. 이 순서 때문에 IOP의 terminal/error/recovery 경계가 동작하기 전에 외부에서 143으로 끝난다.

부분 출력이 이미 caller에게 commit된 attempt 21/22는 stall을 감지하더라도 exact replay 대상이 아니다. 그래도 IOP가 dispatcher보다 먼저 명시적 error terminal을 보내야 truncated open stream 대신 원인을 관측할 수 있다. attempt 23의 두 번째 turn처럼 caller-visible commit 전 stall은 alternate provider exact replay 후보가 될 수 있다.

Pi TUI가 정상인 이유

Pi TUI가 Stream Evidence Gate를 우회하는 것은 아니다. 같은 OpenAI-compatible 경로를 사용한다.

TUI에는 Chronos dispatcher의 180초 silence watchdog이 없다.
보통 fresh 또는 더 짧은 context에서 호출된다.
이번 stall은 결정적이지 않다. attempt 23의 첫 40,995-token turn도 같은 provider에서 정상 terminal까지 완료했다.

따라서 짧은 TUI 호출의 정상 완료는 filter 우회 증거가 아니며, 같은 약 41k context와 provider binding으로 재현해야 비교가 성립한다.

다음 작업 순서

route 의도 확정
- dev에서 ornith:35b의 의도된 실제 장비/provider가 GX10인지 확인한다.
- GX10이 맞다면 현재 model catalog/provider binding drift를 먼저 수정 대상으로 잡는다.
provider와 Node relay 분리 재현
- 동일한 약 41k-token Chat Completions 요청을 stream=true로 준비한다.
- provider 직접 호출과 IOP Node tunnel 호출을 각각 수행한다.
- raw prompt/output은 저장하지 않고 아래 이벤트를 request correlation과 monotonic timestamp로 각각 기록한다.
  - response_start, body/delta progress, 마지막 release
  - finish_reason_observed와 모든 active choice가 finished됐는지 여부
  - done_marker_observed
  - upstream_eof_observed
  - tunnel_end_emitted
  - core_terminal_emitted와 terminal commit
  - 각 종료 신호 시점의 pending_runes, staged finish/usage frame 수
- provider 직접 응답, Node ingress, tunnel emit, Edge codec, Core terminal의 시각을 대조해 어느 경계에서 신호가 멈췄는지 분리한다.
timeout ownership 정렬
- provider의 response_stall_timeout_ms를 Chronos dispatcher보다 짧게 설정하는 방안을 검토한다. 예: IOP 120s, dispatcher는 IOP terminal/recovery가 끝날 margin을 포함해 더 길게 둔다.
- 수치는 장문맥에서 정상적으로 180초 이상 무출력 후 완료되는 사례가 있는지 측정한 뒤 확정한다.
- post-commit stall은 명시적 terminal error, pre-commit stall은 현재 ExactReplay gate에 따라 alternate provider recovery가 가능한지 각각 검증한다.
회귀 테스트 추가
- active repeat_guard에서 partial BODY 뒤 END가 오지 않는 fixture
- response start만 온 pre-commit stall과 alternate-provider recovery
- stream-open stall의 단일 SSE error terminal
- pending 500-rune tail이 있는 상태의 stall/cancel 정리
- 정상 finish chunk와 [DONE]/transport END의 exact-wire 단일 terminal
- finish_reason은 왔지만 [DONE]/EOF/END가 오지 않는 fixture에서 pending release와 종료 grace 동작
- finish_reason 뒤 usage chunk와 정상 [DONE]이 오는 fixture에서 wire 순서 보존 및 terminal exactly-once
종료 처리 수정 방향 검토
- 모든 active choice에 유효한 finish_reason이 확인되는 순간을 filter의 safe release trigger로 사용할지 검토한다.
- filter가 pass하면 sub-threshold pending content와 staged finish chunk를 release한다.
- trailing usage와 정상 [DONE]을 받을 수 있도록 짧고 bounded된 terminal grace를 둔다.
- grace 안에 [DONE]/END가 오지 않으면 terminal을 exactly-once로 finalize하고, 뒤늦은 중복 종료 신호는 무시한다.
- exact-wire passthrough 및 trailing usage 호환성 때문에 filter release trigger와 transport terminal commit을 같은 상태로 단순 합치지 않는다.
dev live smoke
- Pi TUI와 headless dispatcher를 같은 model, context 크기, provider binding으로 비교한다.
- terminal 도착 시간, 마지막 progress부터 terminal까지의 idle, 선택 provider만 기록한다.
- secret, request 원문, response 원문은 evidence에 남기지 않는다.

이번 세션에서 수행한 검증

환경:

/config/.local/bin/go -> /config/opt/go/bin/go
go version go1.26.2 linux/arm64
GOROOT=/config/opt/go

실행 결과:

go test -count=1 ./apps/edge/internal/openai \
  -run 'Test(StreamGateChatConfiguredOutputFiltersCleanStreamSingleTerminal|OpenAITunnelCodecTerminalWire|StreamGateTunnelBuildRuntimeNoopPassRelaysRawBytes|DevRepeatGuardRequestDeadline)$'
PASS

go test -count=1 ./packages/go/streamgate \
  -run 'Test(StreamReleaserPassThroughAndTerminal|StreamReleaserTerminalAfterFullReleaseSkipsSecondaryRelease|CommitBoundaryCommitsEmptySuccessAndTerminalOnce)$'
PASS

이 테스트들은 정상 terminal/release 경로가 현재 소스에서 동작함을 확인한다. 실제 장문맥 provider stall을 재현하거나 timeout 정합성을 검증한 것은 아니다.

작업 시 주의사항

dev-corp Spark evidence를 이 장애에 재사용하지 않는다.
onexplayer-lemonade 같은 runtime alias만 보고 물리 장비를 단정하지 않는다.
filter가 원인이라고 전제하지 않는다. 현재 증거상 filter 판정은 전부 pass다.
반대로 filter의 500-rune hold가 보이는 truncation을 확대한다는 사실도 누락하지 않는다.
단순히 Chronos dispatcher timeout만 늘리면 open stream을 오래 유지할 뿐이다. IOP liveness terminal과의 순서를 함께 설계한다.
live 설정 변경, provider 재시작, route 변경, 배포는 이번 handoff 범위에서 수행하지 않았다.

14 KiB Raw Blame History

Handoff: ornith:35b streaming session stall과 terminal 지연