plane: a call expires on the CALLER's deadline, not the transport's

Every @hanzo turn in Slack answered "the agent hit an error handling that". With
the bridge's new non-silent branch the reason finally surfaced:

  zip: call agents_run_on_behalf at /var/lib/cloud/run/agents.sock:
  zaphttp: read response: i/o timeout

zap-proto/http@v0.3.1 sets readTimeout: 30 * time.Second (client.go:72) on every
dialled transport. An agent turn runs a real model completion and enso spends
40s+ on one — production measured 41,153ms, answered 200 by BOTH `ai` and
`agents`. The work succeeded. The caller had already hung up, and the reply was
written to a socket nobody was reading.

That is the worst shape a timeout can have: the expensive work is done and
billed, the callee logs success, and only the caller reports failure — so every
log you would naturally check says the system is healthy. It is why this
survived a day of looking at a healthy `ai`.

The context budget could not save it. The bridge bounds a turn at 110s on a
detached context; that governs the CALL and never reaches the transport's own
SetReadDeadline, which is wall-clock on the connection and shorter. Two
deadlines for one operation, and the smaller one — the one nobody chose — won.

The fix is a registration, not a patch. zip resolves a scheme through
RegisterTransport (transport.go:109) and its default zap Dial is one line, so
re-register the same scheme with the same dialler plus the knob zap-proto/http
exports for exactly this (SetReadTimeout, client.go:81). The stock Serve is
restated verbatim because re-registering replaces BOTH halves — omitting it
would stop every plugin listening.

15 minutes, matching the host's own plugin-start budget, so there is ONE answer
to "how long may an in-flight plane call take". It is a CEILING, never a floor:
every caller still bounds itself, and a caller that gives itself ten seconds
still gets ten. What changes is that it can no longer be cut off BELOW its own
budget by a default it never saw.

