From 3345ff93170ab351e2ffffb41df6ed8989e28152 Mon Sep 17 00:00:00 2001 From: jochen Date: Sat, 10 Oct 2026 14:01:57 +0200 Subject: [PATCH 1/3] One message per problem: a reminder replaces, a blip says nothing (issues 373 and 369) The operator stopped believing the mesh's notifications: one problem stood twice on the desk (a reminder beside the message it followed, an escalation then a reminder 31 s later), a unit failing again at each apply was said again 22 times, and a question's buttons outlived it on a reminder the ask's end never reached. - messenger: a reminder or escalation is said in place of the problem's message (Replace under its handle), alone, never as a digest line; a problem first said in a digest gets its own message next time. A reminder counts from when it was last said. A clearing is said once it stays cleared 2 min (10 min once it came back); back before that, the message continues without a word. Cleared before ever said and back: said. An ask's expiry is said with its day. - desk-channel: a send or show under a handle already shown replaces its notification by the notifier's replace id. - telegram: the same deletes the earlier message and sends the new one, ringing as its kind rings; one it cannot delete loses its buttons. --- modules/desk-channel/README.md | 4 + modules/desk-channel/cmd/desk-channel/desk.go | 9 +- .../cmd/desk-channel/desk_test.go | 39 ++++ modules/messenger/README.md | 17 +- .../messenger/cmd/messenger/details_test.go | 25 ++- .../messenger/cmd/messenger/history_test.go | 2 +- modules/messenger/cmd/messenger/holder.go | 109 ++++++++-- .../messenger/cmd/messenger/holder_test.go | 68 ++++-- .../cmd/messenger/onemessage_test.go | 198 ++++++++++++++++++ modules/messenger/cmd/messenger/outbox.go | 43 +++- .../messenger/cmd/messenger/seatchannel.go | 16 ++ modules/messenger/cmd/messenger/sync.go | 1 + modules/messenger/cmd/messenger/words.go | 17 ++ modules/messenger/cmd/messenger/words_test.go | 2 + modules/telegram/README.md | 3 + modules/telegram/cmd/telegram/channel.go | 26 ++- modules/telegram/cmd/telegram/channel_test.go | 45 ++++ 17 files changed, 569 insertions(+), 55 deletions(-) create mode 100644 modules/messenger/cmd/messenger/onemessage_test.go diff --git a/modules/desk-channel/README.md b/modules/desk-channel/README.md index d92f5139..925e1d2a 100644 --- a/modules/desk-channel/README.md +++ b/modules/desk-channel/README.md @@ -11,6 +11,10 @@ each machine the operator sits at (the `node-notifier` seat), and says which but was made. A message with buttons stays until it is dismissed. - **A notifier that started again** (`dunst.started`) is shown again every open message with buttons it showed. - A message no machine took is said to the router as failed; the router tries it again. +- **One notification per message** (issue 373): an `edit`, and a `send` or `show` under a handle already shown (a + reminder, an escalation), replace that message's notification on each machine by its id (the notifier's + `replace_id`), so a problem is one notification updated in place. An edit goes only where it was shown; a + message said again is shown anew on a machine it was not. ## What the operator gives diff --git a/modules/desk-channel/cmd/desk-channel/desk.go b/modules/desk-channel/cmd/desk-channel/desk.go index 9c90ece1..68ef6ba4 100644 --- a/modules/desk-channel/cmd/desk-channel/desk.go +++ b/modules/desk-channel/cmd/desk-channel/desk.go @@ -141,8 +141,13 @@ func (d *Desk) Take(subject string, body json.RawMessage) error { machines = []string{on} } } + // **One notification per message** (issue 373): an edit, and a message said again under a handle already + // shown (a reminder, an escalation), replace the notification it had on each machine — dunst's replace id — + // so a problem is one notification updated in place, never one more beside it. An edit stays quiet where + // it was shown; a message said again is shown anew where it was not. + edit := parts[4] == asks.Edit var before *Shown - if parts[4] == asks.Edit { + if edit || !m.Secret { var err error if before, err = d.Store.Get(m.Handle); err != nil { return err @@ -154,7 +159,7 @@ func (d *Desk) Take(subject string, body json.RawMessage) error { replace := 0 if before != nil { replace = before.On[machine] - if replace == 0 { + if edit && replace == 0 { continue // an edit goes where the message was shown, and nowhere new } } diff --git a/modules/desk-channel/cmd/desk-channel/desk_test.go b/modules/desk-channel/cmd/desk-channel/desk_test.go index 6a8caa91..88037440 100644 --- a/modules/desk-channel/cmd/desk-channel/desk_test.go +++ b/modules/desk-channel/cmd/desk-channel/desk_test.go @@ -259,3 +259,42 @@ func TestItRunsAsItsOwnAccount(t *testing.T) { t.Errorf("the account %v, its state %v, its settings %v", account, state, settings) } } + +// Issue 373: a message said again under its handle (a reminder, an escalation) replaces its notification on +// each machine — the notifier is called with that notification's replace id — and is shown anew only where it +// was not shown; a message under a new handle replaces nothing. +func TestAMessageSaidAgainUnderItsHandleReplacesItsNotification(t *testing.T) { + d, shown, _, store := newDesk(t, "laptop", "desktop") + take(t, d, asks.Send, asks.Message{Handle: "m1", Title: "2 failed services on shanks"}) + take(t, d, asks.Send, asks.Message{Handle: "m2", Title: "another problem"}) + if len(*shown) != 4 { + t.Fatalf("shown %d", len(*shown)) + } + for _, n := range *shown { + if _, has := n.args["replace_id"]; has { + t.Fatalf("a new message replaced a notification: %+v", n) + } + } + first := store["m1"].On + // The desk now names a third machine as well. + d.Machines = func() []string { return []string{"laptop", "desktop", "third"} } + take(t, d, asks.Show, asks.Message{Handle: "m1", Title: "Still open: 2 failed services on shanks", Urgent: true, + Buttons: []asks.Button{{Label: "Silence for a week", Ticket: "t1"}}}) + again := (*shown)[4:] + if len(again) != 3 { + t.Fatalf("said again on %d machines", len(again)) + } + for _, n := range again { + want, was := first[n.machine] + got, replaces := n.args["replace_id"] + switch { + case was && (!replaces || got != want): + t.Errorf("on %s the reminder did not replace notification %d: %v", n.machine, want, n.args) + case !was && replaces: + t.Errorf("on %s, where it was not shown, it replaced %v", n.machine, got) + } + } + if s := store["m1"]; len(s.On) != 3 || len(s.Message.Buttons) != 1 { + t.Fatalf("what is shown was not kept: %+v", s) + } +} diff --git a/modules/messenger/README.md b/modules/messenger/README.md index 9907a96d..380c7402 100644 --- a/modules/messenger/README.md +++ b/modules/messenger/README.md @@ -114,12 +114,21 @@ warning kept quiet is also said once after a day. | When | What | |---|---| | `condition-raised` | one message, deduplicated by the condition's key | -| still open after 1 h (urgent) or 12 h (warning) | once more — never sooner than that after it was first said | -| `condition-changed` from warning to urgent | once more, to both channels | -| `condition-cleared` | the first message edited to say so; said inside a digest, a line in the next one | -| cleared and raised again within 10 min | the same message, edited back to open — not a new one | +| still open after 1 h (urgent) or 12 h (warning) | once more, in place of its message — never sooner than that after it was last said | +| `condition-changed` from warning to urgent | once more, in place of its message, to both channels | +| `condition-cleared` | once it stays cleared 2 min (10 min once it came back): its message edited to say so; said inside a digest, a line in the next one | +| cleared and raised again before its clearing was said | nothing: to the operator it never ended — a unit failing again after each apply is one message, not one per apply | +| cleared, said so, and raised again within 10 min | the same message, edited back to open — not a new one | | silenced | nothing, its clearing included | +**One message per problem** (issue 373). A record keeps the id of its message on each channel; a reminder or +an escalation is said **in place of it** — the channel takes the earlier one away and shows the new one as a +new message is shown, so it rings once and no second message stands beside the first (the desk replaces the +notification by its id; Telegram deletes the earlier message). A message said again goes alone, never as a +line of a digest beside the message it follows; one first said inside a digest gets a message of its own the +next time, and later words replace or edit that one. An ask's buttons live on that one message, so an ask that +ends takes them away everywhere; its expiry is said with its day when it is not today. + - **Routing:** urgent to every kind that can send; a warning to the desk where it can send, otherwise to the channel that reaches the operator away; an ask to every kind that carries one of its answers. - **Bursts are one message.** What is to be said on a channel is held **30 s** from the first and goes diff --git a/modules/messenger/cmd/messenger/details_test.go b/modules/messenger/cmd/messenger/details_test.go index def1cb06..46d9f79e 100644 --- a/modules/messenger/cmd/messenger/details_test.go +++ b/modules/messenger/cmd/messenger/details_test.go @@ -11,6 +11,15 @@ import ( // open message", because each new message replaced the ticket of the one before it. Every message still // shown keeps a Details of its own, used once, and Details never acts. +// shownOn is every message a channel was given: sent, or said again in place of an earlier one (issue 373). +func shownOn(ch *fakeChannel) []Message { + out := append([]Message(nil), ch.sends...) + for _, r := range ch.replaced { + out = append(out, r.m) + } + return out +} + func detailsOf(t *testing.T, m Message) string { t.Helper() tok := ticketFor(m, DetailsLabel) @@ -47,10 +56,13 @@ func TestDetailsWorksOnEachOfThreeWarningsOnceEach(t *testing.T) { settle(h, c) } } - if len(tg.sends) != 3 { - t.Fatalf("%d messages, want 3", len(tg.sends)) + // Issue 373: one problem said again replaces its message rather than standing beside it; each of + // the three messages still has a Details of its own. + msgs := shownOn(tg) + if len(msgs) != 3 { + t.Fatalf("%d messages, want 3", len(msgs)) } - for _, m := range tg.sends { + for _, m := range msgs { toks = append(toks, detailsOf(t, m)) } if toks[0] == toks[1] || toks[1] == toks[2] || toks[0] == toks[2] { @@ -188,10 +200,11 @@ func TestAnUnreadyChannelPushesOutNoShownDetails(t *testing.T) { tg.notReady = nil c.pass(2 * time.Minute) h.Flush() - if len(tg.sends) != 2 { - t.Fatalf("%d messages, want 2", len(tg.sends)) + msgs := shownOn(tg) + if len(msgs) != 2 { + t.Fatalf("%d messages, want 2", len(msgs)) } - for _, tk := range []string{tok, detailsOf(t, tg.sends[1])} { + for _, tk := range []string{tok, detailsOf(t, msgs[1])} { if out, err := h.Chosen("telegram", choiceOf(tk, "42", c.now())); err != nil || out != "shown" { t.Errorf("Details: %q %v", out, err) } diff --git a/modules/messenger/cmd/messenger/history_test.go b/modules/messenger/cmd/messenger/history_test.go index d8571174..a8285d77 100644 --- a/modules/messenger/cmd/messenger/history_test.go +++ b/modules/messenger/cmd/messenger/history_test.go @@ -292,7 +292,7 @@ func TestABurstIsOneMessage(t *testing.T) { for i := 0; i < 3; i++ { h.Condition(EventCleared, Condition{Key: fmt.Sprintf("seat.s%d.silent", i)}) } - runFor(h, c, time.Minute) + runFor(h, c, ClearSettle+time.Minute) // a clearing is said once it stays cleared (issue 373) if len(tg.sends) != 2 || len(tg.edits) != 0 || !strings.HasPrefix(tg.sends[1].Title, "Mesh: 3 resolved") { t.Fatalf("sends %d edits %d: %q", len(tg.sends), len(tg.edits), tg.sends[len(tg.sends)-1].Title) } diff --git a/modules/messenger/cmd/messenger/holder.go b/modules/messenger/cmd/messenger/holder.go index 5fce4fd7..dfff2c47 100644 --- a/modules/messenger/cmd/messenger/holder.go +++ b/modules/messenger/cmd/messenger/holder.go @@ -25,9 +25,11 @@ package main // // - On `condition-raised`: one message, deduplicated by the condition's key. Said again with the // same key while open, it is the same message, not a second. -// - Once more if still open after 1 hour (urgent) or 12 hours (warning). -// - On `condition-cleared`: the first message is edited where the channel can (both can). -// Cleared and raised again within ten minutes, it is the same message, edited back to open. +// - Once more if still open after 1 hour (urgent) or 12 hours (warning), counted from when it was last +// said; a reminder or an escalation replaces its message, never stands beside it (issue 373). +// - On `condition-cleared`: once it stays cleared ClearSettle, its message is edited where the channel can +// (both can). Raised again before that, nothing is said: to the operator it never ended. Cleared, said +// so, and raised again within ten minutes, it is the same message, edited back to open. // - A silenced condition sends nothing. // - Urgent to both channels; warning to the desktop when the operator's session is there, // otherwise to Telegram. @@ -59,9 +61,13 @@ const ( // QuietRemindAfter: a warning kept quiet as needing nothing is said once after this. QuietRemindAfter = 24 * time.Hour ReopenWindow = 10 * time.Minute - CapPerHour = 20 - KeptSends = 200 - KeptRefusals = 50 + // ClearSettle: a clearing is said once the condition stayed cleared this long. One raised again sooner + // (a unit failing again after each apply, issue 373) continues its message without a word, and its + // clearing is never said. Once it has come back, its next clearing waits the whole ReopenWindow. + ClearSettle = 2 * time.Minute + CapPerHour = 20 + KeptSends = 200 + KeptRefusals = 50 // FreshFor: an event older than this by its own time is history — state, never a message. FreshFor = 10 * time.Minute @@ -120,6 +126,18 @@ type Channel interface { CanEdit() bool } +// replacer is a channel that can say a message again in place of the one it showed under that id: the earlier +// one goes, the new one is shown as a new message is — it rings as its kind rings (issue 373). A reminder or +// an escalation is then one message per problem, never one more beside it. +type replacer interface { + Replace(id string, m Message) error +} + +func replaces(ch Channel) bool { + _, ok := ch.(replacer) + return ok +} + // silentEditor is a channel whose edits notify nobody (Telegram's are): what is over is said there // even when it ended while the holder was away, since saying it costs the operator nothing. type silentEditor interface{ SilentEdit() bool } @@ -160,14 +178,22 @@ type Record struct { More string `json:"more"` Raised time.Time `json:"raised"` SilencedTill time.Time `json:"silenced_till,omitempty"` - Sent map[string]string `json:"sent,omitempty"` // channel -> the first message's id; "" when said in a digest + Sent map[string]string `json:"sent,omitempty"` // channel -> its message's id; "" when said in a digest FirstSent time.Time `json:"first_sent,omitempty"` - Reminded bool `json:"reminded,omitempty"` - Pending string `json:"pending,omitempty"` // what could not be said yet: raised, reminder, … - Folded bool `json:"folded,omitempty"` // held by the cap - Cleared time.Time `json:"cleared,omitempty"` - Count int `json:"count"` - Refused string `json:"refused,omitempty"` + // LastSaid is when a message about it last went out: a reminder is due its bound after it, never sooner + // (an escalation followed by a reminder 31 s later, issue 373). + LastSaid time.Time `json:"last_said,omitempty"` + // ClearUnsaid: cleared, and the clearing not said yet — it is said once it stays cleared ClearSettle; + // raised again before, the message continues as if it never cleared. ClearSilent: said only where an edit + // notifies nobody (it ended while this holder was away). + ClearUnsaid bool `json:"clear_unsaid,omitempty"` + ClearSilent bool `json:"clear_silent,omitempty"` + Reminded bool `json:"reminded,omitempty"` + Pending string `json:"pending,omitempty"` // what could not be said yet: raised, reminder, … + Folded bool `json:"folded,omitempty"` // held by the cap + Cleared time.Time `json:"cleared,omitempty"` + Count int `json:"count"` + Refused string `json:"refused,omitempty"` // History: known from the state or from an old event, and never said — not news. History bool `json:"history,omitempty"` // Seen is when this holder last took word of it; the open set read after it is authoritative. @@ -454,14 +480,27 @@ func (h *Holder) raised(rec Record, quiet bool) { if old != nil && now.Sub(old.Cleared) < ReopenWindow { // Cleared and raised again within ten minutes: the same message, back to open (to-be 45 §2). h.mu.Lock() + blip := old.ClearUnsaid + gone := now.Sub(old.Cleared) old.Cleared = time.Time{} + old.ClearUnsaid, old.ClearSilent = false, false old.Count++ old.Summary, old.Severity, old.SilencedTill = rec.Summary, rec.Severity, rec.SilencedTill old.takeWords(rec) old.Seen = now h.mu.Unlock() - if !quiet && !old.silenced(now) && old.told() { + switch { + case quiet || old.silenced(now): + case blip: + // Its clearing was never said (issue 373): to the operator it never ended, so nothing is said now. + h.Logf("[messenger] %s back %s after it cleared, which was not said yet: the same message continues, nothing said", + old.Key, roughly(gone)) + h.record(Sent{At: now, Channel: "-", Key: old.Key, What: "reopened", Outcome: "quiet: back before its clearing was said"}) + case old.told(): h.edit(old, "reopened", false) + case !needsNothing(old) && !h.queued(old.Key): + // Cleared before it was ever said, and back: a problem the operator has not heard of is said. + h.deliver(old, "raised") } h.persist(old) return @@ -553,11 +592,32 @@ func (h *Holder) cleared(key string, quiet bool) { h.Logf("[messenger] %s cleared before it was said: nothing to unsay", key) } default: - h.edit(old, "cleared", quiet) + // Said once it stays cleared (ClearSettle; a condition that came back, ReopenWindow): a blip of a few + // seconds is not said at all (issue 373). + h.mu.Lock() + old.ClearUnsaid, old.ClearSilent = true, quiet + h.mu.Unlock() } h.persist(old) } +// clearSettle is how long a record stays cleared before its clearing is said: one that came back before +// waits the whole reopen window, so a condition that flaps is said cleared once, when it stopped flapping. +func clearSettle(r *Record) time.Duration { + if r.Count > 1 { + return ReopenWindow - time.Minute + } + return ClearSettle +} + +// lastSaid is when a message about a record last went out. +func lastSaid(r *Record) time.Time { + if !r.LastSaid.IsZero() { + return r.LastSaid + } + return r.FirstSent +} + // Tick does what time asks: reminders, retries, what is held, and forgetting what cleared long // enough ago that a new raise is a new message. func (h *Holder) Tick() { @@ -578,7 +638,17 @@ func (h *Holder) Tick() { for _, r := range recs { switch { case !r.Cleared.IsZero(): - if now.Sub(r.Cleared) >= ReopenWindow { + if r.ClearUnsaid && now.Sub(r.Cleared) >= clearSettle(r) { + h.mu.Lock() + r.ClearUnsaid = false + silent := r.ClearSilent + h.mu.Unlock() + if !r.silenced(now) { + h.edit(r, "cleared", silent) + } + h.persist(r) + } + if !r.ClearUnsaid && now.Sub(r.Cleared) >= ReopenWindow && !h.queued(r.Key) { h.mu.Lock() delete(h.open, r.Key) h.mu.Unlock() @@ -601,9 +671,10 @@ func (h *Holder) Tick() { h.deliver(r, "quiet-reminder") h.persist(r) case !r.Reminded && !r.FirstSent.IsZero() && now.Sub(r.Raised) >= remindAfter(r.Severity) && - now.Sub(r.FirstSent) >= remindAfter(r.Severity): + now.Sub(lastSaid(r)) >= remindAfter(r.Severity): // Once more after its bound — counted from its raising, and never sooner after it was - // first said (an old condition said at a reading of the state is not reminded at once). + // last said (an old condition said at a reading of the state is not reminded at once, nor one + // just escalated: issue 373). h.mu.Lock() r.Reminded = true h.mu.Unlock() @@ -714,7 +785,7 @@ func (h *Holder) askLines(rec *AskRecord) []string { } } if !rec.Ask.Expires.IsZero() && rec.Ask.OnExpiry != "" { - lines = append(lines, "If nobody answers by "+rec.Ask.Expires.In(h.zone()).Format("15:04")+": "+rec.Ask.OnExpiry+".") + lines = append(lines, "If nobody answers by "+by(rec.Ask.Expires, h.Now(), h.zone())+": "+rec.Ask.OnExpiry+".") } return lines } diff --git a/modules/messenger/cmd/messenger/holder_test.go b/modules/messenger/cmd/messenger/holder_test.go index 1f11b367..737f4aed 100644 --- a/modules/messenger/cmd/messenger/holder_test.go +++ b/modules/messenger/cmd/messenger/holder_test.go @@ -17,6 +17,22 @@ type fakeChannel struct { edits map[string]Message n int silent bool // edits notify nobody, as Telegram's + // replaced is each message said again in place of an earlier one, as the id it replaced and the message. + replaced []replacement +} + +type replacement struct { + id string + m Message +} + +// Replace says a message again in place of an earlier one: shown as a new message is, under the same id. +func (f *fakeChannel) Replace(id string, m Message) error { + if f.fail != nil { + return f.fail + } + f.replaced = append(f.replaced, replacement{id, m}) + return nil } func (f *fakeChannel) SilentEdit() bool { return f.silent } @@ -208,7 +224,7 @@ func TestTheCapIsALastLineAndIsSaidOnce(t *testing.T) { } func TestAMessageCarryingAnAddressIsRefusedAndSaidWithItsWordsWithheld(t *testing.T) { - h, tg, _, _, _ := newHolder(t) + h, tg, _, c, _ := newHolder(t) var emitted []string h.Emit = func(e string, _ any) error { emitted = append(emitted, e); return nil } h.Condition(EventRaised, cond("provider.keycloak.ace.failing", Urgent, "cannot reach 192.168.1.20:8443 with token=abc")) @@ -231,6 +247,8 @@ func TestAMessageCarryingAnAddressIsRefusedAndSaidWithItsWordsWithheld(t *testin } // Its clearing keeps the words withheld. h.Condition(EventCleared, Condition{Key: "provider.keycloak.ace.failing"}) + c.pass(ClearSettle) + h.Tick() for _, m := range tg.edits { if strings.Contains(m.Text(), "192.168") { t.Fatalf("the clearing carried it: %q", m.Text()) @@ -262,24 +280,26 @@ func TestStillOpenPastItsBoundItIsSaidOnceMore(t *testing.T) { settle(h, c) c.pass(59 * time.Minute) h.Tick() - if len(tg.sends) != 2 { - t.Fatalf("reminded before the hour: %d", len(tg.sends)) + if len(tg.sends) != 2 || len(tg.replaced) != 0 { + t.Fatalf("reminded before the hour: %d %d", len(tg.sends), len(tg.replaced)) } c.pass(2 * time.Minute) h.Tick() - if len(tg.sends) != 3 || (tg.sends[2].Title != "Still open: bus controller slow-consumer" || !strings.Contains(tg.sends[2].Body, "for 61 min")) { - t.Fatalf("urgent reminder: %d %q", len(tg.sends), tg.sends[len(tg.sends)-1].Title) + // Said once more in place of its first message (issue 373): one message per problem. + if len(tg.sends) != 2 || len(tg.replaced) != 1 || tg.replaced[0].id != "1" || + tg.replaced[0].m.Title != "Still open: bus controller slow-consumer" || !strings.Contains(tg.replaced[0].m.Body, "for 61 min") { + t.Fatalf("urgent reminder: %d sends, %+v", len(tg.sends), tg.replaced) } c.pass(3 * time.Hour) h.Tick() - if len(tg.sends) != 3 { + if len(tg.replaced) != 1 { t.Fatalf("reminded twice") } c.pass(9 * time.Hour) // the warning is now 13 h old h.Tick() settle(h, c) - if len(tg.sends) != 4 || tg.sends[3].Title != "Still open: plan 41 stalled" { - t.Fatalf("warning reminder: %d", len(tg.sends)) + if len(tg.sends) != 2 || len(tg.replaced) != 2 || tg.replaced[1].id != "2" || tg.replaced[1].m.Title != "Still open: plan 41 stalled" { + t.Fatalf("warning reminder: %d sends, %+v", len(tg.sends), tg.replaced) } } @@ -290,6 +310,8 @@ func TestClearedEditsTheFirstMessageAndReopenedWithinTenMinutesIsNotNew(t *testi h.Condition(EventRaised, k) c.pass(14 * time.Minute) h.Condition(EventCleared, Condition{Key: k.Key}) + c.pass(ClearSettle) // said once it stays cleared (issue 373) + h.Tick() if len(tg.sends) != 1 || len(tg.edits) != 1 || len(dt.edits) != 1 { t.Fatalf("telegram sends %d edits %d, desktop edits %d", len(tg.sends), len(tg.edits), len(dt.edits)) } @@ -299,7 +321,7 @@ func TestClearedEditsTheFirstMessageAndReopenedWithinTenMinutesIsNotNew(t *testi if len(h.Open()) != 0 { t.Fatalf("still open") } - c.pass(5 * time.Minute) + c.pass(3 * time.Minute) k.At = c.now() // a reopening keeps its first raising time; the event says when it happened h.Condition(EventRaised, k) if len(tg.sends) != 1 || !strings.Contains(tg.edits["1"].Title, "(again, 2nd time)") { @@ -351,8 +373,10 @@ func TestEscalationIsSaidOnce(t *testing.T) { h.Condition(EventChanged, k) h.Condition(EventChanged, k) settle(h, c) - if len(dt.sends) != 2 || len(tg.sends) != 1 || !strings.HasPrefix(tg.sends[0].Title, "Now urgent: ") { - t.Fatalf("desktop %d telegram %d", len(dt.sends), len(tg.sends)) + // The desktop's warning is replaced by the urgent message (issue 373); Telegram, which had none, is sent one. + if len(dt.sends) != 1 || len(dt.replaced) != 1 || dt.replaced[0].id != "g14=1" || + !strings.HasPrefix(dt.replaced[0].m.Title, "Now urgent: ") || len(tg.sends) != 1 || !strings.HasPrefix(tg.sends[0].Title, "Now urgent: ") { + t.Fatalf("desktop %d sends %d replaced, telegram %d", len(dt.sends), len(dt.replaced), len(tg.sends)) } // Escalated while the warning still waited its window: one message, the urgent one. k2 := cond("machine.ace.silent", Warning, "the home server is silent") @@ -360,9 +384,23 @@ func TestEscalationIsSaidOnce(t *testing.T) { k2.Severity = Urgent h.Condition(EventChanged, k2) settle(h, c) - if len(dt.sends) != 3 || !strings.HasPrefix(dt.sends[2].Title, "Now urgent: ") { + if len(dt.sends) != 2 || !strings.HasPrefix(dt.sends[1].Title, "Now urgent: ") || len(dt.replaced) != 1 { t.Fatalf("desktop %d: %q", len(dt.sends), dt.sends[len(dt.sends)-1].Title) } + // Escalated, then the hour of an urgent one passes since it was raised: no reminder until an hour after the + // escalation was said (issue 373: "Now urgent" and "Still open" 31 s apart). + c.pass(59 * time.Minute) + h.Tick() + settle(h, c) + if len(dt.replaced) != 1 || len(tg.replaced) != 0 { + t.Fatalf("reminded within the hour of the escalation: %+v %+v", dt.replaced, tg.replaced) + } + c.pass(2 * time.Minute) + h.Tick() + settle(h, c) + if len(tg.replaced) != 2 || len(tg.sends) != 2 { + t.Fatalf("not reminded an hour after the escalation, in place: telegram %d sends %+v", len(tg.sends), tg.replaced) + } } func TestAChannelThatCannotSendSaysSoAndIsTriedAgain(t *testing.T) { @@ -411,6 +449,12 @@ func TestARestartForgetsNothing(t *testing.T) { t.Fatalf("a restart sent it again") } again.Condition(EventCleared, Condition{Key: k.Key}) + third := &Holder{Away: tg, Store: st, Now: c.now, Logf: t.Logf} + if err := third.Load(); err != nil { + t.Fatal(err) + } + c.pass(ClearSettle) + third.Tick() // a clearing not said yet before a restart is said after it if len(tg.edits) != 1 { t.Fatalf("a restart lost the message to edit") } diff --git a/modules/messenger/cmd/messenger/onemessage_test.go b/modules/messenger/cmd/messenger/onemessage_test.go new file mode 100644 index 00000000..efd6645b --- /dev/null +++ b/modules/messenger/cmd/messenger/onemessage_test.go @@ -0,0 +1,198 @@ +package main + +// Issue 373: the operator no longer trusted the mesh's notifications — one problem shown twice, a unit that +// failed again at each apply said again each time, a question still offered after it ended. One message per +// problem at any time, updated in place. + +import ( + "strings" + "testing" + "time" +) + +func saidOn(chs ...*fakeChannel) int { + n := 0 + for _, ch := range chs { + n += len(ch.sends) + len(ch.edits) + len(ch.replaced) + } + return n +} + +// A unit that fails again seconds after each apply clears it: the message continues without a word — no +// "again, 22nd time", no "Resolved" — and once it stays cleared, its clearing is said once. +func TestAFlappingConditionIsSaidOnceAndItsClearingOnceWhenItStops(t *testing.T) { + h, tg, dt, c, _ := newHolder(t) + k := cond("machine.shanks.units", Warning, "2 failed services on shanks") + k.Raised = c.now() + h.Condition(EventRaised, k) + settle(h, c) + if len(dt.sends) != 1 || saidOn(tg) != 0 { + t.Fatalf("raised: desktop %d, telegram %d", len(dt.sends), saidOn(tg)) + } + for i := 0; i < 22; i++ { + c.pass(3 * time.Minute) + h.Tick() + cl := Condition{Key: k.Key, At: c.now()} + h.Condition(EventCleared, cl) + c.pass(15 * time.Second) + h.Flush() + k.At = c.now() + h.Condition(EventRaised, k) + h.Flush() + } + runFor(h, c, 20*time.Minute) + if got := saidOn(tg, dt); got != 1 { + t.Fatalf("a flapping condition was said %d times; want once: desktop %+v %+v %+v", got, dt.sends, dt.edits, dt.replaced) + } + // Once it has come back, a longer gap — past ClearSettle, inside the reopen window — is still a blip. + h.Condition(EventCleared, Condition{Key: k.Key, At: c.now()}) + runFor(h, c, 5*time.Minute) + k.At = c.now() + h.Condition(EventRaised, k) + runFor(h, c, time.Minute) + if got := saidOn(tg, dt); got != 1 { + t.Fatalf("a condition that flaps slower was said again: %d", got) + } + if open := h.Open(); len(open) != 1 || open[0].Count != 24 { + t.Fatalf("open: %+v", open) + } + // A genuinely new problem meanwhile is said. + n := cond("machine.ace.disk-full", Urgent, "the home server's disk is full") + n.Raised = c.now() + h.Condition(EventRaised, n) + if len(tg.sends) != 1 || len(dt.sends) != 2 { + t.Fatalf("a new problem was swallowed: telegram %d desktop %d", len(tg.sends), len(dt.sends)) + } + // The unit stays mended: its clearing is said once, in place of its message. + h.Condition(EventCleared, Condition{Key: k.Key, At: c.now()}) + runFor(h, c, 30*time.Minute) + if len(dt.edits) != 1 || !strings.HasPrefix(dt.edits["g14=1"].Title, "Resolved: ") || len(dt.sends) != 2 { + t.Fatalf("its clearing: edits %+v, sends %d", dt.edits, len(dt.sends)) + } +} + +// A clearing a few seconds long is never said, and the message continues; an urgent problem rang once. +func TestAnUrgentBlipRingsOnceAndItsBlipsSayNothing(t *testing.T) { + h, tg, dt, c, _ := newHolder(t) + k := cond("machine.ace.silent", Urgent, "the home server is silent") + k.Raised = c.now() + h.Condition(EventRaised, k) + for i := 0; i < 5; i++ { + c.pass(time.Minute) + h.Condition(EventCleared, Condition{Key: k.Key, At: c.now()}) + c.pass(20 * time.Second) + h.Tick() + k.At = c.now() + h.Condition(EventRaised, k) + } + runFor(h, c, 10*time.Minute) + if len(tg.sends) != 1 || len(dt.sends) != 1 || len(tg.edits)+len(dt.edits)+len(tg.replaced)+len(dt.replaced) != 0 { + t.Fatalf("telegram %d %d %d, desktop %d %d %d", len(tg.sends), len(tg.edits), len(tg.replaced), len(dt.sends), + len(dt.edits), len(dt.replaced)) + } +} + +// Cleared before it was ever said, and back within the reopen window: a problem the operator never heard of is +// said, not swallowed as the same message. +func TestAConditionClearedBeforeItWasSaidAndBackIsSaid(t *testing.T) { + h, _, dt, c, _ := newHolder(t) + k := cond("machine.shanks.units", Warning, "2 failed services on shanks") + k.Raised = c.now() + h.Condition(EventRaised, k) + c.pass(10 * time.Second) + h.Condition(EventCleared, Condition{Key: k.Key, At: c.now()}) + c.pass(time.Minute) + k.At = c.now() + h.Condition(EventRaised, k) + runFor(h, c, 2*time.Minute) + if len(dt.sends) != 1 || !strings.Contains(dt.sends[0].Title, "machine shanks units") { + t.Fatalf("desktop %+v", dt.sends) + } +} + +// Said first inside a digest, a problem's next message is one of its own, and the word after that replaces or +// edits that one: never a second message beside it. +func TestAProblemSaidInADigestGetsAMessageOfItsOwnThatLaterWordsReplace(t *testing.T) { + h, tg, _, c, _ := newHolder(t) + h.Desk = nil + a := cond("seat.s1.silent", Warning, "s1 is silent") + b := cond("seat.s2.silent", Warning, "s2 is silent") + a.Raised, b.Raised = c.now(), c.now() + h.Condition(EventRaised, a) + h.Condition(EventRaised, b) + settle(h, c) + if len(tg.sends) != 1 || !strings.HasPrefix(tg.sends[0].Title, "Mesh: 2 new problems") { + t.Fatalf("sends %+v", tg.sends) + } + b.Severity = Urgent + h.Condition(EventChanged, b) + settle(h, c) + if len(tg.sends) != 2 || !strings.HasPrefix(tg.sends[1].Title, "Now urgent: ") { + t.Fatalf("escalation: %+v", tg.sends) + } + h.Condition(EventCleared, Condition{Key: b.Key, At: c.now()}) + c.pass(ClearSettle) + h.Tick() + settle(h, c) + if len(tg.sends) != 2 || !strings.HasPrefix(tg.edits["2"].Title, "Resolved: seat s2") { + t.Fatalf("its clearing was not an edit of its own message: sends %d, edits %+v", len(tg.sends), tg.edits) + } +} + +// An ask's expiry is said with its day when it is not today: an ask lasting a week read as ending tonight. +func TestAnAsksExpiryIsSaidWithItsDay(t *testing.T) { + now := time.Date(2026, 10, 9, 21, 33, 0, 0, time.UTC) + for at, want := range map[time.Time]string{ + now.Add(time.Hour): "22:33", + now.Add(24 * time.Hour): "tomorrow 21:33", + now.Add(7 * 24 * time.Hour): "Fri 16 Oct 21:33", + } { + if got := by(at, now, time.UTC); got != want { + t.Errorf("%s: %q, want %q", at, got, want) + } + } + h, _, _, c, _ := newHolder(t) + h.Zone = func() *time.Location { return time.UTC } + c.t = now + rec := &AskRecord{Asker: ConditionOwner} + rec.Ask.Expires = now.Add(7 * 24 * time.Hour) + rec.Ask.OnExpiry = "nothing is done" + lines := strings.Join(h.askLines(rec), "\n") + if !strings.Contains(lines, "If nobody answers by Fri 16 Oct 21:33: nothing is done.") { + t.Fatalf("%s", lines) + } +} + +// A question on a problem's message, then its reminder: when the question ends, the one message the operator +// has loses its buttons and says so — none is left offering an answer nobody takes. +func TestAnEndedQuestionLeavesNoMessageOfferingItsAnswers(t *testing.T) { + h, tg, dt, c, store, _ := newRouter(t) + link(h, store, c, "42", c.now().Add(-2*time.Hour)) + k := cond("machine.novox.secret-given", Urgent, "a secret was given at the terminal") + k.Raised = c.now() + h.Condition(EventRaised, k) + settle(h, c) + a := ackAsk(c, "q-1") + a.About = k.Key + a.Expires = c.now().Add(3 * time.Hour) + submit(t, h, ConditionOwner, a) + settle(h, c) + for i := 0; i < 4*60; i++ { + c.pass(time.Minute) + stand(h, c) + h.Tick() + h.Flush() + } + if rec := store.asks[ConditionOwner+".q-1"]; rec.State == StateOpen { + t.Fatalf("the ask did not expire: %+v", rec.State) + } + for _, ch := range []*fakeChannel{tg, dt} { + if len(ch.sends) != 1 { + t.Fatalf("%s: %d messages for one problem", ch.name, len(ch.sends)) + } + last := ch.edits[map[string]string{"telegram": "1", "desktop": "g14=1"}[ch.name]] + if len(ch.replaced) == 0 || len(last.Actions) > 1 || !strings.Contains(last.Body, "No longer answerable") { + t.Fatalf("%s: replaced %d, the message now: %q %v", ch.name, len(ch.replaced), last.Text(), labelsOf(last)) + } + } +} diff --git a/modules/messenger/cmd/messenger/outbox.go b/modules/messenger/cmd/messenger/outbox.go index 1b264e4d..0ecb0a21 100644 --- a/modules/messenger/cmd/messenger/outbox.go +++ b/modules/messenger/cmd/messenger/outbox.go @@ -294,7 +294,9 @@ func (h *Holder) flushChannel(ch Channel, now time.Time, force bool) { // an ask whose approval was not offered folded into a digest, and its one answer lost with it). var alone, rest []entry for _, e := range entries { - if len(e.msg.Actions) > 1 || (len(e.msg.Actions) > 0 && e.r != nil && e.r.Ask != "") { + // A message said again about a record shown here goes alone too: it replaces that record's message, + // so a reminder is never a digest line beside the message it follows (issue 373). + if len(e.msg.Actions) > 1 || (len(e.msg.Actions) > 0 && e.r != nil && e.r.Ask != "") || h.replacing(ch, e) != "" { alone = append(alone, e) } else { rest = append(rest, e) @@ -329,12 +331,26 @@ type entry struct { msg Message } -// sendEntries sends entries as one message — itself when alone, a digest when several — and records it. +// replacing is the id of the message an entry replaces on a channel: the record's own message there, when the +// entry says it again (not its clearing) and the channel can replace; "" for a new message. +func (h *Holder) replacing(ch Channel, e entry) string { + if e.r == nil || e.it.What == "cleared" || !replaces(ch) { + return "" + } + h.mu.Lock() + defer h.mu.Unlock() + return e.r.Sent[ch.Name()] +} + +// sendEntries sends entries as one message — itself when alone, a digest when several — and records it. A +// record said again where its message is shown replaces that message (issue 373): one message per problem. func (h *Holder) sendEntries(ch Channel, entries []entry, now time.Time) bool { name := ch.Name() var m Message + prior := "" if len(entries) == 1 { m = entries[0].msg + prior = h.replacing(ch, entries[0]) } else { items := make([]item, len(entries)) msgs := make([]Message, len(entries)) @@ -343,7 +359,13 @@ func (h *Holder) sendEntries(ch Channel, entries []entry, now time.Time) bool { } m = digest(items, msgs) } - id, err := ch.Send(m) + var id string + var err error + if prior != "" { + id, err = prior, ch.(replacer).Replace(prior, m) + } else { + id, err = ch.Send(m) + } h.noteChannel(name, err) if err != nil { return false @@ -367,22 +389,25 @@ func (h *Holder) sendEntries(ch Channel, entries []entry, now time.Time) bool { if r.Sent == nil { r.Sent = map[string]string{} } - if _, has := r.Sent[name]; !has { - own := "" - if len(entries) == 1 { - own = id - } - r.Sent[name] = own + if len(entries) == 1 { + // Its own message: the one later words replace or edit — also after it was said in a digest. + r.Sent[name] = id + } else if _, has := r.Sent[name]; !has { + r.Sent[name] = "" } if r.FirstSent.IsZero() { r.FirstSent = now } + r.LastSaid = now } } h.mu.Unlock() key, what := "(digest)", fmt.Sprintf("digest of %d", len(entries)) if len(entries) == 1 { key, what = entries[0].it.Key, entries[0].it.What + if prior != "" { + what += ", in place of its earlier message" + } } h.record(Sent{At: now, Channel: name, Key: key, What: what, Outcome: "sent"}) for _, e := range entries { diff --git a/modules/messenger/cmd/messenger/seatchannel.go b/modules/messenger/cmd/messenger/seatchannel.go index 36446ec9..f7c8fff2 100644 --- a/modules/messenger/cmd/messenger/seatchannel.go +++ b/modules/messenger/cmd/messenger/seatchannel.go @@ -243,6 +243,15 @@ func (c *SeatChannel) Send(m Message) (string, error) { return handle, c.put(handle, m, false) } +// Replace says a message again under the handle of one shown before: the channel takes the earlier one away +// and shows this one as a new message is shown — ringing as its kind rings (issue 373). An edit is quiet. +func (c *SeatChannel) Replace(handle string, m Message) error { + if handle == "" { + return errors.New("no message on record to replace") + } + return c.put(handle, m, false) +} + // Edit replaces the message a handle names. func (c *SeatChannel) Edit(handle string, m Message) error { if handle == "" { @@ -311,6 +320,13 @@ func (c *KindChannel) Send(m Message) (string, error) { handle := newHandle() return handle, s.putOn(c.Kind, handle, m, false) } +func (c *KindChannel) Replace(handle string, m Message) error { + if handle == "" { + return errors.New("no message on record to replace") + } + s := &SeatChannel{Bench: c.Bench, Publish: c.Publish} + return s.putOn(c.Kind, handle, m, false) +} func (c *KindChannel) Edit(handle string, m Message) error { s := &SeatChannel{Bench: c.Bench, Publish: c.Publish} return s.putOn(c.Kind, handle, m, true) diff --git a/modules/messenger/cmd/messenger/sync.go b/modules/messenger/cmd/messenger/sync.go index 1633ae22..4589ee15 100644 --- a/modules/messenger/cmd/messenger/sync.go +++ b/modules/messenger/cmd/messenger/sync.go @@ -68,6 +68,7 @@ func (h *Holder) Sync(open []Condition, asked time.Time) SyncResult { if !old.Cleared.IsZero() { // Ended here, open there: back to open, quietly — the reading is not an event. old.Cleared = time.Time{} + old.ClearUnsaid, old.ClearSilent = false, false old.Count++ } old.Summary, old.Subject, old.Kind, old.SilencedTill = rec.Summary, rec.Subject, rec.Kind, rec.SilencedTill diff --git a/modules/messenger/cmd/messenger/words.go b/modules/messenger/cmd/messenger/words.go index 226749f4..666a5b0e 100644 --- a/modules/messenger/cmd/messenger/words.go +++ b/modules/messenger/cmd/messenger/words.go @@ -198,6 +198,23 @@ func when(t, now time.Time, loc *time.Location) string { return lt.Format("2 Jan 15:04") } +// by is a moment ahead as the operator reads it, in their zone: "23:33" today, "tomorrow 23:33", "Fri 16 Oct +// 23:33" later. An ask's expiry was said as a clock time alone, so an ask lasting a week read as one ending +// tonight (issue 373). +func by(t, now time.Time, loc *time.Location) string { + lt, ln := t.In(loc), now.In(loc) + y1, m1, d1 := lt.Date() + y2, m2, d2 := ln.Date() + if y1 == y2 && m1 == m2 && d1 == d2 { + return lt.Format("15:04") + } + ty, tm, td := ln.AddDate(0, 0, 1).Date() + if y1 == ty && m1 == tm && d1 == td { + return "tomorrow " + lt.Format("15:04") + } + return lt.Format("Mon 2 Jan 15:04") +} + func capital(s string) string { if s == "" { return s diff --git a/modules/messenger/cmd/messenger/words_test.go b/modules/messenger/cmd/messenger/words_test.go index 32d2e474..99cd60e6 100644 --- a/modules/messenger/cmd/messenger/words_test.go +++ b/modules/messenger/cmd/messenger/words_test.go @@ -225,6 +225,8 @@ func TestRealNotificationsReadInOneGlanceAndAreAnsweredFromTheNotification(t *te t.Fatal(err) } h.Condition(EventCleared, cleared) + c.pass(ClearSettle) + h.Tick() end := dt.edits["g14=1"] if end.Title != e.cleared || end.Body != "" || len(end.Actions) != 0 { t.Errorf("clearance %q / %q / %v, want one line %q", end.Title, end.Body, end.Actions, e.cleared) diff --git a/modules/telegram/README.md b/modules/telegram/README.md index 8bd0a6ff..130ea725 100644 --- a/modules/telegram/README.md +++ b/modules/telegram/README.md @@ -8,6 +8,9 @@ as the operator. - **Shows what the router sends** (its kind's worker on the `channel` queue): a message, a question with buttons — each button carries only the router's one-time ticket — or an edit of a message shown before. It sends to the account the router names as linked, or, before one is, to the chat a `/start` came from. + A message sent under a handle already shown (a reminder, an escalation) **replaces** it (issue 373): the + earlier message is deleted and the new one sent, ringing as its kind rings, since an edit here notifies + nobody; one the service will not delete loses its buttons and says a newer message follows. - **Says what the operator chose** on `intake` under its own kind: a tapped button (`choice`), with the sender as Telegram authenticated it; `/start` (`link`); a message it could not deliver (`failed`); and whether it can send (`standing`). Only a private chat with the account itself counts. diff --git a/modules/telegram/cmd/telegram/channel.go b/modules/telegram/cmd/telegram/channel.go index 381cbb40..33368e8c 100644 --- a/modules/telegram/cmd/telegram/channel.go +++ b/modules/telegram/cmd/telegram/channel.go @@ -10,7 +10,8 @@ package main // handle). Up to 4096 characters arrive whole; longer is cut and the cut said (D1). A warning or a // clearing arrives without sound, an urgent message or a question rings (D4). A rate limit is waited out // as told (D5); a refusal is a permanent failure, said to the router, never retried; an edit to the same -// text is a success (D6). A message that cannot be delivered after three tries is said as failed. +// text is a success (D6). A message that cannot be delivered after three tries is said as failed. A +// `send` or `show` under a handle already shown replaces that message: deleted, and the new one sent. // - **What arrives** is long-polled: outbound only. A tapped button is said as a `choice` with the sender // the service authenticated, and acknowledged on the phone with the router's word on it — what was // recorded, or why it was not — which comes as a reply to the tap; without one in TapWait, with words that @@ -232,11 +233,19 @@ func (c *Channel) Take(subject string, body json.RawMessage) error { words, buttons := text(m), c.buttons(m) silent := m.Silent || (!m.Urgent && len(buttons) == 0) var place *Placed - if verb == asks.Edit { + if verb == asks.Edit || !m.Secret { if place, err = c.Store.Placed(m.Handle); err != nil { return err // the state is away: offered again } } + if verb != asks.Edit && place != nil { + // **A message said again under a handle already shown replaces it** (issue 373): a reminder or an + // escalation is one message per problem, not one more beside it. An edit here notifies nobody, so the + // earlier message is deleted and this one sent, ringing as its kind rings; one the service will not + // delete loses its buttons and says where the newer one is. + c.replaced(*place) + place = nil + } for try := 1; ; try++ { var id int64 switch { @@ -274,6 +283,19 @@ func (c *Channel) Take(subject string, body json.RawMessage) error { } } +// replaced takes an earlier message out of the chat: deleted, or where the service refuses that (a message +// older than two days), its buttons taken away and the newer message named. +func (c *Channel) replaced(p Placed) { + err := c.Bot.Delete(p.Chat, p.ID) + if err == nil { + return + } + c.Logf("[telegram] an earlier message could not be deleted (%v); its buttons are taken away instead", err) + if err := c.Bot.Edit(p.Chat, p.ID, "Replaced by a newer message below.", nil); err != nil && !gone(err) { + c.Logf("[telegram] an earlier message could not be marked replaced either: %v", err) + } +} + func (c *Channel) newMessage(handle string, chat int64, words string, buttons [][2]string, silent bool, id *int64) error { got, err := c.Bot.Send(chat, words, buttons, silent) if err != nil { diff --git a/modules/telegram/cmd/telegram/channel_test.go b/modules/telegram/cmd/telegram/channel_test.go index 5b518471..1897373d 100644 --- a/modules/telegram/cmd/telegram/channel_test.go +++ b/modules/telegram/cmd/telegram/channel_test.go @@ -580,3 +580,48 @@ func TestAToastIsCutAtTelegramsBound(t *testing.T) { t.Errorf("toast %q", got) } } + +// Issue 373: a reminder or an escalation is sent under the handle of the message it follows, and replaces it: +// the earlier one leaves the chat and the new one rings as its kind rings. One the service will not delete +// loses its buttons. A new handle is a new message, and nothing is deleted. +func TestAMessageSaidAgainUnderItsHandleReplacesTheEarlierOne(t *testing.T) { + c, f, _, st := newChannel(t, goodToken) + subject, body := work(asks.Show, asks.Message{Handle: "m1", Title: "Urgent: ace silent", Urgent: true, To: "42", + Buttons: []asks.Button{{Label: "Silence for a week", Ticket: "0123456789abcdef0123456789abcdef"}}}) + if err := c.Take(subject, body); err != nil { + t.Fatal(err) + } + first := st.placed["m1"].ID + subject, body = work(asks.Send, asks.Message{Handle: "m2", Title: "another problem", To: "42"}) + _ = c.Take(subject, body) + if len(f.of("deleteMessage")) != 0 { + t.Fatal("a new handle deleted a message") + } + subject, body = work(asks.Show, asks.Message{Handle: "m1", Title: "Still open: ace silent", Urgent: true, To: "42", + Buttons: []asks.Button{{Label: "Silence for a week", Ticket: "fedcba9876543210fedcba9876543210"}}}) + if err := c.Take(subject, body); err != nil { + t.Fatal(err) + } + del := f.of("deleteMessage") + if len(del) != 1 || del[0].Body["message_id"] != float64(first) { + t.Fatalf("the earlier message was not deleted: %+v", del) + } + sent := f.of("sendMessage") + if len(sent) != 3 || sent[2].Body["disable_notification"] != false || st.placed["m1"].ID == first { + t.Fatalf("the reminder was not sent ringing in its place: %d sends, placed %d", len(sent), st.placed["m1"].ID) + } + // The service refuses the delete: the earlier message loses its buttons instead. + f.answer["deleteMessage"] = func(map[string]any) (int, string) { + return 400, `{"ok":false,"error_code":400,"description":"Bad Request: message can't be deleted"}` + } + second := st.placed["m1"].ID + subject, body = work(asks.Send, asks.Message{Handle: "m1", Title: "Now urgent: ace silent", Urgent: true, To: "42"}) + _ = c.Take(subject, body) + ed := f.of("editMessageText") + if len(ed) != 1 || ed[0].Body["message_id"] != float64(second) || !strings.Contains(ed[0].Body["text"].(string), "Replaced") { + t.Fatalf("an undeletable earlier message kept its buttons: %+v", ed) + } + if kb, _ := json.Marshal(ed[0].Body["reply_markup"]); string(kb) != `{"inline_keyboard":[]}` { + t.Errorf("its buttons stayed: %s", kb) + } +} From f8515219b1f1f7ea03267ed379bf305f07e48a7e Mon Sep 17 00:00:00 2001 From: jochen Date: Sat, 10 Oct 2026 14:14:05 +0200 Subject: [PATCH 2/3] Review: a blip swallows no escalation or waiting reminder; replace safely (issue 373) - A comeback before the clearing was said rings when it is urgent now, and says the reminder or escalation that was waiting when it cleared. - Comebacks never said are counted apart, so "again, Nth time" counts only what the operator was told; an urgent comeback after a said clearing rings again in place of its message. - telegram sends the new message before deleting the earlier one, so a failed send leaves the operator a message. - desk-channel keeps a machine's notification on record when its replace fails, and says a message shown nowhere as failed. - A store that cannot be read sends a new message instead of holding it. - Tests for each, and for a reminder in a burst and a clearing the channel could not take. --- modules/desk-channel/README.md | 3 +- modules/desk-channel/cmd/desk-channel/desk.go | 17 +++- .../cmd/desk-channel/desk_test.go | 25 +++++ modules/messenger/README.md | 4 +- modules/messenger/cmd/messenger/holder.go | 50 +++++++--- .../messenger/cmd/messenger/holder_test.go | 6 +- .../cmd/messenger/onemessage_test.go | 95 ++++++++++++++++++- modules/messenger/cmd/messenger/outbox.go | 14 +++ modules/messenger/cmd/messenger/sync.go | 2 +- modules/telegram/README.md | 5 +- modules/telegram/cmd/telegram/channel.go | 28 +++--- modules/telegram/cmd/telegram/channel_test.go | 15 +++ 12 files changed, 229 insertions(+), 35 deletions(-) diff --git a/modules/desk-channel/README.md b/modules/desk-channel/README.md index 925e1d2a..e6050c86 100644 --- a/modules/desk-channel/README.md +++ b/modules/desk-channel/README.md @@ -14,7 +14,8 @@ each machine the operator sits at (the `node-notifier` seat), and says which but - **One notification per message** (issue 373): an `edit`, and a `send` or `show` under a handle already shown (a reminder, an escalation), replace that message's notification on each machine by its id (the notifier's `replace_id`), so a problem is one notification updated in place. An edit goes only where it was shown; a - message said again is shown anew on a machine it was not. + message said again is shown anew on a machine it was not. A replace that fails on a machine keeps that + machine's notification on record, so a later edit still reaches it. ## What the operator gives diff --git a/modules/desk-channel/cmd/desk-channel/desk.go b/modules/desk-channel/cmd/desk-channel/desk.go index 68ef6ba4..3e846a93 100644 --- a/modules/desk-channel/cmd/desk-channel/desk.go +++ b/modules/desk-channel/cmd/desk-channel/desk.go @@ -147,14 +147,22 @@ func (d *Desk) Take(subject string, body json.RawMessage) error { // it was shown; a message said again is shown anew where it was not. edit := parts[4] == asks.Edit var before *Shown - if edit || !m.Secret { + switch { + case edit: var err error if before, err = d.Store.Get(m.Handle); err != nil { return err } + case !m.Secret: + var err error + if before, err = d.Store.Get(m.Handle); err != nil { + d.Logf("[desk-channel] what is shown under this handle could not be read (%v): shown as a new message", err) + before = nil + } } s := Shown{Message: m, On: map[string]int{}, Sent: d.Now()} var failed []string + shown := 0 for _, machine := range machines { replace := 0 if before != nil { @@ -166,11 +174,16 @@ func (d *Desk) Take(subject string, body json.RawMessage) error { id, err := d.show(machine, m, replace) if err != nil { failed = append(failed, machine+": "+err.Error()) + if replace != 0 { + // Its notification is still there: kept, so a later edit or clearing still reaches it. + s.On[machine] = replace + } continue } s.On[machine] = id + shown++ } - if len(s.On) == 0 { + if shown == 0 { why := "no machine showed it" if len(failed) > 0 { why += " — " + strings.Join(failed, "; ") diff --git a/modules/desk-channel/cmd/desk-channel/desk_test.go b/modules/desk-channel/cmd/desk-channel/desk_test.go index 88037440..d6245312 100644 --- a/modules/desk-channel/cmd/desk-channel/desk_test.go +++ b/modules/desk-channel/cmd/desk-channel/desk_test.go @@ -298,3 +298,28 @@ func TestAMessageSaidAgainUnderItsHandleReplacesItsNotification(t *testing.T) { t.Fatalf("what is shown was not kept: %+v", s) } } + +// The review of PR 176: a replace that fails on a machine keeps that machine's notification on record, so a +// later edit or clearing still reaches it; failing everywhere, it is said to the router as failed. +func TestAFailedReplaceKeepsTheNotificationItWasToReplace(t *testing.T) { + d, shown, said, store := newDesk(t, "laptop", "desktop") + take(t, d, asks.Send, asks.Message{Handle: "m1", Title: "2 failed services on shanks"}) + first := store["m1"].On + notify := d.Notify + d.Notify = func(machine string, args map[string]any) (json.RawMessage, error) { + if machine == "desktop" { + return nil, errors.New("no session answers") + } + return notify(machine, args) + } + take(t, d, asks.Send, asks.Message{Handle: "m1", Title: "Still open: 2 failed services on shanks"}) + if got := store["m1"].On["desktop"]; got != first["desktop"] { + t.Fatalf("the desktop's notification %d was forgotten: %v", first["desktop"], store["m1"].On) + } + d.Notify = func(string, map[string]any) (json.RawMessage, error) { return nil, errors.New("away") } + take(t, d, asks.Send, asks.Message{Handle: "m1", Title: "Now urgent: 2 failed services on shanks"}) + if len(said[asks.IntakeSubject(asks.FailedWhat, Kind)]) != 1 { + t.Fatalf("shown nowhere, and not said as failed") + } + _ = shown +} diff --git a/modules/messenger/README.md b/modules/messenger/README.md index 380c7402..3b5c4eb0 100644 --- a/modules/messenger/README.md +++ b/modules/messenger/README.md @@ -117,8 +117,8 @@ warning kept quiet is also said once after a day. | still open after 1 h (urgent) or 12 h (warning) | once more, in place of its message — never sooner than that after it was last said | | `condition-changed` from warning to urgent | once more, in place of its message, to both channels | | `condition-cleared` | once it stays cleared 2 min (10 min once it came back): its message edited to say so; said inside a digest, a line in the next one | -| cleared and raised again before its clearing was said | nothing: to the operator it never ended — a unit failing again after each apply is one message, not one per apply | -| cleared, said so, and raised again within 10 min | the same message, edited back to open — not a new one | +| cleared and raised again before its clearing was said | nothing: to the operator it never ended — a unit failing again after each apply is one message, not one per apply; back as urgent, or with a reminder waiting when it cleared, that is said | +| cleared, said so, and raised again within 10 min | the same message, edited back to open — not a new one (urgent: said again in its place, so it rings) | | silenced | nothing, its clearing included | **One message per problem** (issue 373). A record keeps the id of its message on each channel; a reminder or diff --git a/modules/messenger/cmd/messenger/holder.go b/modules/messenger/cmd/messenger/holder.go index dfff2c47..6679b0ee 100644 --- a/modules/messenger/cmd/messenger/holder.go +++ b/modules/messenger/cmd/messenger/holder.go @@ -63,7 +63,7 @@ const ( ReopenWindow = 10 * time.Minute // ClearSettle: a clearing is said once the condition stayed cleared this long. One raised again sooner // (a unit failing again after each apply, issue 373) continues its message without a word, and its - // clearing is never said. Once it has come back, its next clearing waits the whole ReopenWindow. + // clearing is never said. Once it has come back, its next clearing waits the reopen window less a minute. ClearSettle = 2 * time.Minute CapPerHour = 20 KeptSends = 200 @@ -186,14 +186,19 @@ type Record struct { // ClearUnsaid: cleared, and the clearing not said yet — it is said once it stays cleared ClearSettle; // raised again before, the message continues as if it never cleared. ClearSilent: said only where an edit // notifies nobody (it ended while this holder was away). - ClearUnsaid bool `json:"clear_unsaid,omitempty"` - ClearSilent bool `json:"clear_silent,omitempty"` - Reminded bool `json:"reminded,omitempty"` - Pending string `json:"pending,omitempty"` // what could not be said yet: raised, reminder, … - Folded bool `json:"folded,omitempty"` // held by the cap - Cleared time.Time `json:"cleared,omitempty"` - Count int `json:"count"` - Refused string `json:"refused,omitempty"` + ClearUnsaid bool `json:"clear_unsaid,omitempty"` + ClearSilent bool `json:"clear_silent,omitempty"` + // ClearHeld is what was waiting to be said of it when it cleared (a reminder, an escalation): said after + // all if it comes back before its clearing was said. Blips counts those comebacks, never said, so a + // condition that flaps is known as one and its message's "again, Nth time" counts only what was said. + ClearHeld string `json:"clear_held,omitempty"` + Blips int `json:"blips,omitempty"` + Reminded bool `json:"reminded,omitempty"` + Pending string `json:"pending,omitempty"` // what could not be said yet: raised, reminder, … + Folded bool `json:"folded,omitempty"` // held by the cap + Cleared time.Time `json:"cleared,omitempty"` + Count int `json:"count"` + Refused string `json:"refused,omitempty"` // History: known from the state or from an old event, and never said — not news. History bool `json:"history,omitempty"` // Seen is when this holder last took word of it; the open set read after it is authoritative. @@ -481,21 +486,36 @@ func (h *Holder) raised(rec Record, quiet bool) { // Cleared and raised again within ten minutes: the same message, back to open (to-be 45 §2). h.mu.Lock() blip := old.ClearUnsaid + held := old.ClearHeld + escalated := old.Severity == Warning && rec.Severity == Urgent gone := now.Sub(old.Cleared) old.Cleared = time.Time{} - old.ClearUnsaid, old.ClearSilent = false, false - old.Count++ + old.ClearUnsaid, old.ClearSilent, old.ClearHeld = false, false, "" + if blip { + old.Blips++ + } else { + old.Count++ + } old.Summary, old.Severity, old.SilencedTill = rec.Summary, rec.Severity, rec.SilencedTill old.takeWords(rec) old.Seen = now h.mu.Unlock() switch { case quiet || old.silenced(now): + case blip && escalated: + // Back before its clearing was said, and urgent now: said as an escalation, which rings. + h.deliver(old, "escalated") + case blip && held != "": + // Back before its clearing was said: what was waiting to be said of it when it cleared is said now. + h.deliver(old, held) case blip: // Its clearing was never said (issue 373): to the operator it never ended, so nothing is said now. h.Logf("[messenger] %s back %s after it cleared, which was not said yet: the same message continues, nothing said", old.Key, roughly(gone)) h.record(Sent{At: now, Channel: "-", Key: old.Key, What: "reopened", Outcome: "quiet: back before its clearing was said"}) + case old.told() && old.Severity == Urgent: + // Its end was said, and it is back: urgent, it rings again, in place of its message. + h.deliver(old, "reopened") case old.told(): h.edit(old, "reopened", false) case !needsNothing(old) && !h.queued(old.Key): @@ -576,7 +596,11 @@ func (h *Holder) cleared(key string, quiet bool) { h.Logf("[messenger] %s cleared and was not open here: nothing to say", key) return } + held := h.queuedWhat(key) h.mu.Lock() + if held == "" { + held = old.Pending + } old.Cleared = now old.Pending = "" old.Folded = false @@ -595,7 +619,7 @@ func (h *Holder) cleared(key string, quiet bool) { // Said once it stays cleared (ClearSettle; a condition that came back, ReopenWindow): a blip of a few // seconds is not said at all (issue 373). h.mu.Lock() - old.ClearUnsaid, old.ClearSilent = true, quiet + old.ClearUnsaid, old.ClearSilent, old.ClearHeld = true, quiet, held h.mu.Unlock() } h.persist(old) @@ -604,7 +628,7 @@ func (h *Holder) cleared(key string, quiet bool) { // clearSettle is how long a record stays cleared before its clearing is said: one that came back before // waits the whole reopen window, so a condition that flaps is said cleared once, when it stopped flapping. func clearSettle(r *Record) time.Duration { - if r.Count > 1 { + if r.Count > 1 || r.Blips > 0 { return ReopenWindow - time.Minute } return ClearSettle diff --git a/modules/messenger/cmd/messenger/holder_test.go b/modules/messenger/cmd/messenger/holder_test.go index 737f4aed..68092431 100644 --- a/modules/messenger/cmd/messenger/holder_test.go +++ b/modules/messenger/cmd/messenger/holder_test.go @@ -324,8 +324,10 @@ func TestClearedEditsTheFirstMessageAndReopenedWithinTenMinutesIsNotNew(t *testi c.pass(3 * time.Minute) k.At = c.now() // a reopening keeps its first raising time; the event says when it happened h.Condition(EventRaised, k) - if len(tg.sends) != 1 || !strings.Contains(tg.edits["1"].Title, "(again, 2nd time)") { - t.Fatalf("reopened as new: sends %d, edit %q", len(tg.sends), tg.edits["1"].Title) + // Urgent, and its end was said: it rings again, in place of its message (issue 373), never as a new one. + if len(tg.sends) != 1 || len(tg.replaced) != 1 || tg.replaced[0].id != "1" || + !strings.Contains(tg.replaced[0].m.Title, "(again, 2nd time)") { + t.Fatalf("reopened as new: sends %d, replaced %+v", len(tg.sends), tg.replaced) } h.Condition(EventCleared, Condition{Key: k.Key}) c.pass(11 * time.Minute) diff --git a/modules/messenger/cmd/messenger/onemessage_test.go b/modules/messenger/cmd/messenger/onemessage_test.go index efd6645b..ae769b28 100644 --- a/modules/messenger/cmd/messenger/onemessage_test.go +++ b/modules/messenger/cmd/messenger/onemessage_test.go @@ -53,7 +53,8 @@ func TestAFlappingConditionIsSaidOnceAndItsClearingOnceWhenItStops(t *testing.T) if got := saidOn(tg, dt); got != 1 { t.Fatalf("a condition that flaps slower was said again: %d", got) } - if open := h.Open(); len(open) != 1 || open[0].Count != 24 { + // Its comebacks were never said: the count the operator reads ("again, Nth time") does not grow with them. + if open := h.Open(); len(open) != 1 || open[0].Count != 1 { t.Fatalf("open: %+v", open) } // A genuinely new problem meanwhile is said. @@ -196,3 +197,95 @@ func TestAnEndedQuestionLeavesNoMessageOfferingItsAnswers(t *testing.T) { } } } + +// The review of PR 176: a comeback before the clearing was said must not swallow what changed meanwhile — a +// warning back as urgent rings, and a reminder waiting to go out when it cleared still goes out. +func TestABlipSwallowsNeitherAnEscalationNorAWaitingReminder(t *testing.T) { + h, tg, dt, c, _ := newHolder(t) + k := cond("machine.shanks.units", Warning, "2 failed services on shanks") + k.Raised = c.now() + h.Condition(EventRaised, k) + settle(h, c) + if len(dt.sends) != 1 || len(tg.sends) != 0 { + t.Fatalf("raised: desktop %d telegram %d", len(dt.sends), len(tg.sends)) + } + h.Condition(EventCleared, Condition{Key: k.Key, At: c.now()}) + c.pass(20 * time.Second) + k.Severity, k.At = Urgent, c.now() + h.Condition(EventRaised, k) + settle(h, c) + if len(tg.sends) != 1 || !strings.HasPrefix(tg.sends[0].Title, "Now urgent: ") { + t.Fatalf("back as urgent, and Telegram was not rung: %+v", tg.sends) + } + + // A warning's reminder held by the desk's gentle rhythm when it cleared: said when it comes back. + w := cond("plan.41.stalled", Warning, "plan 41 waits") + w.Raised = c.now() + h.Condition(EventRaised, w) + runFor(h, c, DesktopWarningEvery+time.Minute) + before := len(dt.sends) + len(dt.replaced) + c.pass(RemindWarning) + h.Tick() // the reminder is due, and the desk holds it: a warning went out there less than 15 min ago + h.Condition(EventRaised, cond("seat.s9.silent", Warning, "s9 is silent")) + h.Flush() + h.Condition(EventCleared, Condition{Key: w.Key, At: c.now()}) + c.pass(20 * time.Second) + w.At = c.now() + h.Condition(EventRaised, w) + runFor(h, c, DesktopWarningEvery+time.Minute) + found := false + for _, r := range dt.replaced { + found = found || strings.HasPrefix(r.m.Title, "Still open: plan 41") + } + for _, m := range dt.sends { + found = found || strings.Contains(m.Body, "plan 41 stalled") || strings.HasPrefix(m.Title, "Still open: plan 41") + } + if !found || len(dt.sends)+len(dt.replaced) == before { + t.Fatalf("the reminder waiting when it blipped was lost: sends %+v replaced %+v", dt.sends, dt.replaced) + } +} + +// The review of PR 176: a reminder for one problem and a new problem in the same burst — the reminder goes +// alone in place of its message, never as a digest line beside it. +func TestAReminderInABurstReplacesItsMessageAndIsNoDigestLine(t *testing.T) { + h, tg, _, c, _ := newHolder(t) + h.Desk = nil + a := cond("plan.41.stalled", Warning, "plan 41 waits") + a.Raised = c.now() + h.Condition(EventRaised, a) + settle(h, c) + c.pass(RemindWarning) + h.Tick() + b := cond("seat.s9.silent", Warning, "s9 is silent") + b.Raised = c.now() + h.Condition(EventRaised, b) + settle(h, c) + for _, m := range tg.sends { + if strings.HasPrefix(m.Title, "Mesh: ") { + t.Fatalf("a reminder went into a digest: %q", m.Text()) + } + } + if len(tg.replaced) != 1 || tg.replaced[0].id != "1" || len(tg.sends) != 2 { + t.Fatalf("sends %+v, replaced %+v", tg.sends, tg.replaced) + } +} + +// The review of PR 176: a clearing the channel could not take is kept until it is said, past the reopen window. +func TestAClearingTheChannelCouldNotTakeIsSaidLater(t *testing.T) { + h, tg, _, c, _ := newHolder(t) + h.Desk = nil + k := cond("machine.ace.silent", Urgent, "the home server is silent") + k.Raised = c.now() + h.Condition(EventRaised, k) + tg.fail = errorf("telegram is away") + h.Condition(EventCleared, Condition{Key: k.Key, At: c.now()}) + runFor(h, c, ReopenWindow+2*time.Minute) + tg.fail = nil + runFor(h, c, 2*time.Minute) + for _, m := range tg.sends { + if strings.HasPrefix(m.Title, "Resolved: ") { + return + } + } + t.Fatalf("the clearing was lost: %+v", tg.sends) +} diff --git a/modules/messenger/cmd/messenger/outbox.go b/modules/messenger/cmd/messenger/outbox.go index 0ecb0a21..c23aa9bf 100644 --- a/modules/messenger/cmd/messenger/outbox.go +++ b/modules/messenger/cmd/messenger/outbox.go @@ -104,6 +104,20 @@ func (h *Holder) unqueue(key string) int { return n } +// queuedWhat is what is held to be said of a record, not its clearing: "" when nothing is. +func (h *Holder) queuedWhat(key string) string { + h.mu.Lock() + defer h.mu.Unlock() + for _, list := range h.outbox { + for _, it := range list { + if it.Msg == nil && it.Key == key && it.What != "cleared" { + return it.What + } + } + } + return "" +} + func (h *Holder) queued(key string) bool { h.mu.Lock() defer h.mu.Unlock() diff --git a/modules/messenger/cmd/messenger/sync.go b/modules/messenger/cmd/messenger/sync.go index 4589ee15..d7983ee0 100644 --- a/modules/messenger/cmd/messenger/sync.go +++ b/modules/messenger/cmd/messenger/sync.go @@ -68,7 +68,7 @@ func (h *Holder) Sync(open []Condition, asked time.Time) SyncResult { if !old.Cleared.IsZero() { // Ended here, open there: back to open, quietly — the reading is not an event. old.Cleared = time.Time{} - old.ClearUnsaid, old.ClearSilent = false, false + old.ClearUnsaid, old.ClearSilent, old.ClearHeld = false, false, "" old.Count++ } old.Summary, old.Subject, old.Kind, old.SilencedTill = rec.Summary, rec.Subject, rec.Kind, rec.SilencedTill diff --git a/modules/telegram/README.md b/modules/telegram/README.md index 130ea725..46598277 100644 --- a/modules/telegram/README.md +++ b/modules/telegram/README.md @@ -9,8 +9,9 @@ as the operator. buttons — each button carries only the router's one-time ticket — or an edit of a message shown before. It sends to the account the router names as linked, or, before one is, to the chat a `/start` came from. A message sent under a handle already shown (a reminder, an escalation) **replaces** it (issue 373): the - earlier message is deleted and the new one sent, ringing as its kind rings, since an edit here notifies - nobody; one the service will not delete loses its buttons and says a newer message follows. + new message is sent, ringing as its kind rings (an edit here notifies nobody), and then the earlier one is + deleted; one the service will not delete loses its buttons and says a newer message follows. A send that + fails leaves the earlier message. - **Says what the operator chose** on `intake` under its own kind: a tapped button (`choice`), with the sender as Telegram authenticated it; `/start` (`link`); a message it could not deliver (`failed`); and whether it can send (`standing`). Only a private chat with the account itself counts. diff --git a/modules/telegram/cmd/telegram/channel.go b/modules/telegram/cmd/telegram/channel.go index 33368e8c..30680da8 100644 --- a/modules/telegram/cmd/telegram/channel.go +++ b/modules/telegram/cmd/telegram/channel.go @@ -11,7 +11,8 @@ package main // clearing arrives without sound, an urgent message or a question rings (D4). A rate limit is waited out // as told (D5); a refusal is a permanent failure, said to the router, never retried; an edit to the same // text is a success (D6). A message that cannot be delivered after three tries is said as failed. A -// `send` or `show` under a handle already shown replaces that message: deleted, and the new one sent. +// `send` or `show` under a handle already shown replaces that message: the new one sent, then the earlier +// one deleted. // - **What arrives** is long-polled: outbound only. A tapped button is said as a `choice` with the sender // the service authenticated, and acknowledged on the phone with the router's word on it — what was // recorded, or why it was not — which comes as a reply to the tap; without one in TapWait, with words that @@ -232,19 +233,21 @@ func (c *Channel) Take(subject string, body json.RawMessage) error { } words, buttons := text(m), c.buttons(m) silent := m.Silent || (!m.Urgent && len(buttons) == 0) - var place *Placed - if verb == asks.Edit || !m.Secret { + // **A message said again under a handle already shown replaces it** (issue 373): a reminder or an + // escalation is one message per problem, not one more beside it. An edit here notifies nobody, so this one + // is sent, ringing as its kind rings, and only then is the earlier one deleted — one the service will not + // delete loses its buttons and says a newer message follows. A send that fails leaves the earlier one. + var place, earlier *Placed + switch { + case verb == asks.Edit: if place, err = c.Store.Placed(m.Handle); err != nil { return err // the state is away: offered again } - } - if verb != asks.Edit && place != nil { - // **A message said again under a handle already shown replaces it** (issue 373): a reminder or an - // escalation is one message per problem, not one more beside it. An edit here notifies nobody, so the - // earlier message is deleted and this one sent, ringing as its kind rings; one the service will not - // delete loses its buttons and says where the newer one is. - c.replaced(*place) - place = nil + case !m.Secret: + if earlier, err = c.Store.Placed(m.Handle); err != nil { + c.Logf("[telegram] where an earlier message under this handle is could not be read (%v): sent as a new one", err) + earlier = nil + } } for try := 1; ; try++ { var id int64 @@ -261,6 +264,9 @@ func (c *Channel) Take(subject string, body json.RawMessage) error { err = c.newMessage(m.Handle, chat, words, buttons, silent, &id) } if err == nil { + if earlier != nil { + c.replaced(*earlier) + } c.mu.Lock() c.lastSent, c.lastErr = c.Now(), "" c.delivered++ diff --git a/modules/telegram/cmd/telegram/channel_test.go b/modules/telegram/cmd/telegram/channel_test.go index 1897373d..863df985 100644 --- a/modules/telegram/cmd/telegram/channel_test.go +++ b/modules/telegram/cmd/telegram/channel_test.go @@ -625,3 +625,18 @@ func TestAMessageSaidAgainUnderItsHandleReplacesTheEarlierOne(t *testing.T) { t.Errorf("its buttons stayed: %s", kb) } } + +// The review of PR 176: the new message is sent before the earlier one is deleted, so a send that fails leaves +// the operator the earlier message rather than none. +func TestAReplacementThatCannotBeSentLeavesTheEarlierMessage(t *testing.T) { + c, f, _, st := newChannel(t, goodToken) + st.Place("m1", Placed{Chat: 42, ID: 7}) + f.answer["sendMessage"] = func(map[string]any) (int, string) { + return 400, `{"ok":false,"error_code":400,"description":"Bad Request: chat not found"}` + } + subject, body := work(asks.Send, asks.Message{Handle: "m1", Title: "Still open: ace silent", Urgent: true, To: "42"}) + _ = c.Take(subject, body) + if len(f.of("deleteMessage")) != 0 || st.placed["m1"].ID != 7 { + t.Fatalf("the earlier message was taken away though its replacement was not sent: %+v", f.of("deleteMessage")) + } +} From 8dfc19c9f7c8216ea6f158be580ec4d4603c26b6 Mon Sep 17 00:00:00 2001 From: jochen Date: Sat, 10 Oct 2026 14:32:35 +0200 Subject: [PATCH 3/3] A silence is said on the shown message, which then times out (issue 373) Seen at 14:40: machine.shanks.units was silenced for 7 days with a reason, and its critical popup stood on the desk as "Still open" while the router logged nothing. A silence now edits the message where it is shown to "Silenced until : " with the reason, no answers and no urgency, so the desk's popup times out; nothing more is said while it lasts. When the silence ends and the condition is still open, the message is edited back to its open words. Resolved while silenced, it is said only where an edit notifies nobody. The silence is taken from the controller's event and from the 10-min reading of the open set alike. --- modules/messenger/README.md | 2 +- modules/messenger/cmd/messenger/holder.go | 76 ++++++++++++---- .../cmd/messenger/onemessage_test.go | 86 +++++++++++++++++++ modules/messenger/cmd/messenger/status.go | 2 +- modules/messenger/cmd/messenger/sync.go | 9 +- modules/messenger/cmd/messenger/words.go | 7 ++ 6 files changed, 163 insertions(+), 19 deletions(-) diff --git a/modules/messenger/README.md b/modules/messenger/README.md index 3b5c4eb0..d377c49f 100644 --- a/modules/messenger/README.md +++ b/modules/messenger/README.md @@ -119,7 +119,7 @@ warning kept quiet is also said once after a day. | `condition-cleared` | once it stays cleared 2 min (10 min once it came back): its message edited to say so; said inside a digest, a line in the next one | | cleared and raised again before its clearing was said | nothing: to the operator it never ended — a unit failing again after each apply is one message, not one per apply; back as urgent, or with a reminder waiting when it cleared, that is said | | cleared, said so, and raised again within 10 min | the same message, edited back to open — not a new one (urgent: said again in its place, so it rings) | -| silenced | nothing, its clearing included | +| silenced | its message, where shown, edited to "Silenced until : " with the reason, no answers and no urgency (the desk's popup times out); nothing more while it lasts; silence over and still open, the message is open again; resolved meanwhile, said only where an edit notifies nobody | **One message per problem** (issue 373). A record keeps the id of its message on each channel; a reminder or an escalation is said **in place of it** — the channel takes the earlier one away and shows the new one as a diff --git a/modules/messenger/cmd/messenger/holder.go b/modules/messenger/cmd/messenger/holder.go index 6679b0ee..b5441d49 100644 --- a/modules/messenger/cmd/messenger/holder.go +++ b/modules/messenger/cmd/messenger/holder.go @@ -173,13 +173,17 @@ type Record struct { Answered string `json:"answered,omitempty"` // Ask is the open ask about this record, `.`: its options are this record's answers // (novox/hq ADR 0259). - Ask string `json:"ask,omitempty"` - Origin string `json:"origin"` - More string `json:"more"` - Raised time.Time `json:"raised"` - SilencedTill time.Time `json:"silenced_till,omitempty"` - Sent map[string]string `json:"sent,omitempty"` // channel -> its message's id; "" when said in a digest - FirstSent time.Time `json:"first_sent,omitempty"` + Ask string `json:"ask,omitempty"` + Origin string `json:"origin"` + More string `json:"more"` + Raised time.Time `json:"raised"` + SilencedTill time.Time `json:"silenced_till,omitempty"` + // SilencedWhy is the reason the silence was given with; SilenceSaid: the message shown was edited to say + // it is silenced (issue 373: a critical popup silenced for a week stood on the desk as if still open). + SilencedWhy string `json:"silenced_why,omitempty"` + SilenceSaid bool `json:"silence_said,omitempty"` + Sent map[string]string `json:"sent,omitempty"` // channel -> its message's id; "" when said in a digest + FirstSent time.Time `json:"first_sent,omitempty"` // LastSaid is when a message about it last went out: a reminder is due its bound after it, never sooner // (an escalation followed by a reminder 31 s later, issue 373). LastSaid time.Time `json:"last_said,omitempty"` @@ -210,7 +214,7 @@ func recordOf(c Condition) Record { return Record{Key: c.Key, Kind: c.Kind, Subject: c.SubjectWords(), Severity: c.Severity, Summary: c.Summary, Headline: c.Headline, Explanation: c.Explanation, Resolved: c.Resolved, Needs: c.Needs, Actions: c.Actions, Origin: "condition", - More: "conditions show " + c.Key, Raised: c.Raised, SilencedTill: c.SilencedTill} + More: "conditions show " + c.Key, Raised: c.Raised, SilencedTill: c.SilencedTill, SilencedWhy: c.SilencedWhy} } // takeWords keeps the plain words current, as the summary is: a condition's words follow what is seen. @@ -471,13 +475,16 @@ func (h *Holder) raised(rec Record, quiet bool) { // it was kept quiet as needing nothing and now needs the operator. h.mu.Lock() wasQuiet := needsNothing(old) - old.Summary, old.Subject, old.Kind, old.SilencedTill = rec.Summary, rec.Subject, rec.Kind, rec.SilencedTill + wasSilenced := old.silenced(now) + old.Summary, old.Subject, old.Kind = rec.Summary, rec.Subject, rec.Kind + old.SilencedTill, old.SilencedWhy = rec.SilencedTill, rec.SilencedWhy old.takeWords(rec) if rec.Severity != "" { old.Severity = rec.Severity } old.Seen = now h.mu.Unlock() + h.silenceWords(old, wasSilenced) h.nowNeeded(old, wasQuiet, quiet) h.persist(old) return @@ -496,7 +503,7 @@ func (h *Holder) raised(rec Record, quiet bool) { } else { old.Count++ } - old.Summary, old.Severity, old.SilencedTill = rec.Summary, rec.Severity, rec.SilencedTill + old.Summary, old.Severity, old.SilencedTill, old.SilencedWhy = rec.Summary, rec.Severity, rec.SilencedTill, rec.SilencedWhy old.takeWords(rec) old.Seen = now h.mu.Unlock() @@ -567,13 +574,16 @@ func (h *Holder) changed(rec Record, quiet bool) { h.mu.Lock() escalated := old.Severity == Warning && rec.Severity == Urgent wasQuiet := needsNothing(old) - old.Summary, old.Subject, old.SilencedTill = rec.Summary, rec.Subject, rec.SilencedTill + wasSilenced := old.silenced(h.Now()) + old.Summary, old.Subject = rec.Summary, rec.Subject + old.SilencedTill, old.SilencedWhy = rec.SilencedTill, rec.SilencedWhy old.takeWords(rec) if rec.Severity != "" { old.Severity = rec.Severity } old.Seen = h.Now() h.mu.Unlock() + h.silenceWords(old, wasSilenced) switch { case escalated && !quiet && !old.silenced(h.Now()): // Routing differs for urgent: said once more, to both channels. @@ -584,6 +594,33 @@ func (h *Holder) changed(rec Record, quiet bool) { h.persist(old) } +// silenceWords keeps a shown message true to a silence (issue 373). Silenced, the message is edited in place +// to say so — until when, and why — with no answers and no urgency, so the desk's popup times out instead of +// standing as if still open. When the silence ends and the condition is still open, the message is edited back +// to its open words, and the usual rules apply again. +func (h *Holder) silenceWords(r *Record, wasSilenced bool) { + now := h.Now() + h.mu.Lock() + silenced, told, said := r.silenced(now), r.told(), r.SilenceSaid + key, till, why := r.Key, r.SilencedTill, r.SilencedWhy + h.mu.Unlock() + switch { + case silenced && !wasSilenced && told && !said: + h.mu.Lock() + r.SilenceSaid = true + h.mu.Unlock() + h.Logf("[messenger] %s silenced until %s (%s): its message says so, and nothing more is said of it", + key, till.Format(time.RFC3339), why) + h.edit(r, "silenced", false) + case !silenced && said: + h.mu.Lock() + r.SilenceSaid = false + h.mu.Unlock() + h.Logf("[messenger] %s is no longer silenced and still open: its message says it is open again", key) + h.edit(r, "raised", false) + } +} + // cleared ends a record. Something never said is ended without a word; what was waiting to be said // about it is dropped. quiet: it ended while this holder was not listening, so it is said only where // an edit notifies nobody. @@ -609,8 +646,13 @@ func (h *Holder) cleared(key string, quiet bool) { h.mu.Unlock() dropped := h.unqueue(key) switch { - case old.silenced(now): + case old.silenced(now) && !old.SilenceSaid: // A silenced condition sends nothing, its clearing included. + case old.silenced(now): + // Its message says it is silenced: said resolved where an edit notifies nobody, so it does not stand. + h.mu.Lock() + old.ClearUnsaid, old.ClearSilent, old.ClearHeld = true, true, "" + h.mu.Unlock() case !told: if dropped > 0 { h.Logf("[messenger] %s cleared before it was said: nothing to unsay", key) @@ -667,8 +709,8 @@ func (h *Holder) Tick() { r.ClearUnsaid = false silent := r.ClearSilent h.mu.Unlock() - if !r.silenced(now) { - h.edit(r, "cleared", silent) + if !r.silenced(now) || r.SilenceSaid { + h.edit(r, "cleared", silent || r.silenced(now)) } h.persist(r) } @@ -683,6 +725,10 @@ func (h *Holder) Tick() { } } case r.silenced(now): + case r.SilenceSaid: + // Its silence ran out while it is still open: the message is open again. + h.silenceWords(r, true) + h.persist(r) case r.Pending != "" && !h.queued(r.Key): // No channel could take it when it was said: tried again. h.deliver(r, r.Pending) @@ -737,7 +783,7 @@ func (h *Holder) say(r *Record, what string) Message { return h.sayOn(r, what, " // can carry, and where the others can be given. An empty kind is the words alone. func (h *Holder) sayOn(r *Record, what, kind string) Message { m := h.words(r, what) - if what == "cleared" || m.Title == "A mesh message was withheld" { + if what == "cleared" || what == "silenced" || m.Title == "A mesh message was withheld" { return m } if r.Answered != "" { diff --git a/modules/messenger/cmd/messenger/onemessage_test.go b/modules/messenger/cmd/messenger/onemessage_test.go index ae769b28..a16cbb58 100644 --- a/modules/messenger/cmd/messenger/onemessage_test.go +++ b/modules/messenger/cmd/messenger/onemessage_test.go @@ -289,3 +289,89 @@ func TestAClearingTheChannelCouldNotTakeIsSaidLater(t *testing.T) { } t.Fatalf("the clearing was lost: %+v", tg.sends) } + +// Issue 373, seen at 14:40: a condition silenced for a week with a reason left its critical popup standing on +// the desk as if still open, and the router logged nothing. A silence edits the shown message in place to say +// so — until when, and why — with no answers and no urgency, so the desk's popup times out; nothing more is +// said while it lasts; when the silence ends and the condition is still open, the message is open again. +func TestASilenceIsSaidOnTheShownMessageAndTheMessageIsOpenAgainWhenItEnds(t *testing.T) { + h, tg, dt, c, _ := newHolder(t) + h.Zone = func() *time.Location { return time.UTC } + k := cond("machine.shanks.units", Warning, "2 failed services on shanks") + k.Raised = c.now() + h.Condition(EventRaised, k) + settle(h, c) + if len(dt.sends) != 1 || len(dt.sends[0].Actions) == 0 { + t.Fatalf("raised: %+v", dt.sends) + } + c.pass(time.Hour) + k.SilencedTill, k.SilencedWhy = c.now().Add(7*24*time.Hour), "the mounts are gone for good" + h.Condition(EventChanged, k) + m, edited := dt.edits["g14=1"] + if !edited || m.Title != "Silenced until Tue 13 Oct 13:00: machine shanks units" || !m.Quiet || m.Urgent || + len(m.Actions) != 0 || !strings.Contains(m.Body, "Because: the mounts are gone for good.") { + t.Fatalf("silenced, and the desk's message says %q %q quiet=%v urgent=%v actions=%v", m.Title, m.Body, m.Quiet, m.Urgent, m.Actions) + } + if len(tg.sends)+len(tg.edits)+len(tg.replaced) != 0 { + t.Fatalf("a silence reached a channel the message was not on") + } + // Nothing more while it lasts: no reminder, and the same silence said again edits nothing more. + h.Condition(EventChanged, k) + runFor(h, c, 13*time.Hour) + if len(dt.sends) != 1 || len(dt.replaced) != 0 || len(dt.edits) != 1 { + t.Fatalf("said again while silenced: sends %d replaced %d edits %d", len(dt.sends), len(dt.replaced), len(dt.edits)) + } + // The silence runs out and the condition is still open: its message is open again, on the same notification. + c.pass(7 * 24 * time.Hour) + h.Tick() + if m := dt.edits["g14=1"]; m.Title != "machine shanks units" || m.Quiet || len(m.Actions) == 0 { + t.Fatalf("the silence ended, and the message says %q quiet=%v actions=%v", m.Title, m.Quiet, m.Actions) + } + if len(dt.sends) != 1 { + t.Fatalf("the silence ending made a new message: %d", len(dt.sends)) + } +} + +// Silenced on both channels and then resolved: Telegram's message, whose edits notify nobody, says so; the +// desk's popup, which timed out, is not brought back. +func TestAConditionResolvedWhileSilencedSaysSoOnlyWhereAnEditNotifiesNobody(t *testing.T) { + h, tg, dt, c, _ := newHolder(t) + k := cond("machine.ace.silent", Urgent, "the home server is silent") + k.Raised = c.now() + h.Condition(EventRaised, k) + k.SilencedTill, k.SilencedWhy = c.now().Add(24*time.Hour), "ace is moving house" + h.Condition(EventChanged, k) + if !strings.HasPrefix(tg.edits["1"].Title, "Silenced until ") || !strings.HasPrefix(dt.edits["g14=1"].Title, "Silenced until ") { + t.Fatalf("telegram %q desk %q", tg.edits["1"].Title, dt.edits["g14=1"].Title) + } + h.Condition(EventCleared, Condition{Key: k.Key, At: c.now()}) + runFor(h, c, ClearSettle+time.Minute) + if !strings.HasPrefix(tg.edits["1"].Title, "Resolved: ") || !strings.HasPrefix(dt.edits["g14=1"].Title, "Silenced until ") { + t.Fatalf("resolved while silenced: telegram %q desk %q", tg.edits["1"].Title, dt.edits["g14=1"].Title) + } + if len(tg.sends)+len(dt.sends) != 2 || len(tg.replaced)+len(dt.replaced) != 0 { + t.Fatalf("a new message was made: sends %d %d", len(tg.sends), len(dt.sends)) + } +} + +// A silence given while this holder was not told (the 10-min reading of the open set carries it) is said the +// same way, and the reading that says it ended makes the message open again. +func TestASilenceReadFromTheOpenSetIsSaidOnTheShownMessage(t *testing.T) { + h, _, dt, c, _ := newHolder(t) + k := cond("machine.shanks.units", Warning, "2 failed services on shanks") + k.Raised = c.now() + h.Condition(EventRaised, k) + settle(h, c) + c.pass(10 * time.Minute) + s := k + s.SilencedTill, s.SilencedWhy = c.now().Add(7*24*time.Hour), "the mounts are gone for good" + h.Sync([]Condition{s}, c.now()) + if m := dt.edits["g14=1"]; !strings.HasPrefix(m.Title, "Silenced until ") || !m.Quiet || len(m.Actions) != 0 { + t.Fatalf("read silenced, and the desk's message says %q quiet=%v actions=%v", m.Title, m.Quiet, m.Actions) + } + c.pass(10 * time.Minute) + h.Sync([]Condition{k}, c.now()) // the silence was lifted: the reading carries none + if m := dt.edits["g14=1"]; m.Title != "machine shanks units" || len(dt.sends) != 1 { + t.Fatalf("read unsilenced, and the desk's message says %q (sends %d)", m.Title, len(dt.sends)) + } +} diff --git a/modules/messenger/cmd/messenger/status.go b/modules/messenger/cmd/messenger/status.go index 79851e7a..4ccbdb6b 100644 --- a/modules/messenger/cmd/messenger/status.go +++ b/modules/messenger/cmd/messenger/status.go @@ -113,7 +113,7 @@ func (h *Holder) Status(listening string) Status { "deduplicated by the condition's key; reminded once after 1 h (urgent) or 12 h (warning); cleared by editing the first message", "at most 20 messages an hour per channel, a last line of defence: reached, it is said once and the rest held for one digest", "refused: anything carrying an address, a path or a secret; channel-refused is sent with the words withheld", - "silenced conditions send nothing; a silence is the controller's, asked of the operator or set through the mesh", + "a silenced condition's message says it is silenced, until when and why, and nothing more is said of it while the silence lasts; a silence is the controller's, asked of the operator or set through the mesh", } anyCan := false for _, c := range st.Channels { diff --git a/modules/messenger/cmd/messenger/sync.go b/modules/messenger/cmd/messenger/sync.go index d7983ee0..8de54260 100644 --- a/modules/messenger/cmd/messenger/sync.go +++ b/modules/messenger/cmd/messenger/sync.go @@ -57,7 +57,7 @@ func (h *Holder) Sync(open []Condition, asked time.Time) SyncResult { old := h.open[c.Key] var r *Record known := old != nil - wasQuiet := false + wasQuiet, wasSilenced := false, false switch { case old != nil && old.Seen.After(asked): h.mu.Unlock() @@ -65,13 +65,15 @@ func (h *Holder) Sync(open []Condition, asked time.Time) SyncResult { continue case old != nil: wasQuiet = needsNothing(old) && !old.told() + wasSilenced = old.silenced(now) if !old.Cleared.IsZero() { // Ended here, open there: back to open, quietly — the reading is not an event. old.Cleared = time.Time{} old.ClearUnsaid, old.ClearSilent, old.ClearHeld = false, false, "" old.Count++ } - old.Summary, old.Subject, old.Kind, old.SilencedTill = rec.Summary, rec.Subject, rec.Kind, rec.SilencedTill + old.Summary, old.Subject, old.Kind = rec.Summary, rec.Subject, rec.Kind + old.SilencedTill, old.SilencedWhy = rec.SilencedTill, rec.SilencedWhy old.takeWords(rec) if rec.Severity != "" { old.Severity = rec.Severity @@ -95,6 +97,9 @@ func (h *Holder) Sync(open []Condition, asked time.Time) SyncResult { told := r.told() silenced := r.silenced(now) h.mu.Unlock() + if known { + h.silenceWords(r, wasSilenced) + } switch { case told || silenced || h.queued(r.Key): case r.Severity == Urgent: diff --git a/modules/messenger/cmd/messenger/words.go b/modules/messenger/cmd/messenger/words.go index 666a5b0e..d0723de0 100644 --- a/modules/messenger/cmd/messenger/words.go +++ b/modules/messenger/cmd/messenger/words.go @@ -51,6 +51,13 @@ func compose(r *Record, what string, now time.Time, loc *time.Location, withhold title = "Still open after a day: " + headline case "escalated": title = "Now urgent: " + headline + case "silenced": + // Said in place of the open message: no urgency, so the desk's popup times out, and no answers. + body := "Nothing more is said of it until then." + if r.SilencedWhy != "" { + body = "Because: " + strings.TrimSuffix(strings.TrimSpace(r.SilencedWhy), ".") + ". " + body + } + return Message{Title: "Silenced until " + by(r.SilencedTill, now, loc) + ": " + headline, Body: body, Quiet: true} case "reopened": title = headline + " (again" + times(r.Count) + ")" if urgent {