Skip to content

Commit 32e35d4

Browse files
aksOpsclaude
andcommitted
fix(serve): stop trigger-C stuck false-fires + boot-burst hub drop
Two v0.1 post-ship nits that the user's browser session surfaced: attention engine: trigger C (stuck) would instantly fire on daemon restart because the hub ring's replay delivered old tool_call events with their original (pre-restart) timestamps. The idle check used the raw lastCall, so a session with a tool_call 10 min before the restart already tripped the 5 min threshold at t=0. Fix: Engine.bootTime is stamped at NewEngine, and trigger C uses max(st.lastCall, bootTime) as the idle reference. A session truly idle for IdleMinutes post-boot still fires; replay-only signals no longer pre-age it. Regression test added. hub buffer: subChanBuffer raised from 128 to 1024. The boot-burst WARN ("hub subscriber dropping events filter=\"\" dropped_total=1") came from the quota ingester's catch-up scan + tailer initial replay fanning out tens of events faster than a newly-subscribed internal consumer could drain its 128-slot channel. 1024 absorbs the burst with negligible memory cost (~200 KB per subscriber) and the SlowConsumerDrop test is now anchored to subChanBuffer so future tweaks stay covered. Verification: go test ./... 493/24, race-clean. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
1 parent 3808f41 commit 32e35d4

4 files changed

Lines changed: 67 additions & 6 deletions

File tree

internal/serve/attention/engine.go

Lines changed: 17 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -92,6 +92,13 @@ type Engine struct {
9292
thr Thresholds
9393
now func() time.Time
9494

95+
// bootTime is the clock at NewEngine. Trigger C (stuck) uses
96+
// max(st.lastCall, bootTime) as its reference so sessions whose
97+
// only tool_call history came from a hub-ring replay don't
98+
// instantly trip stuck with an ancient timestamp. A session that
99+
// truly goes idle after boot will still fire after IdleMinutes.
100+
bootTime time.Time
101+
95102
mu sync.Mutex
96103
sessions_state map[string]*sessionState
97104
}
@@ -116,6 +123,7 @@ func NewEngine(hub *events.Hub, quota QuotaSource, sessions SessionSource, thr T
116123
sessions: sessions,
117124
thr: thr,
118125
now: clock,
126+
bootTime: clock(),
119127
sessions_state: make(map[string]*sessionState),
120128
}
121129
}
@@ -464,9 +472,16 @@ func (e *Engine) pickState(
464472
}
465473
}
466474

