Skip to content

[Bug]: opencode-go stalled-stream watchdog aborts a live stream and drops the completed answer (idle timer re-arms only on token deltas, not block-boundary events) #96518

Description

@yetval

Problem

The opencode-go stalled-stream watchdog can abort a stream that is still alive and actively producing output, replacing a completed answer with a stalled error. When the model finalizes a tool call and then deliberates before the next one, the provider emits real block-boundary SSE events (text_end, thinking_end, toolcall_start, toolcall_end) that prove the socket is alive, but the watchdog does not treat them as liveness. If the gap between two consecutive token deltas exceeds idleTimeoutMs (default 120s) while these boundary events keep flowing, the watchdog calls controller.abort() on the real upstream request and pushes a terminal stalled error event downstream. The provider's real done arrives next and is silently dropped by the settled gate.

User-visible symptom: a completed (or in-flight, about to complete) opencode-go answer is replaced by a stalled error, and the run is classified as FAILED with stopReason: "error" (not "timed-out"), so even the failure cause is misleading. This wrapper is the outermost guard for all opencode-go models (Kimi, GLM, MiniMax, DeepSeek coding models). On cron the shared runtime idle watchdog is disabled, so this wrapper is the sole guard, and cron coding turns with long tool-call deliberation are exactly where boundary-event-only gaps occur. This makes the failure most likely on the workload it most affects.

Root cause

Pinned to current main HEAD 3217165be77071339f599cd1f5f0f341bc5af8dd, file extensions/opencode-go/stream-termination.ts:

  • The idle re-arm predicate isProviderProgressEvent (lines 54-60) returns true only for text_delta, thinking_delta, and toolcall_delta. Block-boundary events are not included.
  • In the read loop (lines 354-358), every forwarded event is pushed downstream via output.push(event), but armIdleTimer() is called only when isProviderProgressEvent(event) is true. So boundary events are forwarded to the consumer but do NOT re-arm the idle timer.
  • When the timer fires, abortStalledStream (lines 281-292) sets settled = true, calls controller.abort(...) on the combined AbortSignal (genuinely interrupting the upstream OpenAI-compatible request), and pushes buildStalledErrorEvent(...) which is type: "error" with stopReason: "error" (lines 107-124).
  • The next real event from the provider (the done) is then dropped by the settled gate at line 341 (if (settled) { return; }).

This contradicts the wrapper's own docstring (lines 203-213): "the timer covers stream creation, first event delivery, and every gap after provider progress begins" and "provider progress refreshes the idle timer and a terminal event cancels it entirely." The code requires a token delta to refresh the timer, not any provider event, so a stream that keeps emitting boundary events between deltas is not actually protected the way the docstring describes.

The wrapper and isProviderProgressEvent were introduced by merged PR #93965 (commit 769579b). The design note there ("only real provider progress switches the wrapper to the shorter idle timer") defined "real provider progress" as deltas only; this report is the gap that the delta-only definition leaves open, not a regression of pre-wrapper behavior.

Reproduction

The test below drives the real createOpencodeGoStalledStreamWrapper with a fake base stream that emits a delta, then real block-boundary events spaced under idleTimeoutMs, then the provider's done. A liveness-aware watchdog must not abort. On current main it aborts and drops the done.

Run command (from repo root):

node scripts/run-vitest.mjs extensions/opencode-go/stream-termination-idlerearm.test.ts

Test source:

import type {
  AssistantMessageEvent,
  AssistantMessageEventStreamContract,
} from "openclaw/plugin-sdk/llm";
import { afterEach, beforeEach, describe, expect, it, vi } from "vitest";
import { createOpencodeGoStalledStreamWrapper } from "./stream-termination.js";

type AnyEvent = AssistantMessageEvent;
type StreamLike = AssistantMessageEventStreamContract;

interface FakeStreamController {
  emit(event: AnyEvent): void;
  end(): void;
}

function createFakeBaseStream(): { stream: StreamLike; controller: FakeStreamController } {
  const queued: IteratorResult<AnyEvent>[] = [];
  const waiters: ((result: IteratorResult<AnyEvent>) => void)[] = [];
  let finished = false;

  const iterator: AsyncIterator<AnyEvent> = {
    next(): Promise<IteratorResult<AnyEvent>> {
      if (queued.length > 0) {
        return Promise.resolve(queued.shift()!);
      }
      if (finished) {
        return Promise.resolve({ value: undefined, done: true });
      }
      return new Promise((resolve) => {
        waiters.push(resolve);
      });
    },
    return(): Promise<IteratorResult<AnyEvent>> {
      finished = true;
      while (waiters.length > 0) {
        waiters.shift()!({ value: undefined, done: true });
      }
      return Promise.resolve({ value: undefined, done: true });
    },
  };

  const stream: StreamLike = {
    [Symbol.asyncIterator]() {
      return iterator;
    },
    push() {},
    end() {},
    result() {
      return Promise.reject(new Error("unused"));
    },
  };

  const controller: FakeStreamController = {
    emit(event: AnyEvent) {
      const waiter = waiters.shift();
      if (waiter) {
        waiter({ value: event, done: false });
      } else {
        queued.push({ value: event, done: false });
      }
    },
    end() {
      finished = true;
      while (waiters.length > 0) {
        waiters.shift()!({ value: undefined, done: true });
      }
    },
  };

  return { stream, controller };
}

