From cc73b386716320a44f7fcc98ac65c0146a96689f Mon Sep 17 00:00:00 2001 From: jochen Date: Thu, 15 Oct 2026 17:46:39 +0200 Subject: [PATCH] issue 797: tells no longer eat the conditions'/notify's cap, and a dropped tell is logged once an hour MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review round 1 of mesh-catalog found sentLastHour counting tells against CapPerHour (ADR 0380 §8 says tells keep their own cap, never shared), and the drop log firing on every drop instead of once an hour per channel as the comment already said. --- modules/messenger/cmd/messenger/holder.go | 50 ++++++++-------- .../messenger/cmd/messenger/holder_test.go | 59 +++++++++++++++++++ modules/messenger/cmd/messenger/outbox.go | 6 +- modules/messenger/cmd/messenger/status.go | 11 +++- 4 files changed, 99 insertions(+), 27 deletions(-) diff --git a/modules/messenger/cmd/messenger/holder.go b/modules/messenger/cmd/messenger/holder.go index 44a167b6..9182672c 100644 --- a/modules/messenger/cmd/messenger/holder.go +++ b/modules/messenger/cmd/messenger/holder.go @@ -321,30 +321,31 @@ type Holder struct { work sync.Mutex // one event, call or tick at a time mu sync.Mutex // what the status reads - open map[string]*Record - recent []Sent - refusals []RefusalNote - outbox map[string][]item - lastSend map[string]time.Time - lastWarn map[string]time.Time - lastTry map[string]time.Time - capSaid map[string]time.Time - chanErr map[string]string - chanErrAt map[string]time.Time - chanOK map[string]time.Time - unreadable int - lastBad string - lastBadAt time.Time - saidOnce map[string]time.Time - storeErr string - heard map[string]int - lastHeard time.Time - started time.Time - syncedAt time.Time - syncErr string - wantSync bool - history int - stale int + open map[string]*Record + recent []Sent + refusals []RefusalNote + outbox map[string][]item + lastSend map[string]time.Time + lastWarn map[string]time.Time + lastTry map[string]time.Time + capSaid map[string]time.Time + tellCapSaid map[string]time.Time + chanErr map[string]string + chanErrAt map[string]time.Time + chanOK map[string]time.Time + unreadable int + lastBad string + lastBadAt time.Time + saidOnce map[string]time.Time + storeErr string + heard map[string]int + lastHeard time.Time + started time.Time + syncedAt time.Time + syncErr string + wantSync bool + history int + stale int // tellSeq makes every tell's key its own, even when two calls land in the same instant. tellSeq int // answered is what came of each answer event, by its id: a redelivered one is acted on once. @@ -376,6 +377,7 @@ func (h *Holder) init() { h.lastWarn = map[string]time.Time{} h.lastTry = map[string]time.Time{} h.capSaid = map[string]time.Time{} + h.tellCapSaid = map[string]time.Time{} h.chanErr = map[string]string{} h.chanErrAt = map[string]time.Time{} h.chanOK = map[string]time.Time{} diff --git a/modules/messenger/cmd/messenger/holder_test.go b/modules/messenger/cmd/messenger/holder_test.go index 241b5dc2..e79286a9 100644 --- a/modules/messenger/cmd/messenger/holder_test.go +++ b/modules/messenger/cmd/messenger/holder_test.go @@ -576,6 +576,65 @@ func TestATellIsDroppedPastItsOwnHourlyCap(t *testing.T) { } } +func TestATellDoesNotCountTowardTheConditionsCap(t *testing.T) { + h, tg, _, c, _ := newHolder(t) + h.Desk = nil + // Bring conditions close to, but under, their own cap: CapPerHour-5. + for i := 0; i < CapPerHour-5; i++ { + h.Condition(EventRaised, cond(fmt.Sprintf("machine.m%d.silent", i), Urgent, "a machine is silent")) + c.pass(BurstWindow + time.Second) + h.Flush() + } + if len(tg.sends) != CapPerHour-5 { + t.Fatalf("sent %d conditions, want %d", len(tg.sends), CapPerHour-5) + } + // A full hour of tells: these must not be counted against the conditions' cap (ADR 0380 §8). + for i := 0; i < TellCapPerHour; i++ { + if _, err := h.Tell("mail", []string{"line"}, ""); err != nil { + t.Fatal(err) + } + } + h.Condition(EventRaised, cond("machine.mlast.silent", Urgent, "a machine is silent")) + c.pass(BurstWindow + time.Second) + h.Flush() + want := CapPerHour - 5 + TellCapPerHour + 1 + if len(tg.sends) != want { + t.Fatalf("sent %d, want %d (the condition after the tells still sent)", len(tg.sends), want) + } + if last := tg.sends[len(tg.sends)-1]; strings.HasPrefix(last.Title, "Mesh messages paused for this hour") { + t.Fatalf("the condition was held behind the tells' sends: %q", last.Title) + } +} + +func TestATellCapDropIsLoggedOnceAnHour(t *testing.T) { + h, tg, _, _, _ := newHolder(t) + h.Desk = nil + var logs []string + h.Logf = func(format string, args ...any) { logs = append(logs, fmt.Sprintf(format, args...)) } + for i := 0; i < TellCapPerHour; i++ { + if _, err := h.Tell("mail", []string{"line"}, ""); err != nil { + t.Fatal(err) + } + } + for i := 0; i < 3; i++ { + if _, err := h.Tell("mail", []string{"line"}, ""); err != nil { + t.Fatal(err) + } + } + if len(tg.sends) != TellCapPerHour { + t.Fatalf("sent %d of %d", len(tg.sends), TellCapPerHour) + } + dropLogs := 0 + for _, l := range logs { + if strings.Contains(l, "dropped") { + dropLogs++ + } + } + if dropLogs != 1 { + t.Fatalf("logged the drop %d times, want 1", dropLogs) + } +} + func TestATestMessageRespectsTheRule(t *testing.T) { h, tg, dt, _, _ := newHolder(t) if out := h.Test("telegram", "see https://example.org"); out["refused"] == "" || len(tg.sends) != 0 { diff --git a/modules/messenger/cmd/messenger/outbox.go b/modules/messenger/cmd/messenger/outbox.go index 31159a63..ab11d4d3 100644 --- a/modules/messenger/cmd/messenger/outbox.go +++ b/modules/messenger/cmd/messenger/outbox.go @@ -609,7 +609,9 @@ func (h *Holder) sendNow(ch Channel, key, what string, m Message) bool { return true } -// allow says whether a channel is under its cap: messages sent in the last hour, as recorded. +// allow says whether a channel is under its cap: messages sent in the last hour, as recorded. A +// tell is not counted here: it has its own cap (TellCapPerHour) so a burst of tells cannot crowd +// out a condition or an ask (ADR 0380 §8). func (h *Holder) allow(channel string) bool { return h.sentLastHour(channel) < CapPerHour } @@ -620,7 +622,7 @@ func (h *Holder) sentLastHour(channel string) int { since := h.Now().Add(-time.Hour) n := 0 for _, s := range h.recent { - if s.Channel == channel && s.Outcome == "sent" && s.At.After(since) { + if s.Channel == channel && s.What != "tell" && s.Outcome == "sent" && s.At.After(since) { n++ } } diff --git a/modules/messenger/cmd/messenger/status.go b/modules/messenger/cmd/messenger/status.go index 17a0cab6..cc89348a 100644 --- a/modules/messenger/cmd/messenger/status.go +++ b/modules/messenger/cmd/messenger/status.go @@ -361,7 +361,16 @@ func (h *Holder) Tell(headline string, lines []string, subject string) (map[stri } if !h.allowTell(name) { dropped = append(dropped, name) - h.Logf("[messenger] a tell was dropped on %s: it is at its own cap of %d tells an hour", name, TellCapPerHour) + h.mu.Lock() + said := h.tellCapSaid[name] + sayIt := said.IsZero() || now.Sub(said) >= time.Hour + if sayIt { + h.tellCapSaid[name] = now + } + h.mu.Unlock() + if sayIt { + h.Logf("[messenger] a tell was dropped on %s: it is at its own cap of %d tells an hour", name, TellCapPerHour) + } h.record(Sent{At: now, Channel: name, Key: key, What: "tell", Outcome: fmt.Sprintf("dropped: at its own cap of %d tells an hour", TellCapPerHour)}) continue