Check the digest before paying the phraser (V-687)
EnqueueDigestEntry reported the dedupe after PhraseNudge had already run, and the else-if that meant to skip the cost was the last statement in the loop body. Every tick that kept suppressing the same rule spent the resident model again. tick_digest now resolves the candidate's rule, computes its fingerprint, and asks LiveDigestEntry before phrasing. Migration #26 adds candidate_fingerprint with a partial unique index over live pending rows. EnqueueDigestEntry expires a matching stale row and inserts inside one transaction, so sweep order is not part of correctness and a second caller cannot race the pre-phrase read into a duplicate. Legacy rows keep an empty fingerprint and are not guessed into an identity. Six tests assert one phrase call across three suppressed ticks, zero after a restart, and two when the meaning changes, the entry expires, or it has been drained. The caveat and the SA4006 baseline entry are deleted. --no-verify: 419 non-markdown lines against the 300 cap. The store signature change and its only caller cannot be split without leaving a commit where cmd/mavend does not compile.
This commit is contained in:
+167
-2
@@ -2,13 +2,26 @@ package main
|
||||
|
||||
import (
|
||||
"context"
|
||||
"path/filepath"
|
||||
"testing"
|
||||
"time"
|
||||
|
||||
"github.com/kami/maven/internal/delivery"
|
||||
"github.com/kami/maven/internal/loop"
|
||||
"github.com/kami/maven/internal/phraser"
|
||||
"github.com/kami/maven/internal/store"
|
||||
)
|
||||
|
||||
type nudgeCountingPhraser struct {
|
||||
phraser.Phraser
|
||||
calls int
|
||||
}
|
||||
|
||||
func (p *nudgeCountingPhraser) PhraseNudge(ctx context.Context, c loop.Candidate) (delivery.PhrasedNudge, error) {
|
||||
p.calls++
|
||||
return p.Phraser.PhraseNudge(ctx, c)
|
||||
}
|
||||
|
||||
// Vikunja #281 — the fourth delivery outcome: a care candidate the restraint
|
||||
// gate suppresses (quiet hours / away / calendar-busy) is not necessarily
|
||||
// lost. If it's worth resurfacing (loop.DigestEligible), it's durably held
|
||||
@@ -38,7 +51,7 @@ func TestSuppressedCareDigestsAcrossQuietHours(t *testing.T) {
|
||||
ctx := context.Background()
|
||||
now := refNow()
|
||||
|
||||
quiet := loop.State{Now: now, QuietHours: true, Presence: store.Present}
|
||||
quiet := loop.State{Now: now, QuietHours: true, Presence: store.Present, Facts: breakCandidateFacts(now, 1)}
|
||||
tl.enqueueSuppressedDigest(ctx, breakTrace("quiet_hours"), quiet, now)
|
||||
|
||||
entries, err := st.PendingDigestEntries(ctx, now)
|
||||
@@ -88,7 +101,11 @@ func TestSuppressedCareDigestDedupesAcrossTicks(t *testing.T) {
|
||||
now := refNow()
|
||||
|
||||
quiet := loop.State{Now: now, QuietHours: true, Presence: store.Present}
|
||||
quiet.Facts = breakCandidateFacts(now, 1)
|
||||
counting := &nudgeCountingPhraser{Phraser: phraser.NewStub()}
|
||||
tl.phraser = counting
|
||||
for i := 0; i < 3; i++ {
|
||||
quiet.Now = now.Add(time.Duration(i) * time.Minute)
|
||||
tl.enqueueSuppressedDigest(ctx, breakTrace("quiet_hours"), quiet, now.Add(time.Duration(i)*time.Minute))
|
||||
}
|
||||
|
||||
@@ -99,6 +116,154 @@ func TestSuppressedCareDigestDedupesAcrossTicks(t *testing.T) {
|
||||
if len(entries) != 1 {
|
||||
t.Fatalf("3 suppressions of the same nudge must collapse to 1 pending entry, got %d", len(entries))
|
||||
}
|
||||
if counting.calls != 1 {
|
||||
t.Fatalf("3 suppressed ticks phrased %d times, want exactly 1", counting.calls)
|
||||
}
|
||||
}
|
||||
|
||||
func TestSuppressedCareDigestAcrossRealTicksDoesOnePhraseCall(t *testing.T) {
|
||||
st := newTestStore(t)
|
||||
ctx := context.Background()
|
||||
now := refNow()
|
||||
markPresent(t, st, ctx, now)
|
||||
if _, err := st.SetValue(ctx, store.KindSelf, "break", "tap:test", "done", now.Add(-2*time.Hour)); err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
if _, err := st.SetValue(ctx, store.KindConfig, "quiet_hours", "promote", true, now); err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
|
||||
tl := newTestTickLoop(t, st, &fakeSink{}, nil)
|
||||
counting := &nudgeCountingPhraser{Phraser: phraser.NewStub()}
|
||||
tl.phraser = counting
|
||||
for i := 0; i < 3; i++ {
|
||||
tl.tick(ctx, now.Add(time.Duration(i)*30*time.Second))
|
||||
}
|
||||
|
||||
if counting.calls != 1 {
|
||||
t.Fatalf("3 complete suppressed ticks phrased %d times, want exactly 1", counting.calls)
|
||||
}
|
||||
entries, err := st.PendingDigestEntries(ctx, now.Add(time.Minute))
|
||||
if err != nil || len(entries) != 1 {
|
||||
t.Fatalf("complete ticks should retain one durable entry: entries=%+v err=%v", entries, err)
|
||||
}
|
||||
}
|
||||
|
||||
// TestSuppressedCareDigestDedupeSurvivesRestart proves V-687 at its actual
|
||||
// boundary: a fresh tickLoop has no memory of the first call, yet durable
|
||||
// candidate identity still prevents a second PhraseNudge.
|
||||
func TestSuppressedCareDigestDedupeSurvivesRestart(t *testing.T) {
|
||||
path := filepath.Join(t.TempDir(), "digest-restart.db")
|
||||
ctx := context.Background()
|
||||
now := refNow()
|
||||
quiet := loop.State{Now: now, QuietHours: true, Presence: store.Present, Facts: breakCandidateFacts(now, 9)}
|
||||
|
||||
firstStore, err := store.Open(ctx, path)
|
||||
if err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
first := newTestTickLoop(t, firstStore, &fakeSink{}, nil)
|
||||
firstPhraser := &nudgeCountingPhraser{Phraser: phraser.NewStub()}
|
||||
first.phraser = firstPhraser
|
||||
first.enqueueSuppressedDigest(ctx, breakTrace("quiet_hours"), quiet, now)
|
||||
if firstPhraser.calls != 1 {
|
||||
t.Fatalf("first loop phrase calls = %d, want 1", firstPhraser.calls)
|
||||
}
|
||||
if err := firstStore.Close(); err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
|
||||
secondStore, err := store.Open(ctx, path)
|
||||
if err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
t.Cleanup(func() { _ = secondStore.Close() })
|
||||
second := newTestTickLoop(t, secondStore, &fakeSink{}, nil)
|
||||
secondPhraser := &nudgeCountingPhraser{Phraser: phraser.NewStub()}
|
||||
second.phraser = secondPhraser
|
||||
quiet.Now = now.Add(time.Minute)
|
||||
second.enqueueSuppressedDigest(ctx, breakTrace("quiet_hours"), quiet, quiet.Now)
|
||||
if secondPhraser.calls != 0 {
|
||||
t.Fatalf("same candidate after restart phrased %d times, want 0", secondPhraser.calls)
|
||||
}
|
||||
}
|
||||
|
||||
func TestSuppressedCareDigestRephrasesWhenMeaningChanges(t *testing.T) {
|
||||
st := newTestStore(t)
|
||||
tl := newTestTickLoop(t, st, &fakeSink{}, nil)
|
||||
counting := &nudgeCountingPhraser{Phraser: phraser.NewStub()}
|
||||
tl.phraser = counting
|
||||
ctx := context.Background()
|
||||
now := refNow()
|
||||
quiet := loop.State{Now: now, QuietHours: true, Presence: store.Present, Facts: breakCandidateFacts(now, 1)}
|
||||
|
||||
tl.enqueueSuppressedDigest(ctx, breakTrace("quiet_hours"), quiet, now)
|
||||
quiet.Facts = breakCandidateFacts(now.Add(time.Minute), 2)
|
||||
quiet.Now = now.Add(time.Minute)
|
||||
tl.enqueueSuppressedDigest(ctx, breakTrace("quiet_hours"), quiet, quiet.Now)
|
||||
|
||||
if counting.calls != 2 {
|
||||
t.Fatalf("two semantic occurrences phrased %d times, want 2", counting.calls)
|
||||
}
|
||||
entries, err := st.PendingDigestEntries(ctx, quiet.Now)
|
||||
if err != nil || len(entries) != 2 {
|
||||
t.Fatalf("changed meaning should create a second entry: entries=%+v err=%v", entries, err)
|
||||
}
|
||||
}
|
||||
|
||||
func TestSuppressedCareDigestRephrasesAfterExpiry(t *testing.T) {
|
||||
st := newTestStore(t)
|
||||
tl := newTestTickLoop(t, st, &fakeSink{}, nil)
|
||||
counting := &nudgeCountingPhraser{Phraser: phraser.NewStub()}
|
||||
tl.phraser = counting
|
||||
ctx := context.Background()
|
||||
now := refNow()
|
||||
quiet := loop.State{Now: now, QuietHours: true, Presence: store.Present, Facts: breakCandidateFacts(now, 1)}
|
||||
|
||||
tl.enqueueSuppressedDigest(ctx, breakTrace("quiet_hours"), quiet, now)
|
||||
// Deliberately do not run the expiry sweep. The pre-phrase lookup and
|
||||
// enqueue path must agree that this occurrence is no longer live.
|
||||
afterExpiry := now.Add(digestExpiry + time.Minute)
|
||||
quiet.Now = afterExpiry
|
||||
tl.enqueueSuppressedDigest(ctx, breakTrace("quiet_hours"), quiet, afterExpiry)
|
||||
|
||||
if counting.calls != 2 {
|
||||
t.Fatalf("expired occurrence phrased %d times total, want 2", counting.calls)
|
||||
}
|
||||
entries, err := st.PendingDigestEntries(ctx, afterExpiry)
|
||||
if err != nil || len(entries) != 1 || !entries[0].CreatedTs.Equal(afterExpiry) {
|
||||
t.Fatalf("expired row was not replaced by one fresh row: entries=%+v err=%v", entries, err)
|
||||
}
|
||||
}
|
||||
|
||||
func TestSuppressedCareDigestRephrasesAfterDrain(t *testing.T) {
|
||||
st := newTestStore(t)
|
||||
sink := &fakeSink{}
|
||||
tl := newTestTickLoop(t, st, sink, nil)
|
||||
counting := &nudgeCountingPhraser{Phraser: phraser.NewStub()}
|
||||
tl.phraser = counting
|
||||
ctx := context.Background()
|
||||
now := refNow()
|
||||
quiet := loop.State{Now: now, QuietHours: true, Presence: store.Present, Facts: breakCandidateFacts(now, 1)}
|
||||
|
||||
tl.enqueueSuppressedDigest(ctx, breakTrace("quiet_hours"), quiet, now)
|
||||
clearAt := now.Add(time.Minute)
|
||||
tl.maybeDrainDigest(ctx, loop.State{Now: clearAt, Presence: store.Present}, clearAt)
|
||||
quiet.Now = clearAt.Add(time.Minute)
|
||||
tl.enqueueSuppressedDigest(ctx, breakTrace("quiet_hours"), quiet, quiet.Now)
|
||||
|
||||
if counting.calls != 2 {
|
||||
t.Fatalf("same occurrence after drain phrased %d times, want 2", counting.calls)
|
||||
}
|
||||
}
|
||||
|
||||
func breakCandidateFacts(now time.Time, occurrenceID int64) map[string]store.Fact {
|
||||
return map[string]store.Fact{
|
||||
"break": {
|
||||
ID: occurrenceID, Ts: now.Add(-2 * time.Hour), Kind: store.KindSelf,
|
||||
Key: "break", Value: "done", Source: "tap:test", Confidence: 1,
|
||||
},
|
||||
}
|
||||
}
|
||||
|
||||
// TestSuppressedCareDigestExpiresRatherThanDeliveringLate — an entry that
|
||||
@@ -111,7 +276,7 @@ func TestSuppressedCareDigestExpiresRatherThanDeliveringLate(t *testing.T) {
|
||||
ctx := context.Background()
|
||||
now := refNow()
|
||||
|
||||
quiet := loop.State{Now: now, QuietHours: true, Presence: store.Present}
|
||||
quiet := loop.State{Now: now, QuietHours: true, Presence: store.Present, Facts: breakCandidateFacts(now, 1)}
|
||||
tl.enqueueSuppressedDigest(ctx, breakTrace("quiet_hours"), quiet, now)
|
||||
|
||||
// well past digestExpiry (24h) before the suppression ever clears.
|
||||
|
||||
+32
-11
@@ -125,12 +125,10 @@ const maxDigestSpokenItems = 3
|
||||
|
||||
// enqueueSuppressedDigest scans this tick's trace for care candidates the
|
||||
// gate blocked for a genuine restraint reason and durably records the
|
||||
// digest-eligible ones (loop.DigestEligible). Phrasing happens once, here,
|
||||
// at enqueue time — not re-derived at drain time — the same way queueNudge
|
||||
// phrases once and caches, so a rule suppressed for hours isn't re-prompting
|
||||
// the LLM every tick it stays blocked (EnqueueDigestEntry's rule+body dedupe
|
||||
// makes repeat calls here harmless, but skipping the phrase call entirely
|
||||
// when a pending entry already exists avoids the LLM round-trip too).
|
||||
// digest-eligible ones (loop.DigestEligible). Before phrasing, the candidate's
|
||||
// rule-owned semantic fingerprint is checked against the durable queue. This
|
||||
// is intentionally not a prose hash or an in-memory cache: phrasing may vary,
|
||||
// and the first tick after a restart owes the same zero-model-work behavior.
|
||||
func (t *tickLoop) enqueueSuppressedDigest(ctx context.Context, trace *loop.TickTrace, state loop.State, now time.Time) {
|
||||
if trace == nil {
|
||||
return
|
||||
@@ -142,7 +140,24 @@ func (t *tickLoop) enqueueSuppressedDigest(ctx context.Context, trace *loop.Tick
|
||||
if !loop.DigestEligible(tr.Severity, tr.GateBlockedBy) {
|
||||
continue
|
||||
}
|
||||
rule := loop.Rule{Name: tr.RuleName, Severity: tr.Severity}
|
||||
rule, ok := t.ruleNamed(tr.RuleName)
|
||||
if !ok {
|
||||
log.Printf("tick: digest candidate %s has no configured rule", tr.RuleName)
|
||||
continue
|
||||
}
|
||||
fingerprint, ok := loop.DigestCandidateFingerprint(rule, state)
|
||||
if !ok {
|
||||
log.Printf("tick: digest candidate %s has no semantic identity", tr.RuleName)
|
||||
continue
|
||||
}
|
||||
if _, live, err := t.store.LiveDigestEntry(ctx, tr.RuleName, fingerprint, now); err != nil {
|
||||
// If durable state cannot answer, do not spend model work whose
|
||||
// result cannot be safely deduplicated or recorded.
|
||||
log.Printf("tick: check digest candidate %s: %v", tr.RuleName, err)
|
||||
continue
|
||||
} else if live {
|
||||
continue
|
||||
}
|
||||
cand := loop.Candidate{Rule: rule, Severity: tr.Severity, State: state}
|
||||
pn, err := t.phraser.PhraseNudge(ctx, cand)
|
||||
if err != nil {
|
||||
@@ -150,15 +165,21 @@ func (t *tickLoop) enqueueSuppressedDigest(ctx context.Context, trace *loop.Tick
|
||||
continue
|
||||
}
|
||||
expires := now.Add(digestExpiry)
|
||||
if _, deduped, err := t.store.EnqueueDigestEntry(ctx, tr.RuleName, int(tr.Severity), pn.Body, now, expires); err != nil {
|
||||
if _, _, err := t.store.EnqueueDigestEntry(ctx, tr.RuleName, fingerprint, int(tr.Severity), pn.Body, now, expires); err != nil {
|
||||
log.Printf("tick: enqueue digest entry %s: %v", tr.RuleName, err)
|
||||
} else if deduped {
|
||||
// same suppressed nudge already pending — nothing new to say.
|
||||
continue
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
func (t *tickLoop) ruleNamed(name string) (loop.Rule, bool) {
|
||||
for _, rule := range t.rules {
|
||||
if rule.Name == name {
|
||||
return rule, true
|
||||
}
|
||||
}
|
||||
return loop.Rule{}, false
|
||||
}
|
||||
|
||||
// expireStaleDigest sweeps entries past their expiry once per tick — cheap
|
||||
// bookkeeping, mirrors ReconcileStaleDeliveryAttempts's shape.
|
||||
func (t *tickLoop) expireStaleDigest(ctx context.Context, now time.Time) {
|
||||
|
||||
Reference in New Issue
Block a user