Skip to content

🐛 Keep the control connection responsive while a broker ask waits - #247

Merged
sdougbrown merged 7 commits into
mainfrom
fix/243-broker-ask-responsiveness
Oct 2, 2026
Merged

sdougbrown merged 7 commits into
mainfrom
fix/243-broker-ask-responsiveness

Conversation

@sdougbrown

Copy link
Copy Markdown
Owner

An unanswered broker_ask blocked the read loop on the control connection for up to the broker's 10-minute ask timeout. While the child kept running, every later request on that connection returned read response: timeout. Dispatch recovered on a second supervisor.

Changes

  • internal/control: broker_ask now runs on a background goroutine bound to a per-connection context. The connection keeps serving requests such as status, spawn, broker_peers, and follow_up while an ask waits. Disconnect and server stop cancel the pending wait.
  • internal/stable: BrokerAsk takes a context and sends /wait_reply with a request context. A cancelled wait withdraws the pending ask via /cancel_message with a fresh context. A late child reply therefore cannot pair with a dead waiter.
  • broker_ask failures return error data with the ask's message_id. Callers can cancel the pending ask with broker_cancel instead of retrying blind. A new optional timeout_ms parameter bounds the wait.
  • internal/runtime/broker: /wait_reply now extends its socket write deadline through a new configurable writeTimeout field. The previous fixed 30s WriteTimeout risked dropping a reply that arrived after the deadline but before the long-poll timeout.
  • client (Go) and packages/core (TS): RPC errors preserve structured data (RPCError / RpcError). The avenor_ask tool returns the message_id in the error text so the agent can withdraw the ask with avenor_cancel. It accepts optional timeout_ms.

Non-ask handlers remain serial. Two hazards rule out per-request goroutines elsewhere. The prompt and shutdown handlers rely on arrival-order semantics. ensureOwner can also reassign ownership after a disconnect. Those handlers stay out of scope.

Follow-up work (out of scope here)

  • Children inherit the supervisor's run_id in durable event logs.
  • avenor_follow_up advertises resume that the Pi backend cannot support (--no-session).

Validation

  • go test ./internal/control/ ./internal/stable/ ./internal/runtime/broker/ ./client/ — ok
  • go test -race on internal/control, internal/runtime/broker, internal/stable — ok, no races
  • bun test in packages/core: 320 pass. packages/pi: 139 pass.
  • New regression tests cover four behaviors: the connection answers status while an ask is blocked. Disconnect cancels the in-flight ask. Ask errors carry message_id. A reply arriving after the old write deadline still reaches the waiter.
  • cmd/avenor has 26 pre-existing failures on a clean tree (macOS unix-socket path length in $TMPDIR); unchanged by this branch

Fixes #243

…nect (#243)

An unanswered broker_ask blocked the control connection's reader for up to
the broker's 10-minute ask timeout, so every later request on that
connection (status, spawn, peers, follow_up) timed out with
"read response: timeout" while the child kept running.

- dispatch broker_ask on a background goroutine bound to a per-connection
  context; connection loss and server stop cancel the pending wait
- BrokerAsk takes a context, sends wait_reply with a request context, and
  withdraws a cancelled ask via /cancel_message using a fresh context
- broker_ask failures return error data with the ask's message_id so the
  caller can cancel it instead of retrying blind; optional timeout_ms
  param bounds the wait
- /wait_reply extends its socket write deadline (new configurable
  writeTimeout field); the previous fixed 30s WriteTimeout could drop a
  reply that arrived after the deadline but before the long-poll timeout
- Go and TS control clients preserve structured RPC error data
  (RPCError / RpcError); the ask tool surfaces the message_id for
  avenor_cancel

Fixes #243

AI-Generated-By: glm-5.3-flash, sparky/qwen3.8:27b

@umpire-bot umpire-bot Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This PR is marked... OUT! ✊

Blocking

timeout_ms parameter silently capped at 30s on every ask path

Files: packages/core/src/tools/ask.ts:45, packages/core/src/supervisor.ts:160/299, packages/core/src/tools/get-supervisor-client.ts:24, packages/core/src/client.ts:218/315-318

The new timeout_ms parameter is silently capped at 30s on every ask path. The singleton client is dialed with Supervisor's default callTimeoutMs = 30_000 (supervisor.ts:160), the external path uses plain dial(id) with no opts (get-supervisor-client.ts:24 → client.ts:218 defaults to 30s), and Client.call() unconditionally arms a 30s timer (client.ts:315-318). An agent passing timeout_ms: 120000 to avenor_ask fails at 30s with a generic "read response: timeout" (a plain Error, not an RpcError) while the server keeps processing the ask and later discards the out-of-order reply. The advertised timeout semantics never hold and the failure message misrepresents the configured bound.

Fix: Thread timeoutMs through Client.call() as a per-call override (e.g. setTimeout(..., Math.max(this.callTimeout, timeoutMs)) for ask-shaped calls), or at minimum have brokerAsk reject/validate timeoutMs > callTimeout so the mismatch is explicit instead of silent.

Comment thread internal/runtime/broker/broker_test.go Outdated
Comment thread internal/runtime/broker/broker_test.go Outdated
Comment thread internal/control/server.go
Comment thread packages/core/src/tools/ask.ts
…rrors

- broker test: set writeTimeout before Start so the server is actually
  created with the 100ms deadline and SetWriteDeadline is load-bearing
- control server: skip the response frame for JSON-RPC notifications
  (req.ID == nil) on the async broker_ask path
- AskError carries pending: false when the ask edge is provably cleaned
  up (send failure, broker-side cleanup, already-deleted edge) and true
  only when cleanup failed; the ask tool's cancel guidance now matches
- TS client: per-call timeout override so timeout_ms above the default
  30s no longer fails client-side first

Refs #247
AI-Generated-By: glm-5.3-flash, sparky/qwen3.8:27b
…imeouts

- withdrawAsk helper classifies ask-edge state on every failure path
  (send and wait): pending=false when the broker cleaned the edge or
  reports it gone; true only when cleanup itself fails
- broker: SetWriteDeadline failure is non-fatal instead of a 500 that
  orphaned the registered edge; fix the writeTimeout doc comment
- control server: reject negative timeout_ms, cap it at the broker's
  10-minute ask ceiling, and bound concurrent in-flight asks per
  connection (8) instead of accumulating unbounded parked goroutines
- broker test: send before starting the replier poll loop and continue
  on transient poll errors; tests for the classification and dead-broker
  send path
- control tests: pin the asyncResponse guard (no double write), the
  notification contract (id-less ask gets no frame), the server-side
  timeout_ms deadline, Stop cancellation, and the in-flight cap
- TS: ignore non-positive timeoutMs, clamp the per-call timer to
  setTimeout's range, and make the timer monkeypatch deterministic

Refs #247
AI-Generated-By: glm-5.3-flash, sparky/qwen3.8:27b
…afe test fixtures

- blockingAskHandler: sync.Once for the entered signal and a mutex around
  askCtx, safe under the in-flight cap test's 8 concurrent asks
- clamp the server-side timeout_ms to just below the broker's
  DefaultAskTimeout so clamped values expire server-side with structured
  error data instead of racing the broker's 504
- classify ask-edge cleanup on the 404 status, not just the body text;
  a refused send connection (request never delivered) reports pending
  false
- TS client: clamp the final computed timer value, not just the input
- tests: strict first-frame reader pins the asyncResponse guard; the
  notification test completes the handler before asserting silence; the
  timeout test uses a 500ms window

AI-Generated-By: glm-5.3-flash
@sdougbrown

Copy link
Copy Markdown
Owner Author

👾 AI Agent

Addressed 4 inline comments across 3 commits (ffd1236, 466abd5, 61d62b4), all as fixes:

  • writeTimeout set after Start() (×2, broker_test.go:2559) — moved before Start() so the server is created with the 100ms deadline; re-verified the deadline extension is load-bearing (revert fails, restore passes).
  • Response frame for notifications (server.go:1310) — the async goroutine returns before writing when req.ID == nil; pinned by a test.
  • Stale avenor_cancel guidance (ask.ts:56) — the server now returns data: {message_id, pending}; pending: false when the edge is provably gone, pending: true only when cleanup itself failed. Guidance matches.

Blocking verdict — timeout_ms capped at 30s: fixed via a per-call timeout override in Client.call(). The timer is now max(callTimeout, timeoutMs + 10s), clamped to setTimeout's range. The server-side cap sits 5s below the broker's ask ceiling, so the structured ask error arrives before the client timer fires. Non-positive or non-finite timeout_ms values are ignored client-side.

Internal adversarial review after the fixes found and fixed further issues: send-path edge cleanup with a withdrawAsk classification on every failure path. Also fixed: non-fatal SetWriteDeadline, timeout_ms validation and clamping, a per-connection in-flight ask cap (8), a test data race in the in-flight-cap fixture, and test-determinism fixes. Go suites pass (incl. -race on the touched packages); bun test: core 335 pass, pi 139 pass.

Review loop: 2 iterations. Deferred as accepted: per-call timeout for the Go client.Call (no Go caller sends broker_ask today), write deadlines on control-socket writeJSON, and connection-cycling ask creation (threat-model dependent).

@umpire-bot review again

@umpire-bot umpire-bot Bot left a comment •

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This PR is marked... FOUL BALL. 👉

Play by play: 2 bot reviews

  1. Review 1: Request changes
  2. Review 2: Comment 👈

Prior Findings Review

Fixed (4)

Prior findings that have been resolved.
4 prior findings have been resolved in the current code.


Comment thread internal/control/server.go
Comment thread internal/control/server.go
Comment thread client/client.go
@sdougbrown

Copy link
Copy Markdown
Owner Author

👾 AI Agent

Round 2 addressed 3 inline comments in commit 799ed28, all as fixes:

  • Timeout clamp untested (server.go:1317) — TestBrokerAskTimeoutClampedToMax sends an oversized timeout_ms and asserts the handler deadline is clamped to maxAskTimeoutMS.
  • Negative timeout_ms guard untested (server.go:1312) — TestBrokerAskNegativeTimeoutRejected asserts the -32602 rejection.
  • Go RPCError.Data untested (client.go:162) — TestCallErrorPreservesData asserts the payload, code, and message format survive.

Review loop: 3 iterations. All 7 review threads resolved; no remaining findings. Go suites pass; bun test: core 335 pass, pi 139 pass.

@sdougbrown

Copy link
Copy Markdown
Owner Author

@umpire-bot review again

@umpire-bot umpire-bot Bot left a comment •

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This PR is marked... FOUL BALL. 👉

Play by play: 3 bot reviews

  1. Review 1: Request changes
  2. Review 2: Comment
  3. Review 3: Comment 👈

Prior Findings Review

Fixed (7)

Prior findings that have been resolved.
7 prior findings have been resolved in the current code.


Comment thread packages/pi/src/index.ts Outdated
Comment thread packages/core/src/client.test.ts Outdated
Comment thread internal/stable/supervisor.go
Comment thread internal/control/server_test.go
Comment thread packages/pi/src/index.ts
- declare avenor_ask's timeout_ms as Type.Integer so fractional values
  cannot reach the int64 server parser
- rewrite the duplicated per-call-timeout test so it covers the branch
  where the base callTimeout exceeds timeoutMs + margin
- cover the send-failure cleanup path end-to-end: a 404 target on a live
  broker runs withdrawAsk and classifies pending=false
- assert data["pending"] in the ask-error wire tests (both false and
  true variants)
- add an avenor_ask wiring test for timeout_ms -> timeoutMs

AI-Generated-By: glm-5.3-flash, sparky/qwen3.8:27b
@sdougbrown

Copy link
Copy Markdown
Owner Author

👾 AI Agent

Round 3 addressed 5 inline comments in commit 49a4900, all as fixes:

  • Fractional timeout_ms (pi/index.ts:1744) — schema is now Type.Integer, matching the server's int64 parse.
  • Duplicate timeout test (client.test.ts:836) — rewritten to cover the branch where the base callTimeout exceeds timeoutMs + margin (asserts 30_000, never 11_000).
  • Send-failure cleanup path (supervisor.go:1735) — TestBrokerAskSendTargetMissingRunsCleanup exercises withdrawAsk against a live broker (404 target → "no pending ask" → pending: false).
  • pending unasserted (server_test.go:2491) — the message-ID test now asserts data["pending"], with a Pending: true variant test.
  • Ask wiring untested (pi/index.ts:1748) — avenor_ask.execute test captures timeout_ms: 2500 → timeoutMs, plus a fractional round-trip.

Review loop: 3 iterations. All 12 threads resolved; no remaining findings. Go: control/stable pass; bun test: core 335 pass, pi 140 pass.

@sdougbrown

Copy link
Copy Markdown
Owner Author

@umpire-bot review again

@umpire-bot umpire-bot Bot left a comment •

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This PR is marked... FOUL BALL. 👉

Play by play: 4 bot reviews

  1. Review 1: Request changes
  2. Review 2: Comment
  3. Review 3: Comment
  4. Review 4: Comment 👈

Prior Findings Review

Fixed (14)

Prior findings that have been resolved.
14 prior findings have been resolved in the current code.


Comment thread packages/core/src/client.test.ts
Comment thread internal/runtime/broker/broker_test.go
Comment thread packages/core/src/tools/ask.test.ts Outdated
…tests

- the write-timeout test now records and asserts the wait_reply elapsed
  time exceeds the deadline, so a reply that lands before the handler
  parks fails loudly instead of passing vacuously
- collapse the three timeout-normalization tests into one it.each case
- the delay-capture assertions stay: the +10s margin is a documented
  contract, and the behavioral case is covered by the slow-response test

AI-Generated-By: glm-5.3-flash
@sdougbrown

Copy link
Copy Markdown
Owner Author

👾 AI Agent

Round 4 addressed 3 inline comments in commit e196f4d:

  • Fixed (2): the write-timeout test now asserts the wait_reply elapsed time exceeds the deadline (self-verifying; logged), and the three timeout-normalization tests are one it.each case.
  • Accepted as is (1): the delay-capture assertions stay — the +10s margin is a deliberate documented contract (client must not fire before the server's structured error arrives), and your comment's keep-as-is condition applies. Observable behavior is separately pinned by the slow-response test.

Review loop: 4 iterations. 15/15 threads resolved; no remaining findings. Go: broker suite passes; bun test: core 335 pass, pi 140 pass.

@sdougbrown

Copy link
Copy Markdown
Owner Author

@umpire-bot review again

@umpire-bot

umpire-bot Bot commented Oct 2, 2026

Copy link
Copy Markdown

No new commits since the last review — skipping this re-review. Latest verdict: #247 (review)

@sdougbrown
sdougbrown merged commit 394f044 into main Oct 2, 2026
11 of 12 checks passed
@sdougbrown
sdougbrown deleted the fix/243-broker-ask-responsiveness branch October 2, 2026 16:02
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

🐛 Keep Pi control tools responsive after a timed-out broker ask

1 participant