MARSOHS-440: doctl-codex proxy M3-M5 - #1893
Conversation
ecf39ff to
065c45b
Compare
|
Can you explain this feature a bit more with some sample use? |
Review: M3–M5 codex proxyReviewed the full diff against The problems are concentrated in the merge resolution and in lifecycle/concurrency, not in the translation layer. Findings are ordered by severity. I've opened #1895 stacked on this branch with fixes for #2 and #3 below, since both are mechanical and verified. Everything else is a design call and left to you. 🔴 1. The merge dropped
|
| AddStringFlag(cmdStartProxy, doctl.ArgAgentProxySession, "", "", "Session ID or name to bridge to", requiredOpt()) | ||
| AddIntFlag(cmdStartProxy, doctl.ArgAgentProxyPort, "", 1144, "Local port to listen on") | ||
| AddBoolFlag(cmdStartProxy, doctl.ArgAgentProxyReplay, "", false, "Replay the session's event history into the first thread on connect (not yet implemented)") | ||
| AddBoolFlag(cmdStartProxy, doctl.ArgAgentProxyReplay, "", false, "Replay the session's event history into the first thread on connect") |
| func New(t *testing.T, sessionID string) *Harness { | ||
| t.Helper() | ||
| h := &Harness{sessionID: sessionID} | ||
| h := &Harness{sessionID: sessionID, hitlCh: make(chan HITLResolution, 8)} |
| // Facade per connection starts clean and makes the previous one's goroutines | ||
| // (if still winding down) entirely self-contained. | ||
| func ServeListener(ctx context.Context, ln net.Listener, newFacade func() Facade) error { | ||
| func ServeListener(ctx context.Context, ln net.Listener, facade Facade) error { |
There was a problem hiding this comment.
Looks like we are back to a single shared Facade across connections, with only the notifier getting swapped on connect.
On #1878 we switched to a new Facade per connection so reconnect (codex --remote) wouldn't keep sticky streamStarted / turn state. Was that intentional here for --replay, or can we restore the per-connection factory?
There was a problem hiding this comment.
Restored in this branch — ServeListener takes newFacade func() Facade again (same as #1878). Each codex --remote connection gets a fresh Facade so streamStarted / turns / notifier can’t leak across reconnect. --replay is per-connection too (finding #6), so a reconnecting TUI with empty scrollback gets history again.
| // The harness's run id doubles as this facade's turn id — already a | ||
| // unique per-turn identifier, no separate id scheme needed. | ||
| f.trackTurn(resp.RunID) | ||
| f.trackTurn(ctx, resp.RunID) |
There was a problem hiding this comment.
Looks like SendInput is still happening before the SSE stream is attached (trackTurn → async runEventLoop → StreamSession).
We ran into this in #1878 and changed the flow to call ensureEventLoop before SendInput so we wouldn't miss early events against a live harness. It looks like that ordering may have been lost during the merge. Would you mind restoring the attach-before-SendInput flow?
There was a problem hiding this comment.
Restored — ensureEventLoop runs before SendInput again (same ordering as #1878). trackTurn only registers the run.
| f.replayMu.Unlock() | ||
| }() | ||
|
|
||
| stream, err := f.Sessions.StreamSession(ctx, f.SessionID, &godo.HostedAgentSessionStreamOptions{ReplayOnly: true}) |
There was a problem hiding this comment.
This will be wired to OHP under the hood, no breaking changes hopefully (I have pushed my commit to switch to OHP for streaming; under review currenly), just FYI.
Review: M3–M5 codex proxy (round 2,
|
| # | Finding | Status at HEAD |
|---|---|---|
| 1 | ensureEventLoop before SendInput |
Restored (facade.go:885), lookupTurn back (facade.go:1006) |
| 2 | Four failing --replay tests |
.../stream route registered; suite green |
| 3 | failAllTrackedTurns map-iteration crash |
Copies under f.mu (facade.go:1260) |
| 4 | Shared Facade racing on notifier |
newFacade func() Facade restored |
| 5 | --replay re-prompting settled HITLs |
translateEvent(..., replay bool) gates the side effects |
| 6 | replayDone outliving the connection |
Per-Facade, so per-connection |
| 7 | Reconnect cursor reset per loop | Hoisted to Facade.streamCursor |
| 8 | Replayed usage inflating the live total | Replay path returns early |
| 9 | item/started not propagating clientDead |
Both notifies propagate now |
| 10 | CheckOrigin accepting any origin |
allowedProxyOrigin + test |
| 11 | Duplicate reply wedging the read loop | Non-blocking send with default: |
| 12 | gofmt |
Clean |
go test -race -count=2 ./internal/agentproxy/... is green, go vet and gofmt are clean, and GOOS=windows/GOOS=darwin builds fine.
There is one new blocking finding, and it came in with the M5 commit (065c45bc) rather than with the fixes. It's serious enough that I'd hold the merge on it alone.
🔴 1. The reconnect cursor drops most of the event stream, because event ids are not ordered
drainStream treats the event id as a monotonically increasing position and discards anything that doesn't sort above the running cursor:
if ev.EventID != "" {
if *cursor != "" && ev.EventID <= *cursor {
continue
}
*cursor = ev.EventID
}The doc comment justifies this by "relying on canonical event ids being ULIDs (lexicographically ordered by time)," and cites doctl agents attach's tokenDeduper as precedent. Neither holds up.
Attach is not precedent. attach's drainStream calls cursor.set(ev.EventID) unconditionally (commands/agents.go:1545) and never compares two ids. Its tokenDeduper dedupes on the text of a run.token_delta (dedup.allow(p.Text), reset on any non-token event) — content, not position. The ordinal comparison here is new, not a generalisation of something already proven in production.
The ids aren't ordered. The producer of every run.* event this facade consumes is the guest harness, and it mints them randomly:
harness-api/public/events.proto:25—string event_id = 1; // Random UUIDv4; unique event identity (not monotonic)- plano
crates/agent_harness/src/spi/events.rs—event_id: Uuid::new_v4()
And critically, the ULID path is not ordered either. harness-api's own events.NewEventID() is ulid.MustNew(ulid.Now(), rand.Reader) — that's 48 bits of millisecond timestamp plus 80 bits of fresh randomness per call, not ulid.Monotonic. Two ids minted in the same millisecond sort randomly against each other, and token deltas arrive many per millisecond. So the assumption fails under both candidate id schemes.
Because the cursor only ratchets upward, it converges on the maximum id seen so far and the drop rate climbs toward 100% as a turn goes on. I drove one ordinary turn (run.started, 12 × run.token_delta, run.completed) through a fake harness that mints ids the way the real one does. Both schemes, several runs each:
uuidv4 (events.proto / plano CanonicalEvent::new)
token deltas: sent 12, delivered 3
token deltas: sent 12, delivered 2
token deltas: sent 12, delivered 6
ulid minted within one millisecond (harness-api events.NewEventID)
token deltas: sent 12, delivered 6
token deltas: sent 12, delivered 4
token deltas: sent 12, delivered 5
run.completed was dropped in every single run, and that's the part that turns a rendering glitch into a broken session. With the turn never finished, noTurnsLeft stays false, so runEventLoop reconnects until the budget is gone and then synthesizes a failure:
codex facade: stream ended (err=<nil>), reconnecting (×4)
codex facade: reconnected 5 times without staying healthy, giving up
turn/completed params: {Turn:{ID:run-uuid-1 Status:failed Error:"lost connection to hosted session"}}
So the user experience is: a truncated, garbled answer, a ~15s stall while the backoff runs down, and then a bogus "lost connection to hosted session" on a session that never lost anything. I also saw duplicate turn/started/item/started for one turn across those reconnects.
The reason CI didn't catch this is that agentproxytest's fixture mints fmt.Sprintf("evt-%d", i) (harness.go:323) — synthetic, monotonic, and nothing like what the harness emits. (Worth noting the fixture is itself only correct below ten events: "evt-10" < "evt-2" lexicographically, so a test queueing eleven would start silently dropping too.)
On the fix: I'd drop the ordinal comparison and follow attach — set the cursor unconditionally for its Last-Event-ID job, and if redelivery needs handling, do it with an explicit set of ids seen since the last attach, or with attach's content-based deduper. ev.Seq is the field that actually carries a monotonic position, but per the SSE contract it's 0 for everything until task D1 ships. That same note is the reason there's little to guard against right now: while positions are 0-0, Last-Event-ID "becomes a real resume point only once D1/History land," so reconnects are forward-only and can't redeliver a prefix in the first place. The dedup is currently costing the common path everything and buying nothing.
🟡 2. Replayed history is stamped with the current time
Every timestamp translateEvent produces comes from the clock, not the event: ts.startedAt = time.Now().Unix() (translate.go:49), StartedAtMs: time.Now().UnixMilli() (:132, :166), CompletedAtMs (:226, :265), and finishTurn's completedAt. That's fine live, but under --replay a conversation from last week renders as having happened in the last few milliseconds, with every turn duration ≈ 0. godo.HostedAgentEvent carries the real event time in At; using it (at least on the replay path) would make history look like history.
🟡 3. The thread token total silently resets after an idle drop
runEventLoop's deferred cleanup does f.totalUsage = tokenUsageBreakdown{} (facade.go:1149). The loop exits via noTurnsLeft whenever the stream drops with no turn in flight — a normal idle timeout between two user messages. The field's own doc says it "accumulates every live run.usage_recorded event seen across this connection," and threadTokenUsageUpdatedNotification's total is thread-scoped, so the TUI's running total jumping backwards after an idle pause contradicts both. turns and streamStarted genuinely are per-loop; totalUsage is per-connection and probably shouldn't be reset alongside them.
🟡 4. replaySessionHistory doesn't skip run-less events
drainStream skips events with no run id (facade.go:1306) precisely because control frames belong to no turn. The replay loop has no equivalent guard — turns[ev.RunID] on a stream.state frame synthesizes a phantom turnState keyed "" with itemID: "-msg". Harmless today because no run-less event kind matches a translateEvent case, but it's a guard that exists on one path and not its twin, and the fake harness emits stream.state on the replay stream too.
🟡 5. clientDead propagation is inconsistent across event kinds
RunStarted and TokenChunk both return true when f.notify fails, but the ToolCallStarted/ToolCallCompleted (translate.go:120, :157, :211, :256) and RunUsageRecorded (:403) notifies discard the result. A client that dies during a tool-call-heavy stretch keeps the loop draining and notifying at a closed socket until something else happens to notice — the same thing finding #9 fixed one case of last round.
🟢 6. lookupTurn costs 200 ms per permanently-untracked event
lookupTurn polls for eventClaimWait (200 ms) before giving up, which is right for the SendInput/trackTurn race it was written for, but it's applied to every miss including ones that can never resolve — an event for a run already deleted by finishTurn, say. Each one stalls the shared drain loop for a fifth of a second while every other in-flight turn waits. Bounding the retry to runs that could plausibly still be registering (e.g. only within a short window of a SendInput return) would keep the fix without the tax.
🟢 7. Replay notifications can race the thread/start reply onto the wire
maybeReplay spawns its goroutine before Dispatch returns (facade.go:810, :831), and handleConn only writes the thread/start result afterward. Nothing orders the two, so a replayed turn/started can in principle reach the client before the thread it refers to has been acknowledged. In practice replaySessionHistory does an HTTP round trip first and will essentially always lose that race — but it's ordering by luck, and gating the goroutine on the reply having been written would make it free.
Verification
go build ./... # ok
go vet ./internal/agentproxy/... ./commands/ # clean
gofmt -l internal/agentproxy/ commands/agents.go # clean
go test -race -count=2 ./internal/agentproxy/... # ok
GOOS=windows go build ./commands/ # ok
GOOS=darwin go build ./commands/ # ok
Finding #1 was reproduced with a throwaway fake harness minting ids both ways; everything else is from reading, and I've said so where I wasn't able to confirm behaviour directly.
The response to the last round was thorough — the ensureEventLoop ordering, the per-connection facade, and the replay HITL gating are all done properly, and the origin check went further than I asked for. Finding #1 is the one thing standing between this and a merge, and it's a small diff.
Implementation plan here (from Adil Hafeez): https://github.internal.digitalocean.com/digitalocean/cthulhu/pull/166147/files
Has milestones that this is based on (M3-M5)
Jira: https://do-internal.atlassian.net/browse/MARSOHS-440