Commit history detached from cancellation on every path, not just failure #73
+64
-10
@@ -8,6 +8,8 @@ import (
|
|||||||
"io"
|
"io"
|
||||||
"log/slog"
|
"log/slog"
|
||||||
"net/http"
|
"net/http"
|
||||||
|
"sync"
|
||||||
|
"time"
|
||||||
|
|
||||||
mdagent "gitea.stevedudenhoeffer.com/steve/majordomo/agent"
|
mdagent "gitea.stevedudenhoeffer.com/steve/majordomo/agent"
|
||||||
"gitea.stevedudenhoeffer.com/steve/majordomo/llm"
|
"gitea.stevedudenhoeffer.com/steve/majordomo/llm"
|
||||||
@@ -62,13 +64,19 @@ func (h *handlers) agentChat(c *gin.Context) {
|
|||||||
return
|
return
|
||||||
}
|
}
|
||||||
|
|
||||||
send := openEventStream(c)
|
stream := openEventStream(c)
|
||||||
|
send := stream.send
|
||||||
|
|
||||||
|
// A model thinking hard between tool calls sends nothing for a while, and an
|
||||||
|
// idle proxy will cut a quiet connection. A comment frame every 20s keeps it
|
||||||
|
// open; SSE ignores comments, so this costs the client nothing.
|
||||||
|
stopBeat := stream.keepAlive(20 * time.Second)
|
||||||
|
|
|||||||
turn, err := h.agent.Run(c.Request.Context(), actor.ID, req.GardenID, req.Message,
|
turn, err := h.agent.Run(c.Request.Context(), actor.ID, req.GardenID, req.Message,
|
||||||
replayHistory(history),
|
replayHistory(history),
|
||||||
func(s mdagent.Step) {
|
func(s mdagent.Step) {
|
||||||
send(chatEvent{Step: &stepEvent{Index: s.Index, Tools: toolNames(s)}})
|
send(chatEvent{Step: &stepEvent{Index: s.Index, Tools: toolNames(s)}})
|
||||||
})
|
})
|
||||||
|
stopBeat()
|
||||||
|
gitea-actions
commented
🟡 stopBeat is called manually instead of via defer, so a panic in h.agent.Run skips cleanup (mitigated only by request-context cancellation) error-handling · flagged by 2 models
🪰 Gadfly · advisory 🟡 **stopBeat is called manually instead of via defer, so a panic in h.agent.Run skips cleanup (mitigated only by request-context cancellation)**
_error-handling · flagged by 2 models_
- **`internal/api/agent.go:79` — `stopBeat` is called manually instead of via `defer`.** `stopBeat := stream.keepAlive(...)` is started at line 73, then `h.agent.Run(...)` runs (lines 74–78), then `stopBeat()` is called as a plain statement at line 79 (before the error check). If `Run` (or anything between the two lines) panics, `stopBeat()` is never reached. The keep-alive goroutine does have a self-cleanup escape hatch — it also selects on `s.c.Request.Context().Done()` (line 159), and a panic…
<sub>🪰 Gadfly · advisory</sub>
|
|||||||
if err != nil {
|
if err != nil {
|
||||||
// The stream is already open, so an error is an event rather than a
|
// The stream is already open, so an error is an event rather than a
|
||||||
// status code — the client has committed to reading a stream by now.
|
// status code — the client has committed to reading a stream by now.
|
||||||
@@ -93,25 +101,71 @@ func (h *handlers) agentChat(c *gin.Context) {
|
|||||||
send(chatEvent{Done: turn})
|
send(chatEvent{Done: turn})
|
||||||
}
|
}
|
||||||
|
|
||||||
// openEventStream puts the response into SSE mode and returns a sender.
|
// eventStream serializes writes to one SSE response.
|
||||||
|
//
|
||||||
|
// The mutex is load-bearing, not decoration: step events are sent from the
|
||||||
|
// agent's run goroutine while the keep-alive ticker writes from its own, and two
|
||||||
|
// goroutines writing a ResponseWriter concurrently is a data race that corrupts
|
||||||
|
// frames long before it crashes anything.
|
||||||
|
type eventStream struct {
|
||||||
|
c *gin.Context
|
||||||
|
mu sync.Mutex
|
||||||
|
}
|
||||||
|
|
||||||
|
// openEventStream puts the response into SSE mode.
|
||||||
//
|
//
|
||||||
// Headers go out before the first write and the stream is flushed immediately,
|
// Headers go out before the first write and the stream is flushed immediately,
|
||||||
// so a proxy holding the response until it looks complete can't reintroduce
|
// so a proxy holding the response until it looks complete can't reintroduce
|
||||||
// exactly the silence streaming exists to remove.
|
// exactly the silence streaming exists to remove.
|
||||||
func openEventStream(c *gin.Context) func(chatEvent) {
|
func openEventStream(c *gin.Context) *eventStream {
|
||||||
c.Header("Content-Type", "text/event-stream")
|
c.Header("Content-Type", "text/event-stream")
|
||||||
c.Header("Cache-Control", "no-cache")
|
c.Header("Cache-Control", "no-cache")
|
||||||
c.Header("X-Accel-Buffering", "no")
|
c.Header("X-Accel-Buffering", "no")
|
||||||
c.Writer.Flush()
|
c.Writer.Flush()
|
||||||
|
return &eventStream{c: c}
|
||||||
|
}
|
||||||
|
|
||||||
return func(ev chatEvent) {
|
func (s *eventStream) send(ev chatEvent) {
|
||||||
b, err := json.Marshal(ev)
|
b, err := json.Marshal(ev)
|
||||||
if err != nil {
|
if err != nil {
|
||||||
slog.Error("api: encode chat event", "error", err)
|
slog.Error("api: encode chat event", "error", err)
|
||||||
return
|
return
|
||||||
|
}
|
||||||
|
s.write(fmt.Sprintf("data: %s\n\n", b))
|
||||||
|
}
|
||||||
|
|
||||||
|
func (s *eventStream) write(frame string) {
|
||||||
|
s.mu.Lock()
|
||||||
|
defer s.mu.Unlock()
|
||||||
|
_, _ = io.WriteString(s.c.Writer, frame)
|
||||||
|
s.c.Writer.Flush()
|
||||||
|
}
|
||||||
|
|
||||||
|
// keepAlive writes an SSE comment frame on an interval until the returned
|
||||||
|
// function is called, so a long silence while the model thinks doesn't look like
|
||||||
|
// a dead connection to whatever sits in between. SSE ignores comment frames, so
|
||||||
|
// this costs the client nothing.
|
||||||
|
func (s *eventStream) keepAlive(every time.Duration) func() {
|
||||||
|
done := make(chan struct{})
|
||||||
|
stopped := make(chan struct{})
|
||||||
|
go func() {
|
||||||
|
defer close(stopped)
|
||||||
|
t := time.NewTicker(every)
|
||||||
|
defer t.Stop()
|
||||||
|
for {
|
||||||
|
select {
|
||||||
|
case <-done:
|
||||||
|
return
|
||||||
|
case <-s.c.Request.Context().Done():
|
||||||
|
return
|
||||||
|
case <-t.C:
|
||||||
|
s.write(": keep-alive\n\n")
|
||||||
|
}
|
||||||
}
|
}
|
||||||
_, _ = fmt.Fprintf(c.Writer, "data: %s\n\n", b)
|
}()
|
||||||
c.Writer.Flush()
|
return func() {
|
||||||
|
close(done)
|
||||||
|
<-stopped
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
|||||||
@@ -130,11 +130,7 @@ func (s *Service) WithChangeSet(ctx context.Context, actorID, gardenID int64, op
|
|||||||
// which is exactly the situation undo exists for. Record what happened,
|
// which is exactly the situation undo exists for. Record what happened,
|
||||||
// mark the summary, and still report the failure.
|
// mark the summary, and still report the failure.
|
||||||
sc.summary = partialSummary(sc.summary)
|
sc.summary = partialSummary(sc.summary)
|
||||||
// Detached from cancellation on purpose. The commonest reason fn failed is
|
if _, cerr := s.commitScope(ctx, sc, nil); cerr != nil {
|
||||||
// that ctx was cancelled or timed out — and using that same dead context
|
|
||||||
// to record what committed would fail too, losing the history for changes
|
|
||||||
// that really happened. That is precisely the case this path exists for.
|
|
||||||
if _, cerr := s.commitScope(context.WithoutCancel(ctx), sc, nil); cerr != nil {
|
|
||||||
slog.Error("service: partial turn could not be recorded", "error", cerr, "garden", gardenID)
|
slog.Error("service: partial turn could not be recorded", "error", cerr, "garden", gardenID)
|
||||||
}
|
}
|
||||||
return nil, err
|
return nil, err
|
||||||
@@ -154,11 +150,23 @@ func partialSummary(summary string) string {
|
|||||||
// commitScope writes a scope's buffered revisions as one change set. revertsID is
|
// commitScope writes a scope's buffered revisions as one change set. revertsID is
|
||||||
// set only by RevertChangeSet. A scope with no revisions writes nothing — an
|
// set only by RevertChangeSet. A scope with no revisions writes nothing — an
|
||||||
// operation that changed nothing doesn't belong in history.
|
// operation that changed nothing doesn't belong in history.
|
||||||
|
//
|
||||||
|
// The write is DETACHED FROM CANCELLATION, always. By the time it runs, the data
|
||||||
|
// changes it describes have already committed — so cancelling it cannot undo
|
||||||
|
// anything, it can only lose the record of what happened and leave real changes
|
||||||
|
// with no way to undo them.
|
||||||
|
//
|
||||||
|
// This was originally only done on the failure path, on the reasoning that a
|
||||||
|
gitea-actions
commented
🟡 commitScope doc embeds a production incident post-mortem that belongs in the commit message, not godoc maintainability · flagged by 1 model
🪰 Gadfly · advisory 🟡 **commitScope doc embeds a production incident post-mortem that belongs in the commit message, not godoc**
_maintainability · flagged by 1 model_
- **`internal/service/revisions.go:159` — doc comment carries a production post-mortem that will rot.** The `commitScope` comment now embeds a historical narrative ("Found in production with 18 plantings and no change set behind them") alongside the durable rule. The rule ("the write is detached from cancellation, always") is worth keeping; the incident report belongs in the commit message / PR description, not the godoc, where it reads as rationale that future readers can't act on and will be t…
<sub>🪰 Gadfly · advisory</sub>
|
|||||||
|
// cancelled context is why fn failed. That missed the commoner case: an agent
|
||||||
|
// turn whose client disconnects can still COMPLETE, and then the success path
|
||||||
|
// commits with a dead context and loses the history anyway. Found in production
|
||||||
|
// with 18 plantings and no change set behind them.
|
||||||
func (s *Service) commitScope(ctx context.Context, sc *changeScope, revertsID *int64) (*domain.ChangeSet, error) {
|
func (s *Service) commitScope(ctx context.Context, sc *changeScope, revertsID *int64) (*domain.ChangeSet, error) {
|
||||||
revs := sc.taken()
|
revs := sc.taken()
|
||||||
if len(revs) == 0 {
|
if len(revs) == 0 {
|
||||||
return nil, nil
|
return nil, nil
|
||||||
}
|
}
|
||||||
|
ctx = context.WithoutCancel(ctx)
|
||||||
return s.store.WriteChangeSet(ctx, &domain.ChangeSet{
|
return s.store.WriteChangeSet(ctx, &domain.ChangeSet{
|
||||||
GardenID: sc.gardenID,
|
GardenID: sc.gardenID,
|
||||||
ActorID: sc.actorID,
|
ActorID: sc.actorID,
|
||||||
@@ -312,10 +320,9 @@ func (s *Service) RevertChangeSet(ctx context.Context, actorID, changeSetID int6
|
|||||||
changes, conflict, err := s.applyInverse(ctx, r, applied)
|
changes, conflict, err := s.applyInverse(ctx, r, applied)
|
||||||
if err != nil {
|
if err != nil {
|
||||||
// Record what actually landed before surfacing the failure, so the
|
// Record what actually landed before surfacing the failure, so the
|
||||||
// partial revert is visible and undoable rather than orphaned. Detached
|
// partial revert is visible and undoable rather than orphaned.
|
||||||
// from cancellation for the same reason as WithChangeSet's path: a
|
// (commitScope detaches from cancellation itself.)
|
||||||
// timed-out context can't be used to write the record of what it did.
|
if _, cerr := s.commitScope(ctx, sc, &target.ID); cerr != nil {
|
||||||
if _, cerr := s.commitScope(context.WithoutCancel(ctx), sc, &target.ID); cerr != nil {
|
|
||||||
slog.Error("service: partial revert could not be recorded", "error", cerr, "changeSet", changeSetID)
|
slog.Error("service: partial revert could not be recorded", "error", cerr, "changeSet", changeSetID)
|
||||||
}
|
}
|
||||||
return nil, nil, err
|
return nil, nil, err
|
||||||
|
|||||||
@@ -805,3 +805,57 @@ func countsTotal(counts []domain.ChangeCount) int {
|
|||||||
}
|
}
|
||||||
return n
|
return n
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// TestSucceededTurnRecordsEvenIfTheCallerWentAway is the production bug.
|
||||||
|
//
|
||||||
|
// The failure path was detached from cancellation; the SUCCESS path was not. An
|
||||||
|
// agent turn whose client disconnects can still COMPLETE — and then the success
|
||||||
|
// path committed with a dead context, the write failed, and real changes were
|
||||||
|
// left with no change set and no way to undo them. Found live with 18 plantings
|
||||||
|
// behind no history at all.
|
||||||
|
//
|
||||||
|
// Nothing about a commit needs the caller to still be there: by the time it
|
||||||
|
// runs, the data it describes has already been written.
|
||||||
|
func TestSucceededTurnRecordsEvenIfTheCallerWentAway(t *testing.T) {
|
||||||
|
s := newTestService(t, openConfig())
|
||||||
|
owner := seedUser(t, s, "[email protected]")
|
||||||
|
g := seedGarden(t, s, owner)
|
||||||
|
bed := seedBed(t, s, owner, g.ID)
|
||||||
|
plant := seedOwnPlant(t, s, owner, 15)
|
||||||
|
|
||||||
|
ctx, cancel := context.WithCancel(context.Background())
|
||||||
|
before := len(history(t, s, owner, g.ID))
|
||||||
|
|
||||||
|
// fn does its work and SUCCEEDS, but the caller goes away before it returns.
|
||||||
|
cs, err := s.WithChangeSet(ctx, owner, g.ID, ChangeSetOptions{
|
||||||
|
Source: domain.SourceAgent, Summary: "plant beans in the second bed",
|
||||||
|
}, func(ctx context.Context) error {
|
||||||
|
if _, err := s.FillNamedRegion(ctx, owner, bed.ID, "all", plant.ID, nil); err != nil {
|
||||||
|
return err
|
||||||
|
}
|
||||||
|
cancel() // the client disconnects, mid-turn, after the work landed
|
||||||
|
return nil
|
||||||
|
})
|
||||||
|
if err != nil {
|
||||||
|
t.Fatalf("WithChangeSet: %v", err)
|
||||||
|
}
|
||||||
|
if cs == nil {
|
||||||
|
t.Fatal("the turn changed things but produced no change set")
|
||||||
|
}
|
||||||
|
|
||||||
|
after := history(t, s, owner, g.ID)
|
||||||
|
if len(after) != before+1 {
|
||||||
|
t.Fatalf("recorded %d change sets, want 1", len(after)-before)
|
||||||
|
}
|
||||||
|
if after[0].Summary != "plant beans in the second bed" {
|
||||||
|
t.Errorf("summary = %q; a completed turn shouldn't be marked partial", after[0].Summary)
|
||||||
|
}
|
||||||
|
// And it's undoable, which is the entire point.
|
||||||
|
if _, conflicts, err := s.RevertChangeSet(context.Background(), owner, cs.ID, domain.SourceUI); err != nil || len(conflicts) != 0 {
|
||||||
|
t.Fatalf("the recorded turn should be undoable: err=%v conflicts=%+v", err, conflicts)
|
||||||
|
}
|
||||||
|
active, _ := s.store.ListActivePlantingsForObject(context.Background(), bed.ID)
|
||||||
|
if len(active) != 0 {
|
||||||
|
t.Errorf("%d plantings survived the undo", len(active))
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|||||||
Reference in New Issue
Block a user
🟡 Magic number keep-alive interval should be a named constant
maintainability · flagged by 2 models
internal/api/agent.go:73— Magic number heartbeat interval. The keep-alive duration20 * time.Secondis hardcoded as a literal at the call site, while every other timeout/duration in this package is a named constant (oidcDiscoveryTimeout,oidcExchangeTimeout, etc.). This breaks the project's existing pattern, buries the tuning knob, and makes it non-discoverable for anyone adjusting proxy timeouts later. It should be a package-level constant such as `sseKeepAliveInterval = 20 * tim…🪰 Gadfly · advisory