diff --git a/internal/rules/rules.go b/internal/rules/rules.go index 680d3b92..6d8db17c 100644 --- a/internal/rules/rules.go +++ b/internal/rules/rules.go @@ -144,6 +144,14 @@ func (e *Engine) Register(r Rule) { defer e.mu.Unlock() cp := r cp.Enabled = true + // A negative cooldown would slip past the `Cooldown > 0` suppression guard + // in Handle and behave as "no cooldown" — a silently-disabled rate limit if + // an operator fat-fingered a sign. Normalise to 0 (the documented + // no-cooldown value) so List reports it honestly and the intent is explicit. + if cp.Cooldown < 0 { + obs.Default().Warn("rule_negative_cooldown_clamped", "rule", r.Name, "cooldown", cp.Cooldown.String()) + cp.Cooldown = 0 + } e.rules[r.Name] = &cp delete(e.lastFire, r.Name) e.fires[r.Name] = 0 @@ -224,7 +232,7 @@ func (e *Engine) List() []Snapshot { // audit observer path must not block on them. func (e *Engine) Handle(entry audit.Entry) { e.mu.Lock() - candidates := make([]*Rule, 0, len(e.rules)) + candidates := make([]firedRule, 0, len(e.rules)) for _, r := range e.rules { if !r.Enabled { continue @@ -238,17 +246,56 @@ func (e *Engine) Handle(entry audit.Entry) { continue } } - e.lastFire[r.Name] = e.deps.Now() + // Optimistically record the fire under the lock so a concurrent + // Handle for the same rule is suppressed by the cooldown. If it turns + // out nothing actually dispatched (see fire's return), we roll this + // back below so a no-op fire doesn't consume the cooldown window. + prev, had := e.lastFire[r.Name] + bump := e.deps.Now() + e.lastFire[r.Name] = bump e.fires[r.Name]++ - candidates = append(candidates, r) + candidates = append(candidates, firedRule{rule: r, prevLast: prev, hadLast: had, bump: bump}) } e.mu.Unlock() - for _, r := range candidates { - e.fire(r, entry) + for _, c := range candidates { + if e.fire(c.rule, entry) { + continue + } + // Nothing dispatched — e.g. the rule's only action was an ActionTool + // dropped because inFlight was saturated. Roll back the optimistic + // accounting: otherwise the rule is reported as fired and, worse, its + // cooldown clock is now running, so the NEXT genuinely-matching event + // inside the window is wrongly suppressed. Restore lastFire only if it + // still holds our bump (a concurrent fire for the same rule may have + // legitimately advanced it — for Cooldown==0, where lastFire is + // display-only; with a cooldown, concurrent same-rule fires can't both + // pass the check above). + e.mu.Lock() + if e.fires[c.rule.Name] > 0 { + e.fires[c.rule.Name]-- + } + if e.lastFire[c.rule.Name].Equal(c.bump) { + if c.hadLast { + e.lastFire[c.rule.Name] = c.prevLast + } else { + delete(e.lastFire, c.rule.Name) + } + } + e.mu.Unlock() } } +// firedRule captures the pre-fire accounting state for a rule Handle decided to +// fire, so a fire whose actions all no-op (e.g. a saturation-dropped tool) can +// be rolled back to not consume its cooldown or inflate its fire count. +type firedRule struct { + rule *Rule + prevLast time.Time + hadLast bool + bump time.Time +} + // Test renders the actions without side effects and returns the // substitution output so operators can preview a rule. Used by // `/rules test`. @@ -266,10 +313,16 @@ func (e *Engine) Test(name string, entry audit.Entry) ([]string, error) { return out, nil } -func (e *Engine) fire(r *Rule, entry audit.Entry) { +// fire dispatches a matched rule's actions and reports whether at least one +// action actually dispatched. It returns false when every action no-ops — a +// missing webhook/tool dispatcher, an unknown kind, or an ActionTool dropped +// because the concurrency cap is saturated — so Handle can roll back the +// optimistic fire accounting for a rule that did nothing. +func (e *Engine) fire(r *Rule, entry audit.Entry) bool { payload := entryPayload(entry) logger := obs.Default().With("rule", r.Name, "tool", entry.Tool, "trace_id", entry.TraceID) + dispatched := false for _, a := range r.Actions { switch a.Kind { case ActionWebhook: @@ -278,8 +331,10 @@ func (e *Engine) fire(r *Rule, entry audit.Entry) { continue } e.deps.WebhookFire(a.Webhook, withTemplated(a.Params, payload, entry)) + dispatched = true case ActionLog: logger.Info("rule_fired", "message", render(firstString(a.Params, "message"), entry)) + dispatched = true case ActionTool: if e.deps.RunTool == nil { logger.Warn("rule_action_skipped", "kind", string(a.Kind), "reason", "no tool runner") @@ -317,10 +372,14 @@ func (e *Engine) fire(r *Rule, entry audit.Entry) { } } }) + // The slot is reserved and the goroutine launched; count it as + // dispatched even though completion is async. + dispatched = true default: logger.Warn("rule_unknown_kind", "kind", string(a.Kind)) } } + return dispatched } // matches applies the AND-over-non-empty predicate. Trailing "*" in Tool diff --git a/internal/rules/rules_test.go b/internal/rules/rules_test.go index 64f48ed2..1d8a12ac 100644 --- a/internal/rules/rules_test.go +++ b/internal/rules/rules_test.go @@ -603,3 +603,94 @@ func TestMatch_SuccessTrue_CombinedWithToolGlob(t *testing.T) { t.Errorf("expected 1 fire (workflow_* + success), got %d", fires) } } + +// snapOf returns the named rule's snapshot, failing if absent. +func snapOf(t *testing.T, e *Engine, name string) Snapshot { + t.Helper() + for _, s := range e.List() { + if s.Name == name { + return s + } + } + t.Fatalf("rule %q not found in List()", name) + return Snapshot{} +} + +// waitForCond polls until cond() or the deadline, failing on timeout. +func waitForCond(t *testing.T, d time.Duration, cond func() bool) { + t.Helper() + deadline := time.Now().Add(d) + for time.Now().Before(deadline) { + if cond() { + return + } + time.Sleep(5 * time.Millisecond) + } + t.Fatal("condition not met before deadline") +} + +// TestEngine_SaturationDropDoesNotConsumeCooldown pins the fix for the +// cooldown-accounting bug: a rule whose only action is a tool dropped because +// the concurrency cap is saturated must NOT be counted as fired and must NOT +// start its cooldown — otherwise the next genuinely-matching event inside the +// window would be wrongly suppressed (a real trigger silently swallowed). +func TestEngine_SaturationDropDoesNotConsumeCooldown(t *testing.T) { + now := time.Now() + var mu sync.Mutex + var calls int + eng := New(Deps{ + Now: func() time.Time { return now }, + RunTool: func(_ context.Context, _ string, _ map[string]interface{}) (string, error) { + mu.Lock() + calls++ + mu.Unlock() + return "", nil + }, + }) + eng.Register(Rule{ + Name: "gated", + Match: Match{Tool: "trigger"}, + Actions: []Action{{Kind: ActionTool, Tool: "slow_tool"}}, + Cooldown: time.Hour, + Enabled: true, + }) + entry := audit.Entry{Tool: "trigger"} + + // Saturate the global tool-action cap so the next dispatch is dropped. + eng.inFlight.Store(maxToolActions) + eng.Handle(entry) + + if snap := snapOf(t, eng, "gated"); snap.Fires != 0 { + t.Errorf("Fires=%d after saturation drop, want 0 (nothing dispatched)", snap.Fires) + } else if !snap.LastFire.IsZero() { + t.Error("LastFire set after saturation drop — cooldown wrongly consumed") + } + + // Free the cap; the SAME event must now fire, proving the earlier drop did + // not consume the 1h cooldown window. + eng.inFlight.Store(0) + eng.Handle(entry) + + if snap := snapOf(t, eng, "gated"); snap.Fires != 1 { + t.Errorf("Fires=%d after cap freed, want 1 (drop must not have consumed cooldown)", snap.Fires) + } else if snap.LastFire.IsZero() { + t.Error("LastFire not set after a real fire") + } + waitForCond(t, 2*time.Second, func() bool { mu.Lock(); defer mu.Unlock(); return calls == 1 }) +} + +// TestEngine_NegativeCooldownClampedToZero pins that a negative cooldown (an +// operator sign typo) is normalised to 0 rather than silently slipping past the +// `Cooldown > 0` suppression guard as "no cooldown". +func TestEngine_NegativeCooldownClampedToZero(t *testing.T) { + eng := New(Deps{}) + eng.Register(Rule{ + Name: "typo", + Match: Match{Tool: "x"}, + Actions: []Action{{Kind: ActionLog}}, + Cooldown: -5 * time.Second, + }) + if snap := snapOf(t, eng, "typo"); snap.Cooldown != 0 { + t.Errorf("negative cooldown not clamped: got %v, want 0", snap.Cooldown) + } +}