467-
// C · stuck — idle > threshold while tmux alive.
475+
// C · stuck — idle > threshold while tmux alive. Reference clamps
476+
// to bootTime so an ancient tool_call recovered from the hub ring
477+
// on daemon restart can't pre-age the signal; the session has to
478+
// go idle for IdleMinutes *since we started watching*.
468479
if e.thr.IdleMinutes > 0 && !st.lastCall.IsZero() {
469-
if now.Sub(st.lastCall) > time.Duration(e.thr.IdleMinutes)*time.Minute {
480+
ref := st.lastCall
481+
if ref.Before(e.bootTime) {
482+
ref = e.bootTime
483+
}
484+
if now.Sub(ref) > time.Duration(e.thr.IdleMinutes)*time.Minute {
470485
return Snapshot{
471486
State: StateStuck,
472487
Since: e.sinceOr(st, StateStuck, now),

internal/serve/attention/engine_test.go

Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -240,6 +240,44 @@ func TestTriggerC_Stuck(t *testing.T) {
240240
}
241241
}
242242

243+
// Regression: daemon restart replays old tool_calls from the hub ring
244+
// with timestamps > IdleMinutes ago. The previous implementation used
245+
// those timestamps directly and pre-tripped stuck on boot. Reference
246+
// now clamps to bootTime, so stuck can only fire on idle *since boot*.
247+
func TestTriggerC_Stuck_BootReplayDoesNotInstantlyFire(t *testing.T) {
248+
now := time.Unix(1_700_000_000, 0).UTC()
249+
hub := events.NewHub(50)
250+
q := newFakeQuota()
251+
s := newFakeSessions("alpha")
252+
thr := Defaults()
253+
thr.IdleMinutes = 5
254+
eng := newEngineAt(&now, hub, q, s, thr)
255+
256+
// Simulate ring replay: a tool_call from 10 minutes before boot.
257+
ancient := now.Add(-10 * time.Minute)
258+
eng.handleEvent(toolCallEv(t, "alpha", false, ancient))
259+
260+
// Immediately at boot: must NOT fire stuck.
261+
eng.evaluateAll()
262+
if snap, ok := eng.Snapshot("alpha"); ok {
263+
t.Fatalf("stuck fired on replay at boot; snap=%+v", snap)
264+
}
265+
266+
// 4 min after boot: still under the 5 min threshold since boot.
267+
now = now.Add(4 * time.Minute)
268+
eng.evaluateAll()
269+
if snap, ok := eng.Snapshot("alpha"); ok {
270+
t.Fatalf("stuck fired at 4 min since boot; snap=%+v", snap)
271+
}
272+
273+
// 6 min since boot with no fresh tool_call → stuck fires now.
274+
now = now.Add(2 * time.Minute)
275+
eng.evaluateAll()
276+
if snap, ok := eng.Snapshot("alpha"); !ok || snap.State != StateStuck {
277+
t.Fatalf("want stuck at 6 min since boot; got %+v ok=%v", snap, ok)
278+
}
279+
}
280+
243281
func TestTriggerD_TmuxDead(t *testing.T) {
244282
now := time.Unix(1_700_000_000, 0).UTC()
245283
hub := events.NewHub(50)

internal/serve/events/hub.go

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,13 @@ import (
1111

1212
const (
1313
defaultRingSize = 500
14-
subChanBuffer = 128
14+
// subChanBuffer sized to absorb boot bursts without dropping: the
15+
// quota ingester's catch-up scan + the tailer's initial JSONL
16+
// replay can fan out dozens of events in a few ms before an
17+
// internal subscriber's consumer loop gets scheduled. 1024 covers
18+
// that comfortably at ~200 KB per subscriber worst-case, and still
19+
// gives ordinary browser SSE tabs plenty of headroom.
20+
subChanBuffer = 1024
1521
dropLogInterval = time.Minute
1622
)
1723

internal/serve/events/hub_test.go

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -134,7 +134,9 @@ func TestHub_SlowConsumerDrop(t *testing.T) {
134134
slow, _ := h.Subscribe("", "")
135135
defer slow.Close()
136136

137-
const n = 1000
137+
// Anchor to the buffer size so this keeps testing "overflow"
138+
// behaviour if subChanBuffer changes in the future.
139+
n := subChanBuffer + 500
138140
done := make(chan struct{})
139141
go func() {
140142
defer close(done)
@@ -149,7 +151,7 @@ func TestHub_SlowConsumerDrop(t *testing.T) {
149151
t.Fatalf("publisher blocked on slow consumer")
150152
}
151153

152-
// Drain what slow can hold (subChanBuffer=128) and verify the rest were dropped.
154+
// Drain what slow can hold (subChanBuffer) and verify the rest were dropped.
153155
delivered := 0
154156
drain:
155157
for {
@@ -166,7 +168,7 @@ drain:
166168
if slow.Dropped() == 0 {
167169
t.Fatal("expected non-zero dropped counter")
168170
}
169-
if uint64(delivered)+slow.Dropped() != n {
171+
if uint64(delivered)+slow.Dropped() != uint64(n) {
170172
t.Fatalf("delivered(%d) + dropped(%d) != %d", delivered, slow.Dropped(), n)
171173
}
172174
t.Logf("slow consumer: published=%d delivered=%d dropped=%d", n, delivered, slow.Dropped())

0 commit comments

Comments
 (0)