loop: add rule trace/explanation engine

ExplainTick and ExplainGate produce a full TickTrace for every tick,
recording per-rule: predicate result, gate result, first gate blocker,
gate detail (snooze/cooldown/presence etc.), and win/loss info.

IPC layer: new MethodTickTrace, DTOs (TickTrace, RuleTrace, GateDetail),
dispatch, client proxy, and CoreAPI interface method.

Daemon: tickLoop caches the latest trace; daemonAPI wraps storeAPI
with a TickTrace override that returns the cached trace.

Tests: 15 new tests for ExplainGate (all blockers, bypass conditions,
ordering) and ExplainTick (nothing fires, one fires, tiebreak,
winner/lost_to recording, gate-blocked recording).
This commit is contained in:
kami
2026-07-05 13:14:58 +04:00
parent 354990fed0
commit 2689db1248
9 changed files with 579 additions and 6 deletions
+1 -1
View File
@@ -62,7 +62,7 @@ Notes:
|---|------|--------|--------|
| 12 | **Recurring reminders** — cron+next_fire_ts cols, RescheduleReminder, dispatcher logic | 1eca17f | done |
| 13 | **Capability model**`scope` column on tools table, migration, UI, tests | 6b80fd0 | done |
| 14 | **Notification batching / digest mode**morning/evening rollup instead of per-event nudges. Configurable window, accumulated messages in one delivery | — | pending |
| 14 | **Notification batching/digest mode**in-memory queue, configurable window/max_items/severity_ceiling | 354990f | done |
| 15 | **Rule trace / explanation engine**`why` query: "why did/didn't you nudge me?" Reads predicate eval log. New `/trace` page or CLI query | — | pending |
| 16 | **Backup/restore automation** — scripts/maven-backup.sh with backup/restore/verify/list | 3f09cdb | done |
+6 -3
View File
@@ -175,10 +175,13 @@ func run(args []string) error {
tickInterval := time.Duration(cfg.TickInterval)
repeatInterval := time.Duration(cfg.RepeatInterval)
autotuneInterval := time.Duration(cfg.AutotuneInterval)
loop := newTickLoop(st, gatherer, dispatcher, phr, rules, tickInterval, repeatInterval, autotuneInterval, cfg.Digest)
tl := newTickLoop(st, gatherer, dispatcher, phr, rules, tickInterval, repeatInterval, autotuneInterval, cfg.Digest)
// ----- IPC boundary (core ↔ modules) -----
coreAPI := ipc.NewStoreAPI(st)
coreAPI := &daemonAPI{
CoreAPI: ipc.NewStoreAPI(st),
getTrace: tl.trace,
}
srv, err := ipc.Listen(cfg.SocketPath, coreAPI)
if err != nil {
return fmt.Errorf("ipc listen: %w", err)
@@ -216,7 +219,7 @@ func run(args []string) error {
wg.Add(1)
go func() {
defer wg.Done()
loop.run(ctx)
tl.run(ctx)
}()
<-ctx.Done()
+66 -2
View File
@@ -20,6 +20,7 @@ import (
"github.com/kami/maven/internal/config"
"github.com/kami/maven/internal/delivery"
"github.com/kami/maven/internal/ipc"
"github.com/kami/maven/internal/loop"
"github.com/kami/maven/internal/phraser"
"github.com/kami/maven/internal/store"
@@ -62,8 +63,9 @@ type tickLoop struct {
// IS the insistence signal). keyed by rule name. nil phrase for a rule
// = no successful initial dispatch yet (cold-start edge — fall back to
// a generic body).
mu sync.Mutex
mu sync.Mutex
lastPhrase map[string]delivery.PhrasedNudge
lastTrace *loop.TickTrace // cached from the most recent tick
}
func newTickLoop(
@@ -133,7 +135,11 @@ func (t *tickLoop) tick(ctx context.Context, now time.Time) {
}
// proactive: at most one candidate, max severity.
if cand := loop.Tick(state, t.rules); cand != nil {
cand, trace := loop.ExplainTick(state, t.rules)
t.mu.Lock()
t.lastTrace = trace
t.mu.Unlock()
if cand != nil {
if t.shouldQueue(cand) {
t.queueNudge(ctx, cand, state, now)
} else {
@@ -363,4 +369,62 @@ func defaultConfigPath() string {
return "mavend.json"
}
return filepath.Join(home, ".config", "maven", "mavend.json")
}
// trace returns the most recent TickTrace, or nil if no tick has run yet.
func (t *tickLoop) trace() *loop.TickTrace {
t.mu.Lock()
defer t.mu.Unlock()
return t.lastTrace
}
// daemonAPI wraps a store-backed CoreAPI and overrides TickTrace with the
// daemon's in-memory tick trace cache.
type daemonAPI struct {
ipc.CoreAPI
getTrace func() *loop.TickTrace
}
func (d *daemonAPI) TickTrace(ctx context.Context) (ipc.TickTrace, error) {
trace := d.getTrace()
if trace == nil {
return ipc.TickTrace{}, nil
}
return toIPCTickTrace(*trace), nil
}
func toIPCTickTrace(t loop.TickTrace) ipc.TickTrace {
rules := make([]ipc.RuleTrace, len(t.RuleTraces))
for i, r := range t.RuleTraces {
rules[i] = toIPCRuleTrace(r)
}
return ipc.TickTrace{
Now: t.Now,
Winner: t.Winner,
Rules: rules,
}
}
func toIPCRuleTrace(r loop.RuleTrace) ipc.RuleTrace {
return ipc.RuleTrace{
RuleName: r.RuleName,
Severity: int(r.Severity),
PredicateResult: r.PredicateResult,
GateResult: r.GateResult,
GateBlockedBy: r.GateBlockedBy,
GateDetail: toIPCGateDetail(r.GateDetail),
WasSelected: r.WasSelected,
LostTo: r.LostTo,
}
}
func toIPCGateDetail(d loop.GateDetail) ipc.GateDetail {
return ipc.GateDetail{
SnoozeUntil: d.SnoozeUntil,
CooldownUntil: d.CooldownUntil,
QuietHours: d.QuietHours,
CalendarBusy: d.CalendarBusy,
Presence: d.Presence,
InertKeysMissing: d.InertKeysMissing,
}
}
+36
View File
@@ -240,6 +240,42 @@ type CoreAPI interface {
LookupTool(ctx context.Context, name string) (Tool, error)
ListTools(ctx context.Context, status string) ([]Tool, error)
RevertFact(ctx context.Context, key string) (int64, error)
// TickTrace returns the most recent tick's rule trace. The daemon caches
// this after every tick; the store adapter returns an error (trace is not
// persisted — it's a daemon-level cache).
TickTrace(ctx context.Context) (TickTrace, error)
}
// --- Rule trace / explanation DTOs ---
// RuleTrace — per-rule evaluation result for one tick.
type RuleTrace struct {
RuleName string `json:"rule_name"`
Severity int `json:"severity"`
PredicateResult bool `json:"predicate_result"`
GateResult bool `json:"gate_result"`
GateBlockedBy string `json:"gate_blocked_by,omitempty"`
GateDetail GateDetail `json:"gate_detail,omitempty"`
WasSelected bool `json:"was_selected"`
LostTo string `json:"lost_to,omitempty"`
}
// GateDetail — snapshot of the values the gate checked.
type GateDetail struct {
SnoozeUntil *time.Time `json:"snooze_until,omitempty"`
CooldownUntil *time.Time `json:"cooldown_until,omitempty"`
QuietHours bool `json:"quiet_hours"`
CalendarBusy bool `json:"calendar_busy"`
Presence string `json:"presence"`
InertKeysMissing []string `json:"inert_keys_missing,omitempty"`
}
// TickTrace — snapshot of one tick's rule evaluations.
type TickTrace struct {
Now time.Time `json:"now"`
Winner string `json:"winner"`
Rules []RuleTrace `json:"rules"`
}
// ErrToolNotFound — no tool row with this name (re-exported store sentinel for
+8
View File
@@ -345,6 +345,14 @@ func (c *Client) ListTools(ctx context.Context, status string) ([]Tool, error) {
return r.Tools, nil
}
func (c *Client) TickTrace(ctx context.Context) (TickTrace, error) {
var t TickTrace
if err := c.call(ctx, MethodTickTrace, nil, &t); err != nil {
return TickTrace{}, err
}
return t, nil
}
func (c *Client) RevertFact(ctx context.Context, key string) (int64, error) {
var result struct {
NewID int64 `json:"new_id"`
+11
View File
@@ -174,6 +174,10 @@ func (a *storeAPI) RevertFact(ctx context.Context, key string) (int64, error) {
return newID, mapErr(err)
}
func (a *storeAPI) TickTrace(ctx context.Context) (TickTrace, error) {
return TickTrace{}, errors.New("store: tick trace not available via direct store API")
}
func (a *storeAPI) ListTools(ctx context.Context, status string) ([]Tool, error) {
ts, err := a.s.ListTools(ctx, status)
if err != nil {
@@ -629,6 +633,13 @@ func (s *Server) dispatch(ctx context.Context, req Request) (json.RawMessage, er
}
return marshalResult(map[string]int64{"new_id": newID}), nil
case MethodTickTrace:
t, err := s.api.TickTrace(ctx)
if err != nil {
return nil, err
}
return marshalResult(t), nil
case MethodAssertStepUp:
if s.StepUp != nil {
return marshalResult(nil), s.StepUp(ctx)
+1
View File
@@ -35,6 +35,7 @@ const (
MethodLookupTool Method = "lookup_tool"
MethodListTools Method = "list_tools"
MethodRevertFact Method = "revert_fact"
MethodTickTrace Method = "tick_trace"
)
// Request — one frame from module to core. Params is the JSON-encoded argument
+140
View File
@@ -0,0 +1,140 @@
package loop
import (
"time"
"github.com/kami/maven/internal/store"
)
// TickTrace — snapshot of one tick's rule evaluations.
type TickTrace struct {
Now time.Time `json:"now"`
Winner string `json:"winner"` // empty if nothing fired
RuleTraces []RuleTrace `json:"rules"`
}
// RuleTrace — per-rule evaluation result for one tick.
type RuleTrace struct {
RuleName string `json:"rule_name"`
Severity Severity `json:"severity"`
PredicateResult bool `json:"predicate_result"`
GateResult bool `json:"gate_result"`
GateBlockedBy string `json:"gate_blocked_by,omitempty"` // "snooze"|"cooldown"|"quiet_hours"|"calendar_busy"|"presence"|"inert_no_data"|"" (passed)
GateDetail GateDetail `json:"gate_detail,omitempty"`
WasSelected bool `json:"was_selected"`
LostTo string `json:"lost_to,omitempty"` // rule that won instead
}
// GateDetail — snapshot of the values the gate checked.
type GateDetail struct {
SnoozeUntil *time.Time `json:"snooze_until,omitempty"`
CooldownUntil *time.Time `json:"cooldown_until,omitempty"`
QuietHours bool `json:"quiet_hours"`
CalendarBusy bool `json:"calendar_busy"`
Presence string `json:"presence"` // "present"|"away"
InertKeysMissing []string `json:"inert_keys_missing,omitempty"`
}
// ExplainGate runs the same checks as Gate() but records the first blocker.
// Returns (passed, blockedBy, detail).
func ExplainGate(s State, r Rule) (bool, string, GateDetail) {
var d GateDetail
d.QuietHours = s.QuietHours
d.CalendarBusy = s.CalendarBusy
d.Presence = "present"
if s.Presence == store.Away {
d.Presence = "away"
}
// Snooze
if until, ok := s.SnoozeUntil[r.Name]; ok && s.Now.Before(until) {
d.SnoozeUntil = &until
return false, "snooze", d
}
// Cooldown
if until, ok := s.CooldownUntil[r.Name]; ok && s.Now.Before(until) {
d.CooldownUntil = &until
return false, "cooldown", d
}
// Quiet hours (care only)
if s.QuietHours && r.Severity.IsCare() {
return false, "quiet_hours", d
}
// Calendar busy (care only)
if s.CalendarBusy && r.Severity.IsCare() {
return false, "calendar_busy", d
}
// Presence away (care only)
if s.Presence == store.Away && r.Severity.IsCare() {
return false, "presence", d
}
// InertWhenNoData
for _, k := range r.InertWhenNoData {
if _, ok := s.Fact(k); !ok {
d.InertKeysMissing = append(d.InertKeysMissing, k)
}
}
if len(d.InertKeysMissing) > 0 {
return false, "inert_no_data", d
}
return true, "", d
}
// ExplainTick evaluates all rules and returns both the best Candidate and
// a full TickTrace explaining every rule's result. Pure: no I/O.
func ExplainTick(s State, rules []Rule) (*Candidate, *TickTrace) {
trace := &TickTrace{
Now: s.Now,
}
var best *Candidate
for _, r := range rules {
tr := RuleTrace{
RuleName: r.Name,
Severity: r.Severity,
}
// Predicate
tr.PredicateResult = r.Predicate(s)
if !tr.PredicateResult {
tr.GateBlockedBy = "predicate"
trace.RuleTraces = append(trace.RuleTraces, tr)
continue
}
// Gate
var passed bool
passed, tr.GateBlockedBy, tr.GateDetail = ExplainGate(s, r)
tr.GateResult = passed
if !passed {
trace.RuleTraces = append(trace.RuleTraces, tr)
continue
}
// Candidate comparison
cand := &Candidate{Rule: r, Severity: r.Severity, State: s}
if best == nil || cand.Severity > best.Severity ||
(cand.Severity == best.Severity && cand.Rule.Name < best.Rule.Name) {
if best != nil {
for i := range trace.RuleTraces {
if trace.RuleTraces[i].RuleName == best.Rule.Name {
trace.RuleTraces[i].LostTo = r.Name
break
}
}
}
best = cand
tr.WasSelected = true
} else {
tr.LostTo = best.Rule.Name
}
trace.RuleTraces = append(trace.RuleTraces, tr)
}
if best != nil {
trace.Winner = best.Rule.Name
}
return best, trace
}
+310
View File
@@ -0,0 +1,310 @@
package loop
import (
"testing"
"time"
"github.com/kami/maven/internal/store"
)
// ----------------------------- ExplainGate --------------------------------
func TestExplainGate_AllPass(t *testing.T) {
now := refTime()
s := State{Now: now, Presence: store.Present}
r := Rule{Name: "test", Severity: Sev3, Predicate: func(State) bool { return true }}
passed, blocked, d := ExplainGate(s, r)
if !passed {
t.Fatalf("all-pass gate: want passed, blocked by %q; detail=%+v", blocked, d)
}
}
func TestExplainGate_Snooze(t *testing.T) {
now := refTime()
s := State{
Now: now,
Presence: store.Present,
SnoozeUntil: map[string]time.Time{"water": now.Add(time.Hour)},
Facts: map[string]store.Fact{"water": factAt("water", "tap:water", `"250ml"`, now.Add(-4*time.Hour))},
}
r := WaterRule()
passed, blocked, d := ExplainGate(s, r)
if passed || blocked != "snooze" {
t.Fatalf("snooze: want blocked=snooze, got passed=%v blocked=%q", passed, blocked)
}
if d.SnoozeUntil == nil || !d.SnoozeUntil.Equal(now.Add(time.Hour)) {
t.Fatalf("snooze-until missing or wrong: %v", d.SnoozeUntil)
}
}
func TestExplainGate_Cooldown(t *testing.T) {
now := refTime()
s := State{
Now: now,
Presence: store.Present,
CooldownUntil: map[string]time.Time{"water": now.Add(10 * time.Minute)},
Facts: map[string]store.Fact{"water": factAt("water", "tap:water", `"250ml"`, now.Add(-4*time.Hour))},
}
r := WaterRule()
passed, blocked, d := ExplainGate(s, r)
if passed || blocked != "cooldown" {
t.Fatalf("cooldown: want blocked=cooldown, got passed=%v blocked=%q", passed, blocked)
}
if d.CooldownUntil == nil || !d.CooldownUntil.Equal(now.Add(10*time.Minute)) {
t.Fatalf("cooldown-until missing or wrong: %v", d.CooldownUntil)
}
}
func TestExplainGate_QuietHours(t *testing.T) {
now := refTime()
s := State{Now: now, Presence: store.Present, QuietHours: true}
r := WaterRule() // Sev1 — care
passed, blocked, _ := ExplainGate(s, r)
if passed || blocked != "quiet_hours" {
t.Fatalf("quiet hours: want blocked=quiet_hours, got passed=%v blocked=%q", passed, blocked)
}
}
func TestExplainGate_QuietHoursOpsBypass(t *testing.T) {
now := refTime()
s := State{Now: now, Presence: store.Present, QuietHours: true,
Facts: map[string]store.Fact{"netdata_alarm": factAt("netdata_alarm", "poll:netdata", `"critical"`, now.Add(-1*time.Minute))},
}
r := NetdataCriticalRule() // Sev3 — ops
passed, blocked, d := ExplainGate(s, r)
if !passed {
t.Fatalf("ops sev3 should bypass quiet hours, blocked=%q detail=%+v", blocked, d)
}
}
func TestExplainGate_CalendarBusy(t *testing.T) {
now := refTime()
s := State{Now: now, Presence: store.Present, CalendarBusy: true}
r := WaterRule() // Sev1
passed, blocked, _ := ExplainGate(s, r)
if passed || blocked != "calendar_busy" {
t.Fatalf("calendar busy: want blocked=calendar_busy, got passed=%v blocked=%q", passed, blocked)
}
}
func TestExplainGate_PresenceAway(t *testing.T) {
now := refTime()
s := State{Now: now, Presence: store.Away}
r := WaterRule() // Sev1 care
passed, blocked, d := ExplainGate(s, r)
if passed || blocked != "presence" {
t.Fatalf("presence away: want blocked=presence, got passed=%v blocked=%q detail=%+v", passed, blocked, d)
}
if d.Presence != "away" {
t.Fatalf("detail presence: want away, got %q", d.Presence)
}
}
func TestExplainGate_PresenceAwayOpsBypass(t *testing.T) {
now := refTime()
s := State{Now: now, Presence: store.Away,
Facts: map[string]store.Fact{"service_down": factAt("service_down", "poll:uptimekuma", `"down"`, now.Add(-1*time.Minute))},
}
r := ServiceDownRule() // Sev4 ops
passed, blocked, d := ExplainGate(s, r)
if !passed {
t.Fatalf("ops sev4 should bypass away, blocked=%q detail=%+v", blocked, d)
}
}
func TestExplainGate_InertNoData(t *testing.T) {
now := refTime()
s := State{Now: now, Presence: store.Present} // no facts at all
r := WaterRule() // InertWhenNoData: ["water"]
passed, blocked, d := ExplainGate(s, r)
if passed || blocked != "inert_no_data" {
t.Fatalf("inert: want blocked=inert_no_data, got passed=%v blocked=%q", passed, blocked)
}
if len(d.InertKeysMissing) != 1 || d.InertKeysMissing[0] != "water" {
t.Fatalf("inert keys: want [water], got %v", d.InertKeysMissing)
}
}
func TestExplainGate_AllBlockersOrdered(t *testing.T) {
// Snooze is checked before cooldown, quiet hours, etc.
now := refTime()
s := State{
Now: now,
Presence: store.Present,
SnoozeUntil: map[string]time.Time{"water": now.Add(time.Hour)},
CooldownUntil: map[string]time.Time{"water": now.Add(10 * time.Minute)},
QuietHours: true,
}
r := WaterRule()
_, blocked, d := ExplainGate(s, r)
if blocked != "snooze" {
t.Fatalf("snooze should be checked first: got blocked=%q", blocked)
}
if d.SnoozeUntil == nil {
t.Fatal("snooze-until should be set")
}
}
// ----------------------------- ExplainTick --------------------------------
func TestExplainTick_NothingFires(t *testing.T) {
now := refTime()
s := State{Now: now, Presence: store.Away}
cand, trace := ExplainTick(s, DefaultRules())
if cand != nil {
t.Fatalf("nil candidate expected, got %+v", cand)
}
if trace.Winner != "" {
t.Fatalf("empty winner expected, got %q", trace.Winner)
}
if !trace.Now.Equal(now) {
t.Fatalf("trace now mismatch")
}
if len(trace.RuleTraces) != len(DefaultRules()) {
t.Fatalf("expected %d rule traces, got %d", len(DefaultRules()), len(trace.RuleTraces))
}
}
func TestExplainTick_OneFires(t *testing.T) {
now := refTime()
s := State{
Now: now,
Presence: store.Present,
Facts: map[string]store.Fact{
"water": factAt("water", "tap:water", `"250ml"`, now.Add(-4*time.Hour)),
},
}
cand, trace := ExplainTick(s, DefaultRules())
if cand == nil || cand.Rule.Name != "water" {
t.Fatalf("want water candidate, got %+v", cand)
}
if trace.Winner != "water" {
t.Fatalf("winner water, got %q", trace.Winner)
}
var found bool
for _, r := range trace.RuleTraces {
if r.RuleName == "water" {
found = true
if !r.PredicateResult {
t.Error("water predicate should be true")
}
if !r.GateResult {
t.Error("water gate should be true")
}
if !r.WasSelected {
t.Error("water should be selected")
}
}
}
if !found {
t.Fatal("water rule not in trace")
}
}
func TestExplainTick_Tiebreak(t *testing.T) {
// Two rules with same severity — alphabetically first should win.
now := refTime()
s := State{
Now: now,
Presence: store.Present,
Facts: map[string]store.Fact{
"water": factAt("water", "tap:water", `"250ml"`, now.Add(-4*time.Hour)),
"meal": factAt("meal", "tap:meal", `"pizza"`, now.Add(-7*time.Hour)),
},
}
cand, trace := ExplainTick(s, []Rule{MealRule(), WaterRule()})
if cand == nil {
t.Fatal("expected a candidate")
}
// Both Sev1, "meal" < "water" alphabetically → meal wins
if cand.Rule.Name != "meal" {
t.Fatalf("tiebreak: want meal, got %q", cand.Rule.Name)
}
if trace.Winner != "meal" {
t.Fatalf("winner should be meal, got %q", trace.Winner)
}
// meal was selected, water lost to meal
var waterFound, mealFound bool
for _, r := range trace.RuleTraces {
switch r.RuleName {
case "water":
waterFound = true
if r.LostTo != "meal" {
t.Errorf("water.LostTo = %q, want meal", r.LostTo)
}
if r.WasSelected {
t.Error("water should not be selected in tiebreak")
}
case "meal":
mealFound = true
if !r.WasSelected {
t.Error("meal should be selected")
}
if r.LostTo != "" {
t.Errorf("meal.LostTo = %q, want empty", r.LostTo)
}
}
}
if !waterFound || !mealFound {
t.Fatal("both rules should be in trace")
}
}
func TestExplainTick_WinnerRecorded(t *testing.T) {
now := refTime()
// water (Sev1) and service_down (Sev4) both want to fire.
s := State{
Now: now,
Presence: store.Present,
Facts: map[string]store.Fact{
"water": factAt("water", "tap:water", `"250ml"`, now.Add(-4*time.Hour)),
"service_down": factAt("service_down", "poll:uptimekuma", `"down"`, now.Add(-1*time.Minute)),
},
}
cand, trace := ExplainTick(s, DefaultRules())
if cand == nil || cand.Rule.Name != "service_down" {
t.Fatalf("max severity wins: want service_down, got %+v", cand)
}
if trace.Winner != "service_down" {
t.Fatalf("winner = %q, want service_down", trace.Winner)
}
// water lost to service_down
var waterLost bool
for _, r := range trace.RuleTraces {
if r.RuleName == "water" && r.LostTo == "service_down" {
waterLost = true
}
}
if !waterLost {
t.Error("water should show lost_to=service_down")
}
}
func TestExplainTick_GateBlockedRecorded(t *testing.T) {
now := refTime()
s := State{
Now: now,
Presence: store.Present,
QuietHours: true,
Facts: map[string]store.Fact{
"water": factAt("water", "tap:water", `"250ml"`, now.Add(-4*time.Hour)),
},
}
_, trace := ExplainTick(s, DefaultRules())
for _, tr := range trace.RuleTraces {
if tr.RuleName == "water" {
if tr.GateBlockedBy != "quiet_hours" {
t.Errorf("water blocked by %q, want quiet_hours", tr.GateBlockedBy)
}
if tr.PredicateResult != true {
t.Error("water predicate should be true")
}
if tr.GateResult != false {
t.Error("water gate should be false")
}
}
}
}