describe("opencode-go idle watchdog re-arm (audit repro)", () => {
  beforeEach(() => vi.useFakeTimers());
  afterEach(() => vi.useRealTimers());

  it("must NOT abort a live stream that keeps emitting block-boundary events between deltas", async () => {
    const { stream: baseStream, controller } = createFakeBaseStream();
    let abortCalled = false;
    const underlying = vi.fn((_model, _context, options) => {
      options?.signal?.addEventListener("abort", () => {
        abortCalled = true;
      });
      return baseStream;
    });

    const idleTimeoutMs = 5_000;
    const wrapper = createOpencodeGoStalledStreamWrapper(underlying as any, {
      provider: "opencode-go",
      idleTimeoutMs,
    });

    const downstream = await Promise.resolve(
      wrapper({ provider: "opencode-go", id: "glm-4.6" } as any, {} as any, {} as any),
    );
    expect(downstream).toBeDefined();
    if (!downstream) return;

    const received: AnyEvent[] = [];
    const consumer = (async () => {
      for await (const event of downstream) {
        received.push(event);
      }
    })();

    const partial = { role: "assistant", content: [{ type: "text", text: "x" }] };

    // Provider starts producing a tool-call turn. Last *delta* arms the idle timer.
    controller.emit({ type: "start", partial } as any);
    controller.emit({ type: "toolcall_delta", contentIndex: 0, delta: "{", partial } as any);
    await vi.advanceTimersByTimeAsync(0);

    // The model now finalizes the tool call and deliberates on the next one,
    // emitting REAL block-boundary events that prove the SSE socket is alive.
    // Each gap is < idleTimeoutMs, so a liveness-aware watchdog must stay armed.
    await vi.advanceTimersByTimeAsync(3_000);
    controller.emit({ type: "toolcall_end", contentIndex: 0, partial } as any); // alive @ +3s
    await vi.advanceTimersByTimeAsync(3_000);
    controller.emit({ type: "toolcall_start", contentIndex: 1, partial } as any); // alive @ +6s

    // 5s after the last *delta* (but only 2s after the last live event), the
    // idle timer fires. Drain microtasks so the abort path runs.
    await vi.advanceTimersByTimeAsync(1_000);

    // The provider's completed answer arrives right after.
    controller.emit({
      type: "done",
      message: { role: "assistant", content: [{ type: "text", text: "final answer" }], stopReason: "stop" },
    } as any);
    controller.end();
    await vi.advanceTimersByTimeAsync(0);
    await consumer;

    const hasDone = received.some((e) => e.type === "done");
    const hasStalledError = received.some(
      (e) => e.type === "error" && (e as any).error?.stopReason === "error",
    );

    expect(abortCalled).toBe(false);
    expect(hasDone).toBe(true);
    expect(hasStalledError).toBe(false);
  });
});

RED output on current main (3217165be77071339f599cd1f5f0f341bc5af8dd):

 FAIL  |extension-misc| extensions/opencode-go/stream-termination-idlerearm.test.ts > opencode-go idle watchdog re-arm (audit repro) > must NOT abort a live stream that keeps emitting block-boundary events between deltas
AssertionError: expected true to be false // Object.is equality

- Expected
+ Received

- false
+ true

 ❯ extensions/opencode-go/stream-termination-idlerearm.test.ts:144:25
    142|     // so the timer fires 5s after the last delta despite live boundar...
    143|     // the request is aborted and the real `done` is dropped (settled-...
    144|     expect(abortCalled).toBe(false);
       |                         ^
    145|     expect(hasDone).toBe(true);
    146|     expect(hasStalledError).toBe(false);

 Test Files  1 failed (1)
      Tests  1 failed (1)

The watchdog aborts the upstream request (abortCalled is true) even though the stream emitted live boundary events well within idleTimeoutMs of each other.

Trigger

A gap longer than idleTimeoutMs (default 120s) between two consecutive *_delta events, while block-boundary events flow in between. Concrete sequence: toolcall_delta -> toolcall_end -> ~130s of model deliberation -> next toolcall_delta. The boundary event refreshes nothing, so the timer fires 120s after the last delta and aborts a stream that is demonstrably alive.

Impact / Severity

P1. A completed or in-flight answer is silently replaced by an error and the run is marked failed with stopReason: "error" (misleading cause, not a timeout). Affects all opencode-go users (Kimi, GLM, MiniMax, DeepSeek coding models). Most acute on cron, where the shared runtime idle watchdog is disabled and this wrapper is the only guard, and where long tool-call deliberation between deltas is common.

Relationship to existing issues

This is distinct from the known adjacent items and should not be deduped against them:

Suggested direction

Not prescriptive and no patch attached: the idle timer should treat any forward-progress provider event as liveness, at minimum the *_end block-boundary events (and arguably toolcall_start), since their arrival proves the socket is alive and the provider is still producing output. The current predicate keys liveness on token deltas only, which undercounts genuine provider activity.

Metadata

Metadata

Assignees

No one assigned

    Labels

    P1High-priority user-facing bug, regression, or broken workflow.clawsweeper:fix-shape-clearClawSweeper found a clear likely implementation shape for this issue.clawsweeper:queueable-fixClawSweeper marked this issue as an existing queue_fix_pr work candidate.clawsweeper:source-reproClawSweeper found a high-confidence source-level issue reproduction.impact:auth-providerAuth, provider routing, model choice, or SecretRef resolution may break.impact:message-lossChannel message delivery can be lost, duplicated, or misrouted.issue-rating: 🦞 diamond lobsterVery strong issue quality with high-confidence source-level or clear reproduction.no-staleExclude from stale automation

    Type

    No type

    Fields

    Priority

    None yet

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions