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 {