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")) + } +}