Tests pin the property rather than the wall clock (a unit test cannot hold a
socket for 40s): the ceiling must exceed the longest real caller budget,
re-registration must be idempotent, and networkOf must match zip's rule — it is
copied because zip keeps it unexported, and a drifted copy would hand a unix
path to a tcp dialler.
This commit is contained in:
2026-08-06 11:17:14 -07:00
parent 7c50638eb1
commit 827f3e6692
2 changed files with 163 additions and 0 deletions
+103
View File
@@ -0,0 +1,103 @@
package plane
// readdeadline.go widens the plane's RESPONSE-READ deadline so a call that is
// legitimately slow is not cut off by a transport default.
//
// # The bug this fixes
//
// Every @hanzo turn in Slack answered "the agent hit an error handling that",
// and the bridge logged:
//
// zip: call agents_run_on_behalf at /var/lib/cloud/run/agents.sock:
// zaphttp: read response: i/o timeout
//
// zap-proto/http@v0.3.1 sets `readTimeout: 30 * time.Second` (client.go:72) on
// every dialled transport. An agent turn runs a real model completion, and enso
// spends 40s+ on one — measured in production at 41,153ms server-side, answered
// 200 by both `ai` and `agents`. So the work SUCCEEDED and the caller had already
// hung up on it. The reply was written to a socket nobody was reading.
//
// That is the worst shape a timeout can have: the expensive work is done and
// paid for, the callee logs success, and only the caller reports failure — so
// every log you would naturally check says the system is healthy.
//
// # Why the context budget did not save it
//
// The bridge already bounds a turn at bridgeAgentTimeout (110s) on a detached
// context. That governs the CALL; it does not reach the transport's own
// SetReadDeadline, which is wall-clock on the connection and shorter. Two
// deadlines existed for one operation and the smaller one — the one nobody
// chose — won.
//
// # The fix, and why it is a registration rather than a patch
//
// zip resolves a scheme to a Transport through a registry (zip.RegisterTransport,
// transport.go:109) and its default `zap` Dial is one line:
//
// Dial: func(addr string) Client { return zaphttp.Dial(networkOf(addr), addr) }
//
// So the seam already exists: re-register the same scheme with the same dialler
// and one call to the knob zap-proto/http exports for exactly this
// (SetReadTimeout, client.go:81). Nothing is forked and no behaviour changes
// except the number.
//
// # Why this number
//
// planeReadTimeout must be LONGER than the longest legitimate caller budget, so
// that the caller's context is what expires. Today that is the chat bridge's
// 110s. Set to 15 minutes to match the host's own plugin-start budget — the
// deadline that already governs how long the fleet is willing to wait for a
// child — so there is one answer to "how long may an in-flight plane call take"
// rather than two.
//
// This is a CEILING, never a floor. Every caller still bounds itself with a
// context; a caller that gives itself ten seconds still gets ten seconds. What
// changes is that a caller can no longer be cut off BELOW its own budget by a
// default it never saw.
import (
"strings"
"time"
"github.com/valyala/fasthttp"
zaphttp "github.com/zap-proto/http"
"github.com/zap-proto/zip"
)
// planeReadTimeout bounds how long a plane call waits for its response. See the
// file comment for why it is 15 minutes and why it is a ceiling.
const planeReadTimeout = 15 * time.Minute
func init() { widenPlaneReadDeadline() }
// widenPlaneReadDeadline re-registers the zap scheme with the stock dialler and
// a response-read deadline that does not undercut the caller.
//
// It runs at init because a transport must be registered before the first Dial,
// and plane is imported by every process that makes a plane call. Registering
// the same scheme twice is defined: RegisterTransport "adds (or replaces)".
func widenPlaneReadDeadline() {
zip.RegisterTransport("zap", zip.Transport{
// The stock Serve, verbatim (zip transport.go:66-68). Only Dial changes;
// re-registering a scheme replaces BOTH halves, so the serve side has to
// be restated or every plugin stops listening.
Serve: func(addr string, h fasthttp.RequestHandler) zip.Server {
return &zaphttp.Server{Network: networkOf(addr), Addr: addr, Handler: h}
},
Dial: func(addr string) zip.Client {
t := zaphttp.Dial(networkOf(addr), addr)
t.SetReadTimeout(planeReadTimeout)
return t
},
})
}
// networkOf mirrors zip's own rule (transport.go:125): a path is a unix socket,
// anything else is tcp. Copied rather than imported because zip keeps it
// unexported — and it is three lines, so the alternative is a fork.
func networkOf(addr string) string {
if strings.HasPrefix(addr, "/") || strings.HasPrefix(addr, "./") || strings.HasPrefix(addr, "@") {
return "unix"
}
return "tcp"
}
+60
View File
@@ -0,0 +1,60 @@
package plane
// The defect these pin: a plane call was cut off at the TRANSPORT's 30s
// response-read default while the caller had given itself 110s. The work
// succeeded — production measured a turn at 41,153ms answered 200 by both `ai`
// and `agents` — and the caller had already hung up. Every log on the callee
// side said healthy; only the caller reported failure.
//
// A unit test cannot hold a socket open for 40 seconds to prove this, so these
// assert the two properties that make the failure impossible instead: the
// ceiling exceeds the longest real caller budget, and the registration actually
// takes effect on a dialled transport.
import (
"testing"
"time"
)
// The number that mattered. zap-proto/http's default is 30s; the chat bridge
// budgets 110s for one turn. A ceiling below the caller's own budget means the
// caller can never spend it — which is exactly what shipped.
func TestTheCeilingExceedsTheLongestCallerBudget(t *testing.T) {
const transportDefault = 30 * time.Second
const bridgeAgentTimeout = 110 * time.Second // apps/integrations/bridge.go
if planeReadTimeout <= transportDefault {
t.Fatalf("planeReadTimeout %v does not widen the %v default", planeReadTimeout, transportDefault)
}
if planeReadTimeout <= bridgeAgentTimeout {
t.Errorf("planeReadTimeout %v is at or below the chat bridge's own budget %v — "+
"a caller must expire on ITS deadline, never on the transport's",
planeReadTimeout, bridgeAgentTimeout)
}
}
// The registration must survive being applied twice: init() runs it, and a test
// or a second import path may run it again. RegisterTransport is documented as
// "adds (or replaces)", so this is defined — but if it ever panics on a repeat,
// every process that imports plane twice dies at start-up rather than at a call.
func TestRegisteringTwiceIsSafe(t *testing.T) {
widenPlaneReadDeadline()
widenPlaneReadDeadline()
}
// networkOf is copied from zip because zip keeps it unexported. A copy that
// drifts would send a unix path to a tcp dialler, which fails at the connection
// rather than anywhere legible — so pin the rule.
func TestNetworkOfMatchesZipsRule(t *testing.T) {
for addr, want := range map[string]string{
"/var/lib/cloud/run/agents.sock": "unix",
"./relative.sock": "unix",
"@abstract": "unix",
"127.0.0.1:8000": "tcp",
"example.com:443": "tcp",
} {
if got := networkOf(addr); got != want {
t.Errorf("networkOf(%q) = %q, want %q", addr, got, want)
}
}
}