4914c45cb0
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.
324 lines
12 KiB
Go
324 lines
12 KiB
Go
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
|
|
// (internal/store's digest_entries) and spoken as one bundle once speaking
|
|
// is appropriate again — never while the suppression reason still holds.
|
|
|
|
func breakTrace(blockedBy string) *loop.TickTrace {
|
|
return &loop.TickTrace{
|
|
RuleTraces: []loop.RuleTrace{{
|
|
RuleName: "break",
|
|
Severity: loop.Sev2,
|
|
PredicateResult: true,
|
|
GateResult: false,
|
|
GateBlockedBy: blockedBy,
|
|
}},
|
|
}
|
|
}
|
|
|
|
// TestSuppressedCareDigestsAcrossQuietHours — a Sev2 care candidate blocked
|
|
// by quiet hours is enqueued into the durable digest, and is spoken as a
|
|
// "digest" nudge only once quiet hours actually end — never while still
|
|
// suppressed (that would just be a second way to nag through quiet hours).
|
|
func TestSuppressedCareDigestsAcrossQuietHours(t *testing.T) {
|
|
st := newTestStore(t)
|
|
sink := &fakeSink{}
|
|
tl := newTestTickLoop(t, st, sink, nil)
|
|
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)
|
|
|
|
entries, err := st.PendingDigestEntries(ctx, now)
|
|
if err != nil {
|
|
t.Fatalf("pending: %v", err)
|
|
}
|
|
if len(entries) != 1 || entries[0].Rule != "break" {
|
|
t.Fatalf("want 1 pending digest entry for break, got %+v", entries)
|
|
}
|
|
|
|
// still quiet hours: draining now must not speak — the same restraint
|
|
// that suppressed the live nudge must suppress the bundle too.
|
|
tl.maybeDrainDigest(ctx, quiet, now)
|
|
if len(sink.sends) != 0 {
|
|
t.Fatalf("digest must not drain while quiet hours holds, got %+v", sink.sends)
|
|
}
|
|
|
|
// quiet hours end: this is the moment speaking is appropriate again.
|
|
after := now.Add(time.Hour)
|
|
clear := loop.State{Now: after, QuietHours: false, Presence: store.Present}
|
|
tl.maybeDrainDigest(ctx, clear, after)
|
|
|
|
if len(sink.sends) != 1 {
|
|
t.Fatalf("want exactly 1 dispatched digest bundle, got %d: %+v", len(sink.sends), sink.sends)
|
|
}
|
|
if sink.sends[0].RuleName != "digest" {
|
|
t.Fatalf("want RuleName digest, got %q", sink.sends[0].RuleName)
|
|
}
|
|
|
|
remaining, err := st.PendingDigestEntries(ctx, after)
|
|
if err != nil {
|
|
t.Fatalf("pending after drain: %v", err)
|
|
}
|
|
if len(remaining) != 0 {
|
|
t.Fatalf("drained entry must no longer be pending, got %+v", remaining)
|
|
}
|
|
}
|
|
|
|
// TestSuppressedCareDigestDedupesAcrossTicks — quiet hours holding for
|
|
// several ticks must not enqueue several copies of the same suppressed
|
|
// nudge; he hears it once when the bundle finally drains.
|
|
func TestSuppressedCareDigestDedupesAcrossTicks(t *testing.T) {
|
|
st := newTestStore(t)
|
|
sink := &fakeSink{}
|
|
tl := newTestTickLoop(t, st, sink, nil)
|
|
ctx := context.Background()
|
|
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))
|
|
}
|
|
|
|
entries, err := st.PendingDigestEntries(ctx, now)
|
|
if err != nil {
|
|
t.Fatalf("pending: %v", err)
|
|
}
|
|
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
|
|
// aged out before the suppression cleared is dropped, not spoken late: a
|
|
// two-day-old "you skipped a break" is noise, not news.
|
|
func TestSuppressedCareDigestExpiresRatherThanDeliveringLate(t *testing.T) {
|
|
st := newTestStore(t)
|
|
sink := &fakeSink{}
|
|
tl := newTestTickLoop(t, st, sink, nil)
|
|
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)
|
|
|
|
// well past digestExpiry (24h) before the suppression ever clears.
|
|
stale := now.Add(48 * time.Hour)
|
|
tl.expireStaleDigest(ctx, stale)
|
|
|
|
clear := loop.State{Now: stale, QuietHours: false, Presence: store.Present}
|
|
tl.maybeDrainDigest(ctx, clear, stale)
|
|
|
|
if len(sink.sends) != 0 {
|
|
t.Fatalf("a stale digest entry must be dropped, not delivered late; got %+v", sink.sends)
|
|
}
|
|
}
|
|
|
|
// TestSuppressedCareDigestIgnoresHighSeverity — defense in depth at the
|
|
// wiring layer: even if a RuleTrace somehow showed a high-severity rule
|
|
// blocked by a care-only gate reason, the tick driver must not durably
|
|
// digest it. Alarms bypass the gate and deliver now, unchanged; they must
|
|
// never be silently delayed into a bundle.
|
|
func TestSuppressedCareDigestIgnoresHighSeverity(t *testing.T) {
|
|
st := newTestStore(t)
|
|
sink := &fakeSink{}
|
|
tl := newTestTickLoop(t, st, sink, nil)
|
|
ctx := context.Background()
|
|
now := refNow()
|
|
|
|
trace := &loop.TickTrace{RuleTraces: []loop.RuleTrace{{
|
|
RuleName: "service_down",
|
|
Severity: loop.Sev4,
|
|
PredicateResult: true,
|
|
GateResult: false,
|
|
GateBlockedBy: "quiet_hours",
|
|
}}}
|
|
quiet := loop.State{Now: now, QuietHours: true, Presence: store.Present}
|
|
tl.enqueueSuppressedDigest(ctx, trace, quiet, now)
|
|
|
|
entries, err := st.PendingDigestEntries(ctx, now)
|
|
if err != nil {
|
|
t.Fatalf("pending: %v", err)
|
|
}
|
|
if len(entries) != 0 {
|
|
t.Fatalf("high severity must never be digested, got %+v", entries)
|
|
}
|
|
}
|