diff --git a/modules/mesh-delivery-gate/README.md b/modules/mesh-delivery-gate/README.md index 4f8b9de3..5b208ec6 100644 --- a/modules/mesh-delivery-gate/README.md +++ b/modules/mesh-delivery-gate/README.md @@ -20,6 +20,19 @@ of such a delivery asks the controller (`delivery-backups-again`) to take the ba delivering; a record from before the controller cleared the failure does not hold it again. A held delivery already ends as covered or delivered when a later merge covers it. +## When a refused or rejected merge is said (ADR 0505 §4, §5) + +`stalled` is what the controller raises as a condition for the operator. The gate's own list (`show`, `deliveries`) +names every refusal and rejection at once, and the pull request is told at once; only `stalled` waits: + +- a merge refused because its trunk moved, whose check the gate asked again, is stalled only once that check answered and + the merge was refused again, or twice the repository's last check time passed (at least the setting + `refusal-stall-floor-minutes`, 10). Every other refusal is stalled at once. +- a delivery that needs its author's new head (its check failed after its Approve: a conflict, a failed check, a rejected + group) is stalled only once no new head came for the setting `author-new-head-minutes` (120). Its line says + `needs: new-head` and names its author: the branch, and the session a `Pushed-by: ` line in the pull + request's description names. + ## Taking the seat over from today's module The gate claims the seat `mesh-delivery` and took it over from the module `mesh-delivery`, which the catalogue no longer holds. diff --git a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/adr505_bus_test.go b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/adr505_bus_test.go new file mode 100644 index 00000000..0bde5945 --- /dev/null +++ b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/adr505_bus_test.go @@ -0,0 +1,88 @@ +//go:build integration + +package main + +import ( + "context" + "encoding/json" + "strconv" + "strings" + "testing" + "time" + + sdk "git.novox.be/novox/mesh-sdk/go/delivery" +) + +// novox/hq ADR 0505 §4 over the real bus, in the bed of bus_test.go: the gate whole, its deliveries kept in its buckets. + +// call asks the bundle one of its verbs, as the runtime does, and answers its result's text. +func (r *runtime) call(t *testing.T, name string, args map[string]any) string { + t.Helper() + r.mu.Lock() + r.next++ + id := "adr505-" + strconv.Itoa(r.next) + ch := make(chan json.RawMessage, 1) + r.wait[id] = ch + r.mu.Unlock() + r.say(map[string]any{"id": id, "method": "tools/call", "params": map[string]any{"name": name, "arguments": args}}) + select { + case raw := <-ch: + return string(raw) + case <-time.After(30 * time.Second): + t.Fatalf("%s was not answered in 30 s", name) + } + return "" +} + +// ADR 0505 §4: an approved head the merge tool refused because its trunk moved is shown by `show` at once but is not in +// `stalled` while its fresh check is unanswered; once that check passed and the merge is refused again, it is. +func TestATrunkMovedRefusalIsStalledOnlyOnceItsFreshCheckDidNotCureItOverARealBus(t *testing.T) { + b := newTestBus(t) + ctx := context.Background() + rt := b.start(t) + evctx, cancel := context.WithCancel(ctx) + defer cancel() + rt.deliverEvents(evctx) + rt.until("the module to subscribe to the events it follows", 20*time.Second, func() bool { + rt.mu.Lock() + defer rt.mu.Unlock() + return len(rt.subs) >= len(followed) + }) + rt.untilHolding() + + const head = "1111111111111111111111111111111111111111" + id := IDOf("novox/app", head) + announced := pr("novox/app", 7, head, "fix/x", "src/a.go") + announced.BaseSHA = "t1t1t1t1t1t1" + b.publish(t, "mesh.mod.gitea.event.pull.updated", announced) + b.publish(t, "mesh.seat."+ControllerSeat+".event.checked", judgedAt("novox/app", 7, head, "pass", "t1t1t1t1t1t1")) + var key string + rt.until("the ask to be written", 10*time.Second, func() bool { key = onlyAsk(b); return key != "" }) + b.answer(t, key, OptionApprove) + rt.until("the merge to be handed to the bridge", 10*time.Second, func() bool { return len(mergeAt(b, "fix/x").Pulls) > 0 }) + + refused := func() { + b.forgeSays(t, sdk.Forge{Kind: sdk.ForgeRefused, Act: "merge", Repository: "novox/app", Number: 7, Head: head, + Words: errAskedAgain.Error()}) + } + refused() + rt.until("show to name the refusal at once", 10*time.Second, func() bool { + return strings.Contains(rt.call(t, Seat+".show", map[string]any{"id": id}), "its verdict was judged against trunk") + }) + if got := rt.call(t, Seat+".stalled", map[string]any{}); strings.Contains(got, id) { + t.Fatalf("said as stalled while its fresh check runs: %s", got) + } + + // The trunk moved; the head is announced again and its fresh check passes; the merge is refused again on it. + b.publish(t, "mesh.mod.gitea.event.pull.merged", merged("novox/app", 9, "9999999999999999999999999999999999999999", "t2t2t2t2t2t2")) + b.publish(t, "mesh.mod.gitea.event.pull.updated", announced) + time.Sleep(time.Second) + b.publish(t, "mesh.seat."+ControllerSeat+".event.checked", judgedAt("novox/app", 7, head, "pass", "t2t2t2t2t2t2")) + rt.until("the fresh verdict to be heard", 10*time.Second, func() bool { + return strings.Contains(rt.call(t, Seat+".show", map[string]any{"id": id}), "t2t2t2t2t2t2") + }) + refused() + rt.until("the refusal on the fresh verdict to be said as stalled", 10*time.Second, func() bool { + return strings.Contains(rt.call(t, Seat+".stalled", map[string]any{}), id) + }) +} diff --git a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/adr505_test.go b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/adr505_test.go new file mode 100644 index 00000000..76833d2f --- /dev/null +++ b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/adr505_test.go @@ -0,0 +1,294 @@ +package main + +import ( + "encoding/json" + "os" + "path/filepath" + "strings" + "testing" + "time" + + stdio "git.novox.be/novox/mesh-sdk/go" +) + +// The tests of novox/hq ADR 0505 "How it is checked" for the gate: a refusal the gate is already answering is no +// stall yet (§4), and a delivery whose cure is its author's new head is its author's for two hours (§5). + +// ADR 0505 §4, §5: the two bounds are settings with their decided defaults. +func TestTheBoundsAreSettingsWithTheirDefaults(t *testing.T) { + read := func(body string) (Settings, error) { + p := filepath.Join(t.TempDir(), "settings.json") + if err := os.WriteFile(p, []byte(body), 0o600); err != nil { + t.Fatal(err) + } + return readSettings(p) + } + h := &Holder{} + if h.refusalFloor() != 10*time.Minute || h.authorBound() != 2*time.Hour { + t.Fatalf("no settings: floor %s, author %s", h.refusalFloor(), h.authorBound()) + } + s, err := read(`{"refusal-stall-floor-minutes": 5, "author-new-head-minutes": 60}`) + if err != nil { + t.Fatal(err) + } + h.Settings = func() Settings { return s } + if h.refusalFloor() != 5*time.Minute || h.authorBound() != time.Hour { + t.Fatalf("set: floor %s, author %s", h.refusalFloor(), h.authorBound()) + } + s, _ = read(`{}`) + if h.refusalFloor() != 10*time.Minute || h.authorBound() != 2*time.Hour { + t.Fatalf("empty file: floor %s, author %s", h.refusalFloor(), h.authorBound()) + } + if _, err := read(`{"author-new-head-minutes": 0}`); err == nil { + t.Fatalf("a bound of zero minutes was taken") + } +} + +// ADR 0505 §4: a repository's last measured check time is its newest verdict's (`took`, as mesh-controller +// cmd/mesh-builder main.go writes it: a duration rounded to the second); none, and the floor alone holds. +func TestTheLastMeasuredCheckTimeIsTheNewestVerdictsOfItsRepository(t *testing.T) { + h := &Holder{} + h.init() + at := time.Date(2026, 10, 22, 10, 0, 0, 0, time.UTC) + h.deliveries["novox/mesh-catalog@a"] = &Delivery{ID: "novox/mesh-catalog@a", Repository: "novox/mesh-catalog", + Check: &Verdict{At: at, Took: "4m0s"}} + h.deliveries["novox/mesh-catalog@b"] = &Delivery{ID: "novox/mesh-catalog@b", Repository: "novox/mesh-catalog", + Check: &Verdict{At: at.Add(time.Hour), Took: "7m30s"}} + h.deliveries["novox/hq@c"] = &Delivery{ID: "novox/hq@c", Repository: "novox/hq", + Check: &Verdict{At: at.Add(2 * time.Hour), Took: "1m0s"}} + if got := h.lastCheckTime("novox/mesh-catalog"); got != 7*time.Minute+30*time.Second { + t.Fatalf("the newer of two: %s", got) + } + if got := h.answeredRefusalBound("novox/mesh-catalog"); got != 15*time.Minute { + t.Fatalf("twice 7m30s: %s", got) + } + if got := h.answeredRefusalBound("novox/hq"); got != 10*time.Minute { + t.Fatalf("twice one minute is under the floor: %s", got) + } + if got := h.answeredRefusalBound("novox/mesh-sdk"); got != 10*time.Minute { + t.Fatalf("no verdict: %s", got) + } +} + +// refusedForAMovedTrunk is a lone delivery approved and refused by the merge tool because its trunk moved and its check +// was asked again (gitea merge.ts:147, errAskedAgain). +func refusedForAMovedTrunk(t *testing.T) (*world, string) { + t.Helper() + w := announced(t) + id := IDOf("novox/app", readyHead) + hear(t, w, ControllerSeat+".checked", judgedAt("novox/app", 7, readyHead, "pass", "t1t1t1t1t1t1")) + w.forge.refuse = errAskedAgain + approve(w) + if len(w.forge.merges) != 1 || w.delivery(id).Ready.RefusedSince == nil { + t.Fatalf("the merge was not asked and refused: %v %+v", w.forge.merges, w.delivery(id).Ready) + } + return w, id +} + +func linesFor(w *world, id string) []StalledLine { + var out []StalledLine + for _, l := range w.h.Stalled() { + if l.ID == id { + out = append(out, l) + } + } + return out +} + +// ADR 0505 §4: a refusal because the trunk moved, whose check the gate asked again, is in the gate's own list at once +// but is no stalled line while its check is unanswered; once that check passed and the merge is refused again, it is. +func TestATrunkMovedRefusalIsStalledOnlyOnceItsFreshCheckAnsweredAndTheMergeIsRefusedAgain(t *testing.T) { + w, id := refusedForAMovedTrunk(t) + if got := linesFor(w, id); len(got) != 0 { + t.Fatalf("said as stalled while its fresh check runs: %+v", got) + } + shown, err := w.h.Show(id) + if err != nil { + t.Fatal(err) + } + if raw, _ := json.Marshal(shown); !strings.Contains(string(raw), "is not merged: its verdict was judged against trunk") { + t.Fatalf("the gate's own list does not show the refusal at once: %s", raw) + } + w.later(5 * time.Minute) + if got := linesFor(w, id); len(got) != 0 { + t.Fatalf("said as stalled at five minutes, its check unanswered: %+v", got) + } + // As on the live mesh (events_test.go): the trunk moved, the head is announced again, its fresh verdict passes + // against the new trunk, and the merge is asked and refused again, the trunk having moved once more. + w.h.PullMerged(merged("novox/app", 9, "9999999999999999", "t2t2t2t2t2t2")) + w.h.PullUpdated(pr("novox/app", 7, readyHead, "feat/x", "src/a.go")) + w.later(time.Second) + hear(t, w, ControllerSeat+".checked", judgedAt("novox/app", 7, readyHead, "pass", "t2t2t2t2t2t2")) + w.settleAll() + if len(w.forge.merges) != 2 { + t.Fatalf("the fresh verdict did not ask the merge again: %v", w.forge.merges) + } + if got := linesFor(w, id); len(got) != 1 { + t.Fatalf("its check answered and the merge refused again, yet no stalled line: %+v", got) + } +} + +// ADR 0505 §4: with no answer, the refusal is said at twice the repository's last check time, at least ten minutes. +func TestATrunkMovedRefusalIsStalledAtTwiceTheLastCheckTimeAtLeastTheFloor(t *testing.T) { + w, id := refusedForAMovedTrunk(t) + w.later(9 * time.Minute) + if got := linesFor(w, id); len(got) != 0 { + t.Fatalf("said before the floor: %+v", got) + } + w.later(2 * time.Minute) + if got := linesFor(w, id); len(got) != 1 { + t.Fatalf("not said past the floor of ten minutes: %+v", got) + } + + w, id = refusedForAMovedTrunk(t) + w.h.mu.Lock() + w.h.deliveries[id].Check.Took = "7m0s" // its repository's last check ran seven minutes: the bound is fourteen + w.h.mu.Unlock() + w.later(11 * time.Minute) + if got := linesFor(w, id); len(got) != 0 { + t.Fatalf("said at eleven minutes, under twice the last check time: %+v", got) + } + w.later(4 * time.Minute) + if got := linesFor(w, id); len(got) != 1 { + t.Fatalf("not said past twice the last check time: %+v", got) + } +} + +// ADR 0505 §4: any other refusal is said at once, as issue 1115 has it. +func TestAnyOtherRefusalIsStalledAtOnce(t *testing.T) { + w := announced(t) + id := IDOf("novox/app", readyHead) + hear(t, w, ControllerSeat+".checked", judgedAt("novox/app", 7, readyHead, "pass", "t1t1t1t1t1t1")) + w.forge.refuse = refusedWords("novox/app#7") + approve(w) + if got := linesFor(w, id); len(got) != 1 { + t.Fatalf("a missing status refusal is not said at once: %+v", got) + } +} + +// rejectedAfterItsApprove is a delivery approved and then rejected: its check failed after the ask (as in events_test.go), +// its pull request's description naming who pushed it when pushedBy is given. +func rejectedAfterItsApprove(t *testing.T, pushedBy string) (*world, string) { + t.Helper() + w := newWorld(t) + w.op.auto = false + p := pr("novox/app", 7, readyHead, "feat/x", "src/a.go") + if pushedBy != "" { + p.Body += "\nPushed-by: " + pushedBy + } + w.h.PullUpdated(p) + w.settleAll() + id := IDOf("novox/app", readyHead) + hear(t, w, ControllerSeat+".checked", judgedAt("novox/app", 7, readyHead, "pass", "t1t1t1t1t1t1")) + if _, err := w.h.Recheck(id, "a second look", "tester"); err != nil { + t.Fatal(err) + } + hear(t, w, ControllerSeat+".checked", judgedAt("novox/app", 7, readyHead, "fail", "t1t1t1t1t1t1")) + approve(w) + w.h.React() + if w.state(id) != Rejected { + t.Fatalf("not rejected: %s", w.state(id)) + } + return w, id +} + +// ADR 0505 §5: a rejected delivery is told on its pull request at once, and reaches the operator only after two hours +// with no new head, in words naming its author (its branch, and the session that pushed it) and needing a new head — +// never "stop it", never "the operator's". +func TestARejectedDeliveryIsItsAuthorsForTwoHours(t *testing.T) { + w, id := rejectedAfterItsApprove(t, "quiet-deliveries@shanks") + said := false + for _, c := range w.forge.comments { + said = said || strings.Contains(c, "not merged") + } + if !said { + t.Fatalf("its author was not told on the pull request at once: %v", w.forge.comments) + } + w.later(2*time.Hour - time.Minute) + if got := linesFor(w, id); len(got) != 0 { + t.Fatalf("the operator's before two hours: %+v", got) + } + w.later(2 * time.Minute) + got := linesFor(w, id) + if len(got) != 1 { + t.Fatalf("not the operator's after two hours with no new head: %+v", got) + } + l := got[0] + if l.Needs != NeedsNewHead || l.Author != "the author of feat/x (quiet-deliveries on shanks)" || l.Branch != "feat/x" { + t.Fatalf("the line does not name its author and the new head it needs: %+v", l) + } + for _, never := range []string{"operator's", "stop it"} { + if strings.Contains(l.Says+l.H2, never) { + t.Fatalf("the line says %q: %+v", never, l) + } + } + if !strings.Contains(l.Says, "needs a new head from the author of feat/x (quiet-deliveries on shanks)") { + t.Fatalf("the words do not say a new head is needed from its author: %q", l.Says) + } +} + +// ADR 0505 §5: with no Pushed-by line, the branch alone names its author. +func TestARejectedDeliveryWithNoPushedByLineIsNamedByItsBranch(t *testing.T) { + w, id := rejectedAfterItsApprove(t, "") + w.later(2*time.Hour + time.Minute) + if got := linesFor(w, id); len(got) != 1 || got[0].Author != "the author of feat/x" { + t.Fatalf("not named by its branch: %+v", got) + } +} + +// ADR 0505 §5: a new head within the two hours ends it: the rejected head is never the operator's. +func TestANewHeadWithinTwoHoursKeepsTheRejectedHeadFromTheOperator(t *testing.T) { + w, id := rejectedAfterItsApprove(t, "quiet-deliveries@shanks") + w.later(time.Hour) + w.h.PullUpdated(pr("novox/app", 7, pushed, "feat/x", "src/a.go")) + w.settleAll() + w.later(2 * time.Hour) + if got := linesFor(w, id); len(got) != 0 { + t.Fatalf("the superseded head reached the operator: %+v", got) + } +} + +// ADR 0505 §2: a walk's end said again by the controller with its declared machines (`declared_read`, a touch marked +// declared) acts once: no transition, comment or ask of the controller the first saying did not make. +func TestAWalkSaidAgainWithItsDeclaredMachinesActsOnceInTheGate(t *testing.T) { + w, id, plan := aDeliveringWalk(t) + done := w.ctl.walk(plan) + sent := time.Date(2026, 10, 6, 12, 40, 0, 0, time.UTC) + done.Modules["app"] = &WalkModule{State: "built", First: []string{"anchor"}, FirstAt: &sent, SentAt: &sent, Build: "build-1", + Gate: &WalkGate{Machines: []string{"anchor"}, Since: &sent, Passes: 1, Verdict: "passed", JudgedAt: &sent}} + done.State = walkDone + done = w.ctl.put(done) + body := func(again bool) []byte { + raw, err := json.Marshal(done) + if err != nil { + t.Fatal(err) + } + var said map[string]any + _ = json.Unmarshal(raw, &said) + said["walk"], said["phase"], said["outcome"] = plan, "ended", "delivered" + said["touches"] = []map[string]any{{"machine": "anchor", "modules": []string{"app"}}} + if again { + said["touches"] = append(said["touches"].([]map[string]any), + map[string]any{"machine": "shanks", "modules": []string{}, "declared": true}) + said["declared_read"] = true + } + out, _ := json.Marshal(said) + return out + } + if err := take(w.h, stdio.Envelope{Key: ControllerSeat + ".plan-moved", Body: body(false)}); err != nil { + t.Fatal(err) + } + w.settleAll() + if s := w.state(id); s != Delivered { + t.Fatalf("the walk's end left it %s", s) + } + transitions, comments, delivers := len(w.delivery(id).Transitions), len(w.forge.comments), len(w.ctl.delivers) + if err := take(w.h, stdio.Envelope{Key: ControllerSeat + ".plan-moved", Body: body(true)}); err != nil { + t.Fatal(err) + } + w.settleAll() + if len(w.delivery(id).Transitions) != transitions || len(w.forge.comments) != comments || len(w.ctl.delivers) != delivers { + t.Fatalf("said again it acted again: transitions %d→%d, comments %d→%d, asks of the controller %d→%d", + transitions, len(w.delivery(id).Transitions), comments, len(w.forge.comments), delivers, len(w.ctl.delivers)) + } +} diff --git a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/checktime.go b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/checktime.go new file mode 100644 index 00000000..91bc0eec --- /dev/null +++ b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/checktime.go @@ -0,0 +1,34 @@ +package main + +import "time" + +// lastCheckTime is how long the newest answered check of a repository ran, as its verdict says it (`took`): the +// repository's last measured check time (novox/hq ADR 0505 §4). Zero when no verdict of the repository says it. +// Under the lock. +func (h *Holder) lastCheckTime(repository string) time.Duration { + var newest *Verdict + var took time.Duration + for _, d := range h.deliveries { + v := d.Check + if d.Repository != repository || v == nil || v.Took == "" { + continue + } + t, err := time.ParseDuration(v.Took) + if err != nil || t <= 0 { + continue + } + if newest == nil || v.At.After(newest.At) { + newest, took = v, t + } + } + return took +} + +// answeredRefusalBound is how long a refusal the gate is already answering waits before it is said as stalled: twice +// the repository's last measured check time, at least the floor (ADR 0505 §4). Under the lock. +func (h *Holder) answeredRefusalBound(repository string) time.Duration { + if b := 2 * h.lastCheckTime(repository); b > h.refusalFloor() { + return b + } + return h.refusalFloor() +} diff --git a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/events_test.go b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/events_test.go index 90e2d95c..f5e1f299 100644 --- a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/events_test.go +++ b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/events_test.go @@ -4,6 +4,7 @@ import ( "encoding/json" "strings" "testing" + "time" stdio "git.novox.be/novox/mesh-sdk/go" ) @@ -229,7 +230,8 @@ func TestAPushAfterTheAskEndsItAndSaysSoOnceOnThePullRequest(t *testing.T) { } } -// Issue 1022 (ADR 0421 §7): a check that failed after the ask merges nothing and is said once and as a stalled line. +// Issue 1022 (ADR 0421 §7), as novox/hq ADR 0505 §5 changed it: a check that failed after the ask merges nothing, is +// said once on the pull request at once, and is a stalled line only after two hours with no new head. func TestACheckThatFailsAfterTheAskIsNotMergedAndIsSaid(t *testing.T) { w := announced(t) id := IDOf("novox/app", readyHead) @@ -252,6 +254,10 @@ func TestACheckThatFailsAfterTheAskIsNotMergedAndIsSaid(t *testing.T) { if said != 1 { t.Fatalf("the failure is not said once: %v", w.forge.comments) } + if lines := w.h.Stalled(); len(lines) != 0 { + t.Fatalf("the failure is the operator's before its author had two hours: %+v", lines) + } + w.later(2*time.Hour + time.Minute) lines := w.h.Stalled() if len(lines) != 1 || lines[0].ID != id || strings.Contains(lines[0].Says, "marked") { t.Fatalf("the failure is not a stalled line: %+v", lines) diff --git a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/holder.go b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/holder.go index ef4b0045..301ed7ed 100644 --- a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/holder.go +++ b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/holder.go @@ -22,6 +22,8 @@ import ( // Holder is the seat's holder. type Holder struct { + // Settings reads the operator's values (settings.go); nil keeps every default. + Settings func() Settings Store Store Controller Controller Forge Forge @@ -374,6 +376,11 @@ func (h *Holder) pullUpdated(p PullEvent) (isNew bool) { d.ReviewedBy, d.ReviewedAt = by, at h.keep(d) } + // So is the line naming who pushed it (ADR 0505 §5). + if by := PushedIn(p.Body); p.Body != "" && by != d.PushedBy { + d.PushedBy = by + h.keep(d) + } // An `after:` line written into the description later is told about too (novox/hq ADR 0419 §2). if after := AfterIn(p.Body); p.Body != "" && !slices.Equal(after, d.After) { d.After = after @@ -451,6 +458,7 @@ func (h *Holder) fillFromAnnouncement(d *Delivery, p PullEvent) { d.ModuleDirs, d.ModuleDirsSaid = p.ModuleDirs, p.ModuleDirsSaid d.Issues, d.After = IssuesIn(p.Title+"\n"+p.Body), AfterIn(p.Body) d.ReviewedBy, d.ReviewedAt = ReviewIn(p.Body) + d.PushedBy = PushedIn(p.Body) if p.BaseSHA != "" { d.BaseSHA = p.BaseSHA } @@ -504,6 +512,7 @@ func (h *Holder) PullEdited(p PullEvent) { } before, _ := reviewWords(d) d.ReviewedBy, d.ReviewedAt = ReviewIn(p.Body) + d.PushedBy = PushedIn(p.Body) d.After = AfterIn(p.Body) title := p.Title if title == "" { @@ -571,6 +580,7 @@ func (h *Holder) freshAnnouncement(p PullEvent, now time.Time, startedOver strin PathsTruncated: p.PathsTruncated, Removed: p.Removed, ModuleDirs: p.ModuleDirs, ModuleDirsSaid: p.ModuleDirsSaid, After: AfterIn(p.Body), Issues: IssuesIn(p.Title + "\n" + p.Body), Created: now, BaseSHA: p.BaseSHA} d.ReviewedBy, d.ReviewedAt = ReviewIn(p.Body) + d.PushedBy = PushedIn(p.Body) why := fmt.Sprintf("%s#%d's head announced", d.Repository, d.Number) if startedOver != "" { why = fmt.Sprintf("%s; %s", why, startedOver) diff --git a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/issue1275_test.go b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/issue1275_test.go index 4530e52c..e26f5b17 100644 --- a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/issue1275_test.go +++ b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/issue1275_test.go @@ -249,9 +249,10 @@ func TestAMemberBothRefusedAndHeldForAStatusIsOneStalledLine(t *testing.T) { } } -// 1275/AC6: a member refused because its verdict is out of date (the trunk moved; its fresh check runs) is a warning at -// once, and urgent only when the group is not merged within ten minutes; the pass stops at the refusal all the same. -func TestAnOutOfDateRefusalIsAWarningAtOnceAndUrgentAfterTenMinutes(t *testing.T) { +// 1275/AC6, as novox/hq ADR 0505 §4 changed it: a member refused because its verdict is out of date (the trunk moved; its +// fresh check runs) is no stalled line while the gate answers it, and urgent once ten minutes passed with the group not +// merged; the pass stops at the refusal all the same. +func TestAnOutOfDateRefusalIsNoLineWhileAnsweredAndUrgentAfterTenMinutes(t *testing.T) { w := approvedGroup(t) allGreen(w) w.forge.refuse = errAskedAgain @@ -267,12 +268,12 @@ func TestAnOutOfDateRefusalIsAWarningAtOnceAndUrgentAfterTenMinutes(t *testing.T } return out } - if got := sev(); len(got) != 1 || got[0] != "warning" { - t.Fatalf("an out of date refusal is %v at once; wanted one warning", got) + if got := sev(); len(got) != 0 { + t.Fatalf("an out of date refusal is %v at once; wanted no line while it is answered", got) } w.later(9 * time.Minute) - if got := sev(); len(got) != 1 || got[0] != "warning" { - t.Fatalf("at nine minutes it is %v; wanted still a warning", got) + if got := sev(); len(got) != 0 { + t.Fatalf("at nine minutes it is %v; wanted still no line", got) } w.later(2 * time.Minute) if got := sev(); len(got) != 1 || got[0] != "urgent" { @@ -300,9 +301,9 @@ func severities(w *world) []string { return out } -// 1275/AC6 (b): the same out of date refusal on a LATER member, after the earlier one merged, is a warning at once and -// urgent after ten minutes: the half merged group does not say it urgent at once. -func TestAnOutOfDateRefusalOnALaterMemberIsAWarningThenUrgent(t *testing.T) { +// 1275/AC6 (b), as ADR 0505 §4 changed it: the same out of date refusal on a LATER member, after the earlier one merged, +// is no line at once and urgent after ten minutes: the half merged group does not say it at once. +func TestAnOutOfDateRefusalOnALaterMemberIsNoLineThenUrgent(t *testing.T) { w := approvedGroup(t) allGreen(w) w.forge.refuseRepo = map[string]error{gCtl: errAskedAgain} @@ -310,8 +311,8 @@ func TestAnOutOfDateRefusalOnALaterMemberIsAWarningThenUrgent(t *testing.T) { w.settleAll() w.h.PullMerged(merged(gCat, 2, gHk, gT1)) w.settleAll() - if got := severities(w); len(got) != 1 || got[0] != "warning" { - t.Fatalf("a later member's out of date refusal is %v at once; wanted one warning", got) + if got := severities(w); len(got) != 0 { + t.Fatalf("a later member's out of date refusal is %v at once; wanted no line while it is answered", got) } w.later(11 * time.Minute) if got := severities(w); len(got) != 1 || got[0] != "urgent" { @@ -371,9 +372,10 @@ var mergeToolRefusals = []struct { "Nothing was merged", false}, } -// 1275/AC6 (e): only the merge tool's two out of date refusals (:121, :147) are warnings; the one saying its check could -// not be asked (:144) and every other is urgent at once. -func TestOnlyTheMergeToolsTwoOutOfDateRefusalsAreWarnings(t *testing.T) { +// 1275/AC6 (e), as ADR 0505 §4 changed it: only the merge tool's two out of date refusals (:121, :147) are answered by +// the gate and said as no line at once; the one saying its check could not be asked (:144) and every other is urgent at +// once. +func TestOnlyTheMergeToolsTwoOutOfDateRefusalsWaitWhileAnswered(t *testing.T) { for _, c := range mergeToolRefusals { if got := outOfDateRefusal(c.words); got != c.outOfDated { t.Errorf("%s: outOfDateRefusal = %v, wanted %v", c.line, got, c.outOfDated) @@ -383,12 +385,12 @@ func TestOnlyTheMergeToolsTwoOutOfDateRefusalsAreWarnings(t *testing.T) { w.forge.refuse = errors.New("the forge refused gitea_merge_pull_request: " + c.words) w.op.answer(w.op.open()[0], OptionApprove) w.settleAll() - want := "urgent" - if c.outOfDated { - want = "warning" + got := severities(w) + if c.outOfDated && len(got) != 0 { + t.Errorf("%s: said %v at once, wanted no line while it is answered", c.line, got) } - if got := severities(w); len(got) != 1 || got[0] != want { - t.Errorf("%s: severity %v at once, wanted %s", c.line, got, want) + if !c.outOfDated && (len(got) != 1 || got[0] != "urgent") { + t.Errorf("%s: severity %v at once, wanted urgent", c.line, got) } } } diff --git a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/main.go b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/main.go index 03855f7c..e5ef06db 100644 --- a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/main.go +++ b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/main.go @@ -41,7 +41,24 @@ const forgePattern = "mesh-delivery-forge-bridge.forge.**" func main() { occupancy := &busOccupancy{} + settingsFile := os.Getenv("MESH_DELIVERY_GATE_SETTINGS") + var saidMu sync.Mutex + lastSaid := "" + settings := func() Settings { + s, err := readSettings(settingsFile) + saidMu.Lock() + defer saidMu.Unlock() + if err != nil && err.Error() != lastSaid { + logf("[mesh-delivery-gate] settings cannot be read, the defaults hold: %v", err) + } + lastSaid = "" + if err != nil { + lastSaid = err.Error() + } + return s + } h := &Holder{ + Settings: settings, Store: kvStore{}, Controller: seatController{ask: stdio.Ask}, Forge: toolForge{ask: stdio.Ask}, diff --git a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/merges.go b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/merges.go index 4070027b..4075efff 100644 --- a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/merges.go +++ b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/merges.go @@ -284,9 +284,14 @@ func (h *Holder) ForgeRefused(f sdk.Forge) { r, now := d.Ready, h.Now() r.merging, r.refusedNoted = false, false answer := oneLine(f.Words) - if r.RefusedSince == nil { - r.RefusedSince = &now + var on time.Time + if d.Check != nil { + on = d.Check.At } + if r.RefusedSince == nil { + r.RefusedSince, r.FirstRefusedOn = &now, on + } + r.LastRefusedOn = on r.noteRefusal(d, answer) if !outOfDateRefusal(answer) { r.Urgent = true // never a warning again for this head diff --git a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/model.go b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/model.go index 9425bfbe..f025d9a9 100644 --- a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/model.go +++ b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/model.go @@ -135,6 +135,9 @@ type Delivery struct { // hold: no Approve is asked until it names the head (novox/hq ADR 0496, issue 1803). ReviewedBy string `json:"reviewed_by,omitempty"` ReviewedAt string `json:"reviewed_at,omitempty"` + // PushedBy is the session that pushed its head, as its pull request's description names it in a line + // `Pushed-by: ` (playbook 07): named with its branch when a new head is needed (novox/hq ADR 0505 §5). + PushedBy string `json:"pushed_by,omitempty"` // FreshWanted is whether a passing verdict that arrived out of date is to have its check asked against the // trunk's head, before the operator is asked (novox/hq ADR 0421 §3, issue 1022). Cleared when it is asked. FreshWanted bool `json:"fresh_wanted,omitempty"` @@ -498,6 +501,31 @@ func ReviewIn(body string) (who, sha string) { return who, sha } +// pushedLine is the line naming the session that pushed a pull request's head: `Pushed-by: ` (ADR 0505 §5). +var pushedLine = regexp.MustCompile(`(?im)^\s*Pushed-by:\s*([A-Za-z0-9_.\-]+(?:@[A-Za-z0-9_.\-]+)?)\s*$`) + +// PushedIn reads it: the last such line, or "" when there is none. +func PushedIn(body string) string { + who := "" + for _, m := range pushedLine.FindAllStringSubmatch(body, -1) { + who = m[1] + } + return who +} + +// authorOf is a delivery's author as the operator reads it: "the author of ", and the session that pushed it +// when its description names one ("who on node": the router refuses an @ in its words). +func authorOf(d *Delivery) string { + who := "the author of " + d.Branch + if d.Branch == "" { + who = "its author" + } + if d.PushedBy != "" { + who += " (" + strings.Replace(d.PushedBy, "@", " on ", 1) + ")" + } + return who +} + // reviewWords is what the delivery's review record says of its head, for the ask: reviewed by whom, or, first, that it // is not reviewed at this head (the ask is held then, ADR 0496). ok is whether it is reviewed at this head. func reviewWords(d *Delivery) (words string, ok bool) { diff --git a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/ready.go b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/ready.go index 77737660..b68d1017 100644 --- a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/ready.go +++ b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/ready.go @@ -35,7 +35,9 @@ import ( // delivery (Ready), said in its log, and the merge's transitions name the Approve as their warrant. // readyRefusedFor is how long the merge tool may refuse an approved head before it is said as stalled: none (issue 1115) — -// a refusal is said at once, and the merge is asked again at each event that can change it, with no timer. +// a refusal is said at once, and the merge is asked again at each event that can change it, with no timer. A refusal the +// gate is already answering (its trunk moved and its check was asked again) is said only once that check answered and +// the merge is still refused, or twice the repository's last check time passed (novox/hq ADR 0505 §4, `answering`). const readyRefusedFor time.Duration = 0 // groupRefusedFor is how long the merge tool may refuse a closed group's member before it is said as stalled: none (issue 1115). @@ -92,6 +94,11 @@ type ReadyRun struct { RepeatTrunk string `json:"repeat_trunk,omitempty"` // RefusedSince is when the merge tool began refusing it without a break. RefusedSince *time.Time `json:"refused_since,omitempty"` + // FirstRefusedOn and LastRefusedOn are when the verdict the merge was asked on was heard, at the first refusal of + // the run of refusals and at the last: a later one than the first is a fresh check answered and refused again + // (novox/hq ADR 0505 §4). + FirstRefusedOn time.Time `json:"first_refused_on,omitzero"` + LastRefusedOn time.Time `json:"last_refused_on,omitzero"` // Merged is when the merge tool merged it. Merged *time.Time `json:"merged,omitempty"` // Failed is why it is not merged and will not be on this head: its check failed. Said once on the pull request. @@ -473,15 +480,25 @@ func (h *Holder) readyLines(now time.Time) []StalledLine { Bound: headHeardBound.String(), H2: "none: a later announcement of the pull request's head (the merge tool announces it again, the forge's announcer restarts, or a new push) or an edit of its description; a recheck does not fill it — the operator's", Says: fmt.Sprintf("%s#%d passed its checks at %s and waits for %s", d.Repository, d.Number, shortOf(r.Head, 12), waitsForHead)}) case r.Failed != "" && d.State == Rejected: - out = append(out, StalledLine{ID: d.ID, Number: d.Number, State: d.State, For: now.Sub(r.Seen).Round(time.Second).String(), - Bound: "0s", H2: "none: a new head, or a recheck that passes — the operator's", - Says: fmt.Sprintf("%s#%d passed its checks at %s and is not merged: %s", d.Repository, d.Number, - shortOf(r.Head, 12), r.Failed)}) + // Its cure is its author's new head: listed here at once (`show`), told on the pull request at once, and the + // operator's only once no new head came within the author's bound (novox/hq ADR 0505 §5). + if now.Sub(d.Since) < h.authorBound() { + continue + } + out = append(out, StalledLine{ID: d.ID, Number: d.Number, State: d.State, For: now.Sub(d.Since).Round(time.Second).String(), + Bound: h.authorBound().String(), H2: "none: a new head from its author, or a recheck that passes", + Needs: NeedsNewHead, Author: authorOf(d), Branch: d.Branch, + Says: fmt.Sprintf("%s#%d passed its checks at %s and is not merged: %s. It needs a new head from %s, "+ + "and none came for %s", d.Repository, d.Number, shortOf(r.Head, 12), r.Failed, authorOf(d), + now.Sub(d.Since).Round(time.Minute))}) case r.Refused != "": out = append(out, StalledLine{ID: d.ID, Number: d.Number, State: d.State, For: now.Sub(r.Seen).Round(time.Second).String(), Bound: "0s", H2: "none: a new head, which asks the operator again — the operator's", Says: fmt.Sprintf("%s#%d at %s is not merged: the operator's answer %s", d.Repository, d.Number, shortOf(r.Head, 12), r.Refused)}) + case h.answering(d, now): + // The trunk moved and its check was asked again: the gate is answering it, so it is no stall yet (ADR 0505 + // §4). `show` lists the refusal meanwhile. case r.RefusedSince != nil && d.Group != "" && h.groupClosed(d.Group) && now.Sub(*r.RefusedSince) >= groupRefusedFor: // A closed group's member (novox/hq ADR 0418 §3, issue 1082): its sibling merged, and its own merge is refused // again after each composed check. Said after the merge window, with the group and the tool's last answer. @@ -542,6 +559,22 @@ func neededOf(d *Delivery) string { return ". Needed: the refusal's cause is met (the merge is asked again at each verdict, status or Approve), or the operator decides." } +// answering is whether an approved head the merge tool refused is one the gate is already answering, and so not said as +// stalled yet (novox/hq ADR 0505 §4): refused only because its trunk moved, its check asked again, and neither has that +// check answered with the merge refused again after it, nor has twice the repository's last check time (at least the +// floor) passed since the refusals began. Any other refusal of this head, and a refusal repeated past its limit, is said +// at once (r.Urgent). Under the lock. +func (h *Holder) answering(d *Delivery, now time.Time) bool { + r := d.Ready + if r == nil || r.RefusedSince == nil || r.Urgent || !outOfDateRefusal(r.Answer) { + return false + } + if r.LastRefusedOn.After(r.FirstRefusedOn) { + return false // its fresh check answered, and the merge was refused again on it + } + return now.Sub(*r.RefusedSince) < h.answeredRefusalBound(d.Repository) +} + // outOfDateFor is how long a refusal for an out of date verdict is a warning before it is urgent (issue 1275, AC6). const outOfDateFor = 10 * time.Minute diff --git a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/settings.go b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/settings.go new file mode 100644 index 00000000..8bda6e77 --- /dev/null +++ b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/settings.go @@ -0,0 +1,83 @@ +package main + +// The gate's settings (novox/hq ADR 0505 §4, §5), merged by the mesh into one JSON file the env names. Each has a +// default here, so a gate started without the file, or with a value it cannot read, keeps the decided bound and says +// why once. + +import ( + "encoding/json" + "errors" + "fmt" + "os" + "time" +) + +const ( + // DefaultRefusalFloor is the least a refusal the gate is already answering (the trunk moved and its check was + // asked again) waits before it is said as stalled, when the setting refusal-stall-floor-minutes gives none. + DefaultRefusalFloor = 10 * time.Minute + // DefaultAuthorBound is how long a delivery whose cure is its author's new head waits for one before the operator + // hears of it, when the setting author-new-head-minutes gives none (ADR 0505 §5). + DefaultAuthorBound = 2 * time.Hour +) + +// Settings are the operator's values for this module. +type Settings struct { + RefusalFloorMinutes *int `json:"refusal-stall-floor-minutes"` + AuthorBoundMinutes *int `json:"author-new-head-minutes"` +} + +// readSettings reads the settings file; a value that is not a whole number of minutes, one or more, is refused. +func readSettings(path string) (Settings, error) { + var s Settings + if path == "" { + return s, errors.New("started without a settings file") + } + raw, err := os.ReadFile(path) + if err != nil { + return s, err + } + var loose map[string]any + if err := json.Unmarshal(raw, &loose); err != nil { + return s, fmt.Errorf("the settings file is not JSON: %v", err) + } + for name, into := range map[string]**int{"refusal-stall-floor-minutes": &s.RefusalFloorMinutes, + "author-new-head-minutes": &s.AuthorBoundMinutes} { + switch v := loose[name].(type) { + case nil: + case float64: + n := int(v) + if v < 1 || v != float64(n) { + return Settings{}, fmt.Errorf("%s is not a whole number of minutes, one or more", name) + } + *into = &n + default: + return Settings{}, fmt.Errorf("%s is not a number", name) + } + } + return s, nil +} + +// minutesOr is a setting's minutes, or the default when it gives none. +func minutesOr(n *int, def time.Duration) time.Duration { + if n == nil { + return def + } + return time.Duration(*n) * time.Minute +} + +// refusalFloor is the least an answered refusal waits before it is said as stalled (ADR 0505 §4). +func (h *Holder) refusalFloor() time.Duration { + if h.Settings == nil { + return DefaultRefusalFloor + } + return minutesOr(h.Settings().RefusalFloorMinutes, DefaultRefusalFloor) +} + +// authorBound is how long a delivery that needs its author's new head waits before the operator hears of it (§5). +func (h *Holder) authorBound() time.Duration { + if h.Settings == nil { + return DefaultAuthorBound + } + return minutesOr(h.Settings().AuthorBoundMinutes, DefaultAuthorBound) +} diff --git a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/verbs.go b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/verbs.go index 3545cfcd..b20ecf9a 100644 --- a/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/verbs.go +++ b/modules/mesh-delivery-gate/cmd/mesh-delivery-gate/verbs.go @@ -233,8 +233,16 @@ type StalledLine struct { Says string `json:"says"` // Severity is "urgent" for a group that is held or half merged (issue 1275); empty otherwise. Severity string `json:"severity,omitempty"` + // Needs is NeedsNewHead for a delivery whose cure is its author's new head (novox/hq ADR 0505 §5), with Author + // naming that author as the operator reads it and Branch its pull request's branch; empty otherwise. + Needs string `json:"needs,omitempty"` + Author string `json:"author,omitempty"` + Branch string `json:"branch,omitempty"` } +// NeedsNewHead is what a stalled line needs when its cure is its author's new head (ADR 0505 §5). +const NeedsNewHead = "new-head" + // Stalled is the `stalled` verb: what the controller's self-check raises as `delivery..stalled`. func (h *Holder) Stalled() []StalledLine { h.mu.Lock() diff --git a/modules/mesh-delivery-gate/files/settings.json b/modules/mesh-delivery-gate/files/settings.json new file mode 100644 index 00000000..848f5158 --- /dev/null +++ b/modules/mesh-delivery-gate/files/settings.json @@ -0,0 +1,4 @@ +{ + "refusal-stall-floor-minutes": 10, + "author-new-head-minutes": 120 +} diff --git a/modules/mesh-delivery-gate/module.json b/modules/mesh-delivery-gate/module.json index a80fad26..d3faa1dd 100644 --- a/modules/mesh-delivery-gate/module.json +++ b/modules/mesh-delivery-gate/module.json @@ -84,6 +84,24 @@ "tools": [ "delivery_status" ], + "config": { + "refusal-stall-floor-minutes": { + "type": "number", + "description": "minutes, at least, before a merge refused because its trunk moved, whose check the gate asked again, is said as stalled; twice the repository's last check time when that is longer (ADR 0505 §4).", + "minimum": 1, + "maximum": 1440, + "trusted": false, + "default": 10 + }, + "author-new-head-minutes": { + "type": "number", + "description": "minutes a delivery that needs its author's new head (a conflict, a failed check, a rejected group) waits for one before the operator hears of it (ADR 0505 §5).", + "minimum": 1, + "maximum": 10080, + "trusted": false, + "default": 120 + } + }, "resources": [ { "id": "state", @@ -91,6 +109,18 @@ "mode": "0700", "place": ".", "unknown": "program" + }, + { + "id": "settings", + "type": "file", + "path": "${dir:state}/settings.json", + "mode": "0600", + "takes-config": [ + "refusal-stall-floor-minutes", + "author-new-head-minutes" + ], + "merge": "json", + "template": "files/settings.json" } ], "build": { @@ -104,7 +134,15 @@ "binary": "mesh-delivery-gate", "loads": [ "mesh-delivery-gate" - ] + ], + "env": { + "MESH_DELIVERY_GATE_SETTINGS": "${dir:state}/settings.json" + } + }, + { + "name": "files", + "kind": "archive", + "from": "files" } ] } diff --git a/modules/messenger/README.md b/modules/messenger/README.md index 5a5a26ba..0fbd1a41 100644 --- a/modules/messenger/README.md +++ b/modules/messenger/README.md @@ -190,17 +190,28 @@ the next minute's sweep. history. An event that cannot be read is refused by name, counted, and told to the operator once an hour. -## While a delivery walks (novox/hq ADR 0308) +## While a delivery walks (novox/hq ADR 0308, ADR 0505) The controller's `plan-moved` says each walk's start and end: `walk`, `phase` (`started`, `ended`), `touches` -(`[{machine, modules}]`: what it moves and what a moved tool runner or node-engine carries), `outcome` +(`[{machine, modules, declared}]`: what it moves and what a moved tool runner or node-engine carries, and, marked +`declared`, a machine it sends nothing to whose declaration its merges change), `outcome` (`delivered`, `failed`, `stopped`), `bound_seconds` and `budget_class` (`cmd/messenger/walks.go`). -- **Held:** while a walk is open and within its bound, a message whose subject is a machine it touches, or a +- **Held:** while a walk is open and within its bound and settle, a message whose subject is a machine it touches, or a module it touches (on a machine it touches, when the subject names one), is held: kept on the walk with when and what, and the history says `held`. A message several open walks touch is told when the last ends or passes its bound. At a walk's end, a later open walk that touches a message takes it over only as a first hold would: - still open, not silenced, not said since, and not one that is never held. + still open, not silenced, not said since, and not one that is never held. The controller's own lease, bus and + health conditions (`core.controller.…`, `bus.controller.…`) are about the module `mesh-controller`, wherever a + walk moves it (ADR 0505 §2). +- **The settle (ADR 0505 §3, §6):** a walk that ended delivered holds on for the setting `settle-seconds` + (120 by default): what it touched stays held, a condition raised then on what it touched is held too, and its + end is told when the settle has passed. A walk that failed or stopped is told at once; for its settle after + that, a condition on what it touched is sent at once, never held. +- **The delivery line (ADR 0505 §1):** every problem's message (raised, asked, reopened, escalated, reminded; not + a clearing, a silencing, a plain notice or an ask's own message) ends, after its since-when line, with "During + the delivery of to .", " after the delivery of to , which + succeeded/failed/was stopped." or "No delivery running.", by the walks that touch its subject. - **Never held:** an ask waiting for the operator (and a condition an open ask is about), a secret given or replaced, a subject no open walk touches, and a walk's own failure (a plan, walk, delivery or build). - **The end is one message:** the outcome, the modules and machines reached, how long; each held message still @@ -209,7 +220,7 @@ The controller's `plan-moved` says each walk's start and end: `walk`, `phase` (` only once the message was sent there. Until then each is kept owed in the state (`owed`): a message lost with a restart before it was sent leaves them untold and owed, and the restarted router says each on its own. A record that clears owes nothing more. -- **The bound:** at its start plus `bound_seconds` (900 when not given), what is held and still open is said, +- **The bound:** at its start plus `bound_seconds` (900 when not given) plus its settle (ADR 0505 §7), what is held and still open is said, with "The walk … is still running, since HH:MM", and the cleared counted; the walk holds nothing more. A walk whose end never comes is forgotten a day after it started. A start heard after its end opens nothing: the controller's moments are compared on its own clock, never with one capped at the router's now. @@ -221,6 +232,7 @@ The controller's `plan-moved` says each walk's start and end: `walk`, `phase` (` said in it; not given, the zone of the machine this runs on. **The kinds that say only what needs the operator**, as a setting: `{"only-what-needs-me": [""]}`. A walk that delivered with nothing held and nothing open is not told on them (ADR 0308 §4); empty by default. + **The settle**, as a setting: `{"settle-seconds": 120}`: how long a delivered walk still holds (ADR 0505 §3). 2. **The channels**: assign `telegram` and `desk-channel` (each says in its README what it needs). Linking an account as the operator is done on the channel, never by a setting. diff --git a/modules/messenger/cmd/messenger/adr505_bus_test.go b/modules/messenger/cmd/messenger/adr505_bus_test.go new file mode 100644 index 00000000..440ca55e --- /dev/null +++ b/modules/messenger/cmd/messenger/adr505_bus_test.go @@ -0,0 +1,86 @@ +//go:build integration + +package main + +import ( + "encoding/json" + "strings" + "testing" + "time" +) + +// novox/hq ADR 0505 over the real bus, in the bed of condition_bus_test.go: the router whole, its walks kept in its +// state, the controller's walk and condition events handed to it as the runtime hands them. + +// controllerEvent hands the bundle one of the controller's events, as the runtime does. +func (b *conditionBed) controllerEvent(t *testing.T, event string, body any) { + t.Helper() + raw, err := json.Marshal(body) + if err != nil { + t.Fatal(err) + } + if _, err := b.r.request("mesh/event", map[string]any{"envelope": map[string]any{"key": ControllerSeat + "." + event, + "node": "test", "body": json.RawMessage(raw)}}); err != nil { + t.Fatal(err) + } +} + +// walkEvent is a plan-moved body as the controller says a walk's start or end (mesh-controller walk_said.go), with a +// machine it sends nothing to and whose declaration its merges change (`declared`, ADR 0505 §2b). +func walkEvent(phase, outcome string, started, at time.Time) map[string]any { + b := map[string]any{"id": "plan-bus", "state": "walking", "walk": "plan-bus", "phase": phase, "budget_class": "leaf", + "bound_seconds": 600, "started_at": started.UTC().Format(time.RFC3339Nano), + "touches": []map[string]any{{"machine": "novox", "modules": []string{"gitea"}}, + {"machine": "shanks", "modules": []string{"mesh-build-image"}, "declared": true}}} + if phase == WalkEnded { + b["outcome"], b["ended_at"] = outcome, at.UTC().Format(time.RFC3339Nano) + } + return b +} + +// conditionEvent is a condition as the controller raises it (mesh-controller probes.go D1, signals.go). +func conditionEvent(key, scope, id, machine, headline string) map[string]any { + now := time.Now().UTC().Format(time.RFC3339) + return map[string]any{"key": key, "kind": key[strings.LastIndex(key, ".")+1:], "severity": Urgent, + "subject": map[string]string{"scope": scope, "id": id, "machine": machine}, "summary": headline, + "headline": headline, "explanation": "Needs you: look at it. " + headline + ".", "needs": "look at it.", + "raised": now, "at": now} +} + +func (b *conditionBed) toldWith(words string) *string { + for _, m := range b.told() { + if strings.Contains(m.Title+"\n"+m.Body, words) { + text := m.Title + "\n" + m.Body + return &text + } + } + return nil +} + +// ADR 0505 §1, §2b, §3: during a walk, a condition on a machine whose declaration it changes is held, and one on an +// untouched machine reaches the desk at once ending "No delivery running."; after the walk delivered, the held one +// reaches the desk only once the settle (two seconds here) has passed, inside the walk's end message. +func TestAWalksDeclaredMachineIsHeldUntilItSettledOverTheBus(t *testing.T) { + b := newConditionBedWith(t, `{"settle-seconds": 2}`) + started := time.Now() + b.controllerEvent(t, EventPlanMoved, walkEvent(WalkStarted, "", started, started)) + b.controllerEvent(t, EventRaised, conditionEvent("machine.shanks.uncomposable", "machine", "shanks", "shanks", + "Shanks cannot get new instructions")) + b.controllerEvent(t, EventRaised, conditionEvent("machine.ace.silent", "machine", "ace", "ace", "Ace is silent")) + b.r.until("the untouched machine's condition reaches the desk with its delivery line", 15*time.Second, func() bool { + m := b.toldWith("Ace is silent") + return m != nil && strings.HasSuffix(*m, "\nNo delivery running.") + }) + if b.toldWith("Shanks cannot get new instructions") != nil { + t.Fatalf("the declared machine's condition was told during the walk") + } + b.controllerEvent(t, EventPlanMoved, walkEvent(WalkEnded, WalkDelivered, started, time.Now())) + time.Sleep(time.Second) + if b.toldWith("Shanks cannot get new instructions") != nil || b.toldWith("Delivered") != nil { + t.Fatalf("told before the settle passed: %+v", b.told()) + } + b.r.until("the walk's end tells what it held once it settled", 30*time.Second, func() bool { + m := b.toldWith("Still open after the delivery of gitea to novox:") + return m != nil && strings.Contains(*m, "Shanks cannot get new instructions") && !strings.Contains(*m, "shanks,") + }) +} diff --git a/modules/messenger/cmd/messenger/adr505_test.go b/modules/messenger/cmd/messenger/adr505_test.go new file mode 100644 index 00000000..541b0f4f --- /dev/null +++ b/modules/messenger/cmd/messenger/adr505_test.go @@ -0,0 +1,409 @@ +package main + +import ( + "os" + "path/filepath" + "strings" + "testing" + "time" +) + +// The tests of novox/hq ADR 0505 "How it is checked" for the router: what a delivery changes is held until it has +// settled, every problem message says whether a delivery ran, and a failed delivery is told at once. + +// ADR 0505 §3: the settle is a setting, settle-seconds, two minutes when none is given. +func TestTheSettleIsReadFromTheSettingsFileAndIsTwoMinutesByDefault(t *testing.T) { + read := func(body string) Settings { + p := filepath.Join(t.TempDir(), "settings.json") + if err := os.WriteFile(p, []byte(body), 0o600); err != nil { + t.Fatal(err) + } + s, err := readSettings(p) + if err != nil { + t.Fatal(err) + } + return s + } + if s := read(`{"settle-seconds": 60}`); s.SettleSeconds == nil || *s.SettleSeconds != 60 { + t.Fatalf("set: %+v", s) + } + if s := read(`{"time-zone": ""}`); s.SettleSeconds != nil { + t.Fatalf("unset: %+v", s) + } + h := &Holder{} + if got := h.settle(); got != 2*time.Minute { + t.Fatalf("no setting: settle %s, want 2m", got) + } + h.Settle = func() time.Duration { return time.Minute } + if got := h.settle(); got != time.Minute { + t.Fatalf("a setting of 60 s: settle %s, want 1m", got) + } + h.Settle = func() time.Duration { return 0 } + if got := h.settle(); got != 0 { + t.Fatalf("a setting of 0: settle %s, want none", got) + } +} + +// controllerConditions are the controller's own conditions as it raises them: the lease's (mesh-controller +// signals.go watchLease: scope core, id controller.lease, the machine its host names, which need not be a node's +// name) and the bus's (reconnects.go: scope bus, id the bus user). +func controllerConditions(c *clock) []Condition { + lease := cond("core.controller.lease.lost", Urgent, "the controller lost its lease") + lease.ID, lease.Machine, lease.Raised = "controller.lease", "a-host-name", c.now() + bus := cond("bus.controller.bus-reconnects", Urgent, "the controller reconnects to the bus") + bus.Raised = c.now() + health := cond("module.controller.unhealthy", Urgent, "the controller is not healthy") + health.Raised = c.now() + return []Condition{lease, bus, health} +} + +// ADR 0505 §2a: the controller's lease, bus and health conditions are held while a walk moving mesh-controller is +// open, whatever name their keys give the controller and whatever host they name. +func TestTheControllersOwnConditionsAreHeldWhileAWalkMovesMeshController(t *testing.T) { + h, tg, dt, c, _ := newHolder(t) + walk(t, h, "plan-c", WalkStarted, "", c.now(), 1200, novox("mesh-controller")) + for _, k := range controllerConditions(c) { + h.Condition(EventRaised, k) + } + runFor(h, c, time.Minute) + if saidOn(tg, dt) != 0 { + t.Fatalf("the controller's own conditions were said during its delivery: %+v %+v", tg.sends, dt.sends) + } + for _, k := range controllerConditions(c) { + if !has(outcomes(h, k.Key), "held") { + t.Errorf("%s was not held: %v", k.Key, outcomes(h, k.Key)) + } + } +} + +// ADR 0505 §2a: a walk that does not move mesh-controller holds none of them. +func TestTheControllersOwnConditionsAreNotHeldByAWalkOfAnotherModule(t *testing.T) { + h, tg, dt, c, _ := newHolder(t) + walk(t, h, "plan-g", WalkStarted, "", c.now(), 1200, Touch{Machine: "ace", Modules: []string{"gitea"}}) + for _, k := range controllerConditions(c) { + h.Condition(EventRaised, k) + } + runFor(h, c, time.Minute) + for _, k := range controllerConditions(c) { + if has(outcomes(h, k.Key), "held") || !heard(headlineOf(k.Key), tg, dt) { + t.Errorf("%s was held by a walk of gitea, or not said: %v", k.Key, outcomes(h, k.Key)) + } + } +} + +// shanksDeclared is a touch as the controller says a machine whose declaration the walk's merges change and to which +// it sends nothing (mesh-controller walk_said.go walkTouch, `declared`, ADR 0505 §2b). +var shanksDeclared = Touch{Machine: "shanks", Modules: []string{"mesh-build-image"}, Declared: true} + +// ADR 0505 §2b: a machine whose declaration a walk's merges change is held like a machine it sends to, and is not +// named among the machines the walk reached. +func TestAMachineWhoseDeclarationTheWalkChangesIsHeldAndNotNamedAsReached(t *testing.T) { + ev, ok, err := DecodeWalk([]byte(`{"id":"plan-d","walk":"plan-d","phase":"started","budget_class":"leaf",` + + `"bound_seconds":600,"touches":[{"machine":"novox","modules":["gitea"]},` + + `{"machine":"shanks","modules":["mesh-build-image"],"declared":true}]}`)) + if err != nil || !ok || len(ev.Touches) != 2 || !ev.Touches[1].Declared || ev.Touches[0].Declared { + t.Fatalf("a declared touch was not read: %+v %v %v", ev.Touches, ok, err) + } + h, tg, dt, c, _ := newHolder(t) + walk(t, h, "plan-d", WalkStarted, "", c.now(), 600, novox("gitea"), shanksDeclared) + k := cond("machine.shanks.uncomposable", Urgent, "shanks cannot get new instructions") + k.Machine, k.Raised = "shanks", c.now() + h.Condition(EventRaised, k) + runFor(h, c, time.Minute) + if !has(outcomes(h, k.Key), "held") || heard(headlineOf(k.Key), tg, dt) { + t.Fatalf("a condition on the declared machine was not held: %v", outcomes(h, k.Key)) + } + if got := touchWords(mergeTouches([]Touch{novox("gitea"), shanksDeclared}, nil)); got != "gitea on novox" { + t.Fatalf("what the walk reached reads %q, want only novox", got) + } + if got := mergeTouches([]Touch{shanksDeclared}, []Touch{{Machine: "shanks", Modules: []string{"buildah"}}}); got[0].Declared { + t.Fatalf("a machine the walk also sends to stayed declared: %+v", got) + } +} + +// ADR 0505 §3: a condition raised 30 seconds after a delivered walk's end, on what it touched, is held; at the end +// plus the settle the end message tells it under "after the delivery of …" when it is still open, and only counts +// it when it cleared. +func TestAConditionRaisedInTheSettleIsHeldAndToldAtItsEnd(t *testing.T) { + for _, clears := range []bool{false, true} { + h, tg, dt, c, _ := newHolder(t) + walk(t, h, "plan-s", WalkStarted, "", c.now(), 600, novox("gitea")) + runFor(h, c, 3*time.Minute) + walk(t, h, "plan-s", WalkEnded, WalkDelivered, c.now(), 0, novox("gitea")) + c.pass(30 * time.Second) + k := cond("machine.novox.uncomposable", Urgent, "novox cannot get new instructions") + k.Machine, k.Raised = "novox", c.now() + h.Condition(EventRaised, k) + runFor(h, c, time.Minute) + if heard(headlineOf(k.Key), tg, dt) || !has(outcomes(h, k.Key), "held") { + t.Fatalf("raised in the settle and not held: %v", outcomes(h, k.Key)) + } + if heard("Delivered", tg, dt) { + t.Fatalf("the end was told before the settle passed: %+v", dt.sends) + } + if clears { + h.Condition(EventCleared, Condition{Key: k.Key, At: c.now()}) + } + runFor(h, c, time.Minute) + switch { + case !clears && !heard("Still open after the delivery of gitea to novox:\n- Urgent: "+headlineOf(k.Key), tg, dt): + t.Fatalf("still open at the settle's end and not told under the delivery: %+v", dt.sends) + case clears && (heard(headlineOf(k.Key), tg, dt) || !heard("1 problem it raised resolved during it.", dt)): + t.Fatalf("cleared in the settle: told, or not counted: %+v", dt.sends) + } + } +} + +// ADR 0505 §3: a reminder of an older condition that falls on a touched subject while a walk is open is held like +// any other message, and told at the settle's end only when the condition is still open. +func TestAReminderDuringAWalkIsHeld(t *testing.T) { + h, tg, dt, c, _ := newHolder(t) + k := cond("machine.novox.network", Urgent, "novox lost its default route") + k.Raised = c.now() + h.Condition(EventRaised, k) + runFor(h, c, time.Minute) + first := saidOn(tg, dt) + if first == 0 { + t.Fatalf("the condition was not said before the walk") + } + runFor(h, c, RemindUrgent-3*time.Minute) + walk(t, h, "plan-r", WalkStarted, "", c.now(), 1200, novox("node-tools")) + runFor(h, c, 5*time.Minute) + if saidOn(tg, dt) != first { + t.Fatalf("the reminder was said during the walk: %+v", dt.sends) + } + if !has(outcomes(h, k.Key), "held") { + t.Fatalf("the reminder was not held: %v", outcomes(h, k.Key)) + } + walk(t, h, "plan-r", WalkEnded, WalkDelivered, c.now(), 0) + runFor(h, c, DefaultSettle+time.Minute) + if !heard("Still open after the delivery of node-tools to novox:", dt) { + t.Fatalf("the held reminder was not told at the settle's end: %+v", dt.sends) + } +} + +// ADR 0505 §3: a router that starts again while a walk settles holds on and tells its end once the settle passed. +func TestAWalkThatSettlesSurvivesARouterRestart(t *testing.T) { + h, tg, dt, c, st := newHolder(t) + walk(t, h, "plan-x", WalkStarted, "", c.now(), 1200, novox("mesh-tools")) + runFor(h, c, time.Minute) + walk(t, h, "plan-x", WalkEnded, WalkDelivered, c.now(), 0) + c.pass(10 * time.Second) + again := &Holder{Away: tg, Desk: dt, Store: st, Now: c.now, Logf: t.Logf} + if err := again.Load(); err != nil { + t.Fatal(err) + } + again.Start() + k := cond("machine.novox.tools-silent", Urgent, "the tools on novox are silent") + k.Raised = c.now() + again.Condition(EventRaised, k) + runFor(again, c, time.Minute) + if heard(headlineOf(k.Key), tg, dt) { + t.Fatalf("not held by the settling walk read back: %v", outcomes(again, k.Key)) + } + runFor(again, c, DefaultSettle) + if !heard("Still open after the delivery of mesh-tools to novox:\n- Urgent: "+headlineOf(k.Key), tg, dt) { + t.Fatalf("the settled walk's end was not told after the restart: %+v", dt.sends) + } + walk(t, again, "plan-x", WalkStarted, "", c.now().Add(-5*time.Minute), 1200, novox("mesh-tools")) + if len(again.walks) != 0 { + t.Fatalf("its late start opened it again: %+v", again.walks) + } +} + +// ADR 0505 §6: a condition raised on a touched subject 30 seconds after a failed walk is sent at once, even while +// another open walk touches the same machine; the same condition after a delivered walk is held. +func TestAConditionJustAfterAFailedWalkIsSentAtOnceAndAfterADeliveredOneHeld(t *testing.T) { + for _, outcome := range []string{WalkFailed, WalkStopped, WalkDelivered} { + h, tg, dt, c, _ := newHolder(t) + walk(t, h, "plan-f", WalkStarted, "", c.now(), 600, novox("gitea")) + walk(t, h, "plan-o", WalkStarted, "", c.now(), 1200, novox("mesh-issues")) + runFor(h, c, 2*time.Minute) + walk(t, h, "plan-f", WalkEnded, outcome, c.now(), 0, novox("gitea")) + runFor(h, c, 30*time.Second) + k := cond("machine.novox.uncomposable", Urgent, "novox cannot get new instructions") + k.Machine, k.Raised = "novox", c.now() + h.Condition(EventRaised, k) + runFor(h, c, 30*time.Second) + sent := heard(headlineOf(k.Key), tg, dt) + if outcome != WalkDelivered && !sent { + t.Fatalf("after a walk that %s, held: %v", outcome, outcomes(h, k.Key)) + } + if outcome == WalkDelivered && sent { + t.Fatalf("after a delivered walk, sent at once: %+v", dt.sends) + } + } +} + +// ADR 0505 §6: an urgent condition on a machine no open or settling walk touches is sent at once during a walk. +func TestAnUrgentConditionOnAnUntouchedMachineIsSentAtOnceDuringAWalk(t *testing.T) { + h, tg, dt, c, _ := newHolder(t) + walk(t, h, "plan-u", WalkStarted, "", c.now(), 1200, novox("gitea")) + k := cond("machine.ace.silent", Urgent, "ace has not been heard") + k.Machine, k.Raised = "ace", c.now() + h.Condition(EventRaised, k) + if !heard(headlineOf(k.Key), tg, dt) { + t.Fatalf("held, while no walk touches ace: %v", outcomes(h, k.Key)) + } +} + +// bodyOf is a held or open record's message as it would be sent now. +func bodyOf(t *testing.T, h *Holder, key, what string) string { + t.Helper() + h.mu.Lock() + r := h.open[key] + h.mu.Unlock() + if r == nil { + t.Fatalf("%s is not open", key) + } + return h.say(r, what).Body +} + +// ADR 0505 §1: a problem's message ends, after its since-when line, with the delivery line: during a walk, in a +// walk's settle, after a failed walk, and with no walk. +func TestEveryProblemMessageEndsWithWhetherADeliveryRan(t *testing.T) { + h, tg, dt, c, _ := newHolder(t) + k := cond("machine.novox.tools-silent", Urgent, "the tools on novox are silent") + k.Raised = c.now() + h.Condition(EventRaised, k) + if !strings.HasSuffix(tg.sends[0].Body, ".\nNo delivery running.") || !strings.Contains(tg.sends[0].Body, "\nSince ") { + t.Fatalf("no walk: %q", tg.sends[0].Body) + } + walk(t, h, "plan-l", WalkStarted, "", c.now(), 600, novox("gitea", "mesh-issues"), shanksDeclared) + if b := bodyOf(t, h, k.Key, "reminder"); !strings.HasSuffix(b, ".\nDuring the delivery of gitea, mesh-issues to novox.") { + t.Fatalf("during a walk: %q", b) + } + runFor(h, c, time.Minute) + walk(t, h, "plan-l", WalkEnded, WalkDelivered, c.now(), 0) + c.pass(40 * time.Second) + if b := bodyOf(t, h, k.Key, "raised"); !strings.HasSuffix(b, "\n40 s after the delivery of gitea, mesh-issues to novox, which succeeded.") { + t.Fatalf("in the settle of a delivered walk: %q", b) + } + runFor(h, c, 3*time.Minute) + if b := bodyOf(t, h, k.Key, "reminder"); !strings.HasSuffix(b, "\nNo delivery running.") { + t.Fatalf("after the settle: %q", b) + } + walk(t, h, "plan-m", WalkStarted, "", c.now(), 600, novox("gitea")) + walk(t, h, "plan-m", WalkEnded, WalkFailed, c.now(), 0) + c.pass(30 * time.Second) + if b := bodyOf(t, h, k.Key, "reminder"); !strings.HasSuffix(b, "\n30 s after the delivery of gitea to novox, which failed.") { + t.Fatalf("after a failed walk: %q", b) + } + keyless(t, dt.sends...) + // Not on a clearing, a silencing or a plain notice. + for _, what := range []string{"cleared", "silenced", "tell"} { + if carriesDeliveryLine(&Record{Origin: "condition"}, what) { + t.Errorf("a %s message carries the delivery line", what) + } + } + if carriesDeliveryLine(&Record{Origin: "ask"}, "raised") { + t.Errorf("an ask's own message carries the delivery line") + } +} + +// ADR 0505 §1: the line names at most six modules and counts the rest, and says no name the content rule refuses. +func TestTheDeliveryLineNamesAtMostSixModulesAndNothingTheRuleRefuses(t *testing.T) { + many := novox("a1", "a2", "a3", "a4", "a5", "a6", "a7", "a8") + if got := deliveryWords([]Touch{many}); got != "a1, a2, a3, a4, a5, a6 and 2 more to novox" { + t.Fatalf("eight modules: %q", got) + } + h, _, _, c, _ := newHolder(t) + walk(t, h, "plan-p", WalkStarted, "", c.now(), 600, novox("/var/lib/mesh-tools")) + k := cond("machine.novox.tools-silent", Urgent, "the tools on novox are silent") + k.Raised = c.now() + h.Condition(EventRaised, k) + if b := bodyOf(t, h, k.Key, "raised"); !strings.HasSuffix(b, "\nDuring a delivery.") { + t.Fatalf("a refused name in the line: %q", b) + } +} + +// ADR 0505 §7: a condition on a machine whose declaration three back-to-back walks change (a machine that stays +// behind is a declared touch of each) reaches the operator at the first walk's bound and settle, while the third +// still runs: never held walk after walk. +func TestADeclaredMachinesConditionAcrossThreeWalksIsSaidAtTheFirstWalksLimit(t *testing.T) { + h, tg, dt, c, _ := newHolder(t) + t0 := c.now() + walk(t, h, "plan-1", WalkStarted, "", c.now(), 600, novox("gitea"), shanksDeclared) // limit: t0 + 10 + 2 min + k := cond("machine.shanks.uncomposable", Urgent, "shanks cannot get new instructions") + k.Machine, k.Raised = "shanks", c.now() + h.Condition(EventRaised, k) + runFor(h, c, 5*time.Minute) + walk(t, h, "plan-1", WalkEnded, WalkDelivered, c.now(), 0, novox("gitea"), shanksDeclared) + runFor(h, c, time.Minute) + walk(t, h, "plan-2", WalkStarted, "", c.now(), 600, novox("mesh-issues"), shanksDeclared) + runFor(h, c, 3*time.Minute) + walk(t, h, "plan-2", WalkEnded, WalkDelivered, c.now(), 0, novox("mesh-issues"), shanksDeclared) + runFor(h, c, time.Minute) + walk(t, h, "plan-3", WalkStarted, "", c.now(), 1200, novox("gitea"), shanksDeclared) + for c.now().Before(t0.Add(12*time.Minute - 10*time.Second)) { + runFor(h, c, 5*time.Second) + } + if heard(headlineOf(k.Key), tg, dt) { + t.Fatalf("said before the first walk's limit: %+v", dt.sends) + } + runFor(h, c, 30*time.Second) + if !heard(headlineOf(k.Key), tg, dt) { + t.Fatalf("held past the first walk's bound and settle: %v", outcomes(h, k.Key)) + } +} + +// ADR 0505 §2: a walk's start or end said again by the controller with its declared machines (declared_read) acts +// once: one walk with both sayings' touches, and one end message. +func TestAWalkSaidAgainWithItsDeclaredMachinesActsOnce(t *testing.T) { + h, tg, dt, c, _ := newHolder(t) + walk(t, h, "plan-r", WalkStarted, "", c.now(), 600, novox("gitea")) + walk(t, h, "plan-r", WalkStarted, "", c.now(), 600, novox("gitea"), shanksDeclared) + if len(h.walks) != 1 || len(h.walks["plan-r"].Touches) != 2 { + t.Fatalf("said again it is not one walk with both touches: %+v", h.walks) + } + runFor(h, c, time.Minute) + walk(t, h, "plan-r", WalkEnded, WalkFailed, c.now(), 0, novox("gitea")) + walk(t, h, "plan-r", WalkEnded, WalkFailed, c.now(), 0, novox("gitea"), shanksDeclared) + runFor(h, c, 3*time.Minute) + n := 0 + for _, m := range append(append([]Message(nil), dt.sends...), tg.sends...) { + if strings.HasPrefix(m.Title, "Delivery failed") { + n++ + } + } + if n != 1 { + t.Fatalf("its end was told %d times: %+v", n, dt.sends) + } +} + +// ADR 0505 §7: a message two walks first held, the sooner of which ends at its limit, is said exactly once — in that +// walk's end message — and not again on its own for the other walk; once per channel when it is urgent. +func TestAMessageTwoWalksFirstHeldIsSaidOnceAtTheSoonerLimit(t *testing.T) { + for _, sev := range []string{Warning, Urgent} { + h, tg, dt, c, _ := newHolder(t) + walk(t, h, "plan-a", WalkStarted, "", c.now(), 360, novox("gitea")) // its limit: 6 min and the settle + walk(t, h, "plan-b", WalkStarted, "", c.now(), 1200, novox("mesh-issues")) // its limit: 22 min + k := cond("machine.novox.network", sev, "novox lost its default route") + k.Raised = c.now() + h.Condition(EventRaised, k) + runFor(h, c, 7*time.Minute) + walk(t, h, "plan-a", WalkEnded, WalkDelivered, c.now(), 0) // settles until its limit, 8 min after the hold + runFor(h, c, 3*time.Minute) + count := func(ch *fakeChannel) int { + n := 0 + for _, m := range ch.sends { + if strings.Contains(m.Text(), headlineOf(k.Key)) { + n++ + } + } + return n + } + want := map[*fakeChannel]int{dt: 1, tg: 0} + if sev == Urgent { + want[tg] = 1 + } + for ch, n := range want { + if got := count(ch); got != n { + t.Fatalf("%s: said %d times on %s, want %d: %+v", sev, got, ch.name, n, ch.sends) + } + } + if !heard("Still open after the delivery of gitea to novox:", dt) { + t.Fatalf("%s: not told in the sooner walk's end message: %+v", sev, dt.sends) + } + } +} diff --git a/modules/messenger/cmd/messenger/bus_test.go b/modules/messenger/cmd/messenger/bus_test.go index 6e34d5eb..9c67bda6 100644 --- a/modules/messenger/cmd/messenger/bus_test.go +++ b/modules/messenger/cmd/messenger/bus_test.go @@ -56,6 +56,8 @@ type busRuntime struct { subscribed, taking bool buckets map[string]jetstream.KeyValue + // settings is the settings file the bundle starts with; empty is `{}`. + settings string } func newBusRuntime(t *testing.T) *busRuntime { @@ -130,7 +132,11 @@ func (r *busRuntime) request(method string, params any) (json.RawMessage, error) func (r *busRuntime) start(dir string) { r.t.Helper() settings := filepath.Join(dir, "settings.json") - _ = os.WriteFile(settings, []byte(`{}`), 0o600) + body := r.settings + if body == "" { + body = `{}` + } + _ = os.WriteFile(settings, []byte(body), 0o600) cmd := exec.Command(os.Args[0], "-test.run=^$") cmd.Env = append(os.Environ(), bundleVar+"=1", "MESH_MESSENGER_SETTINGS="+settings, "MESH_MESSENGER_STATE="+dir, "MESH_SERVED_MODULE=messenger", "MESH_MODULE=messenger", "MESH_NODE=test") diff --git a/modules/messenger/cmd/messenger/condition_bus_test.go b/modules/messenger/cmd/messenger/condition_bus_test.go index 69dd1739..9057315a 100644 --- a/modules/messenger/cmd/messenger/condition_bus_test.go +++ b/modules/messenger/cmd/messenger/condition_bus_test.go @@ -28,8 +28,15 @@ type conditionBed struct { } func newConditionBed(t *testing.T) *conditionBed { + t.Helper() + return newConditionBedWith(t, "") +} + +// newConditionBedWith is the bed with the bundle started on these settings. +func newConditionBedWith(t *testing.T, settings string) *conditionBed { t.Helper() b := &conditionBed{r: newBusRuntime(t)} + b.r.settings = settings b.r.setKinds(map[string][]string{"desktop": {"choice", "edit"}}) if _, err := b.r.nc.Subscribe("mesh.seat."+asks.ChannelSeat+".accept.*.desktop", func(m *nats.Msg) { var msg asks.Message diff --git a/modules/messenger/cmd/messenger/deliveryline.go b/modules/messenger/cmd/messenger/deliveryline.go new file mode 100644 index 00000000..29be208e --- /dev/null +++ b/modules/messenger/cmd/messenger/deliveryline.go @@ -0,0 +1,78 @@ +package main + +// The delivery line (novox/hq ADR 0505 §1): every message about a problem — a condition or a module's notice, +// raised, asked, reopened, escalated or reminded — ends, after its since-when line, with whether a delivery was +// running on what it is about: +// +// - "During the delivery of to ." when an open walk touches its subject; +// - " after the delivery of to , which ." when a walk that touched it ended within +// its settle (a delivered walk settling, a failed or stopped one in the two minutes after it, §6); +// - "No delivery running." otherwise. +// +// The line is this router's, from the walks it keeps (ADR 0308 §1); no producer adds it. It names modules and +// machines as the operator says them, never an id, and is judged by the content rule with the rest of the body. + +import ( + "sort" + "time" +) + +// NoDeliveryLine is the delivery line of a message no walk touches. +const NoDeliveryLine = "No delivery running." + +// outcomeWords are a walk's outcome as the delivery line says it. +var outcomeWords = map[string]string{WalkDelivered: "succeeded", WalkFailed: "failed", WalkStopped: "was stopped"} + +// carriesDeliveryLine says whether a message of a record says the delivery line: a problem's message, and not its +// clearing, its silencing, a plain notice or an ask's own message. +func carriesDeliveryLine(r *Record, what string) bool { + switch what { + case "cleared", "silenced", "tell": + return false + } + return r.Origin != "ask" +} + +// deliveryLine is the line for a record's message at a moment. +func (h *Holder) deliveryLine(r *Record, now time.Time) string { + s := subjectOf(r) + h.mu.Lock() + defer h.mu.Unlock() + h.init() + var during, after []*Walk + for _, w := range h.walks { + if !w.touches(s) { + continue + } + switch { + case w.settling() && now.Before(w.SettleUntil) && !now.Before(w.Ended): + after = append(after, w) + case !w.settling(): + during = append(during, w) // open, within its bound or past it (ADR 0505 §7) + } + } + if len(during) > 0 { + sort.Slice(during, func(i, j int) bool { return during[i].Started.Before(during[j].Started) }) + return plainly("During the delivery of "+deliveryWords(during[0].Touches)+".", "During a delivery.") + } + if f := h.failedJustNow(s, now); f != nil { + after = append(after, f) + } + if len(after) == 0 { + return NoDeliveryLine + } + sort.Slice(after, func(i, j int) bool { return after[i].Ended.After(after[j].Ended) }) + w := after[0] + ago := roughly(now.Sub(w.Ended)) + return plainly(ago+" after the delivery of "+deliveryWords(w.Touches)+", which "+outcomeWords[w.Outcome]+".", + ago+" after a delivery, which "+outcomeWords[w.Outcome]+".") +} + +// plainly is a line when the content rule lets it leave the mesh, else the same said without the names that it +// refused, so the line never withholds the message it ends. +func plainly(line, without string) string { + if _, ok := Check(line); ok { + return line + } + return without +} diff --git a/modules/messenger/cmd/messenger/holder.go b/modules/messenger/cmd/messenger/holder.go index 076fc270..a2dcfaf3 100644 --- a/modules/messenger/cmd/messenger/holder.go +++ b/modules/messenger/cmd/messenger/holder.go @@ -327,6 +327,9 @@ type Holder struct { // CapPerHour is the most messages one channel gets an hour (the setting messages-per-hour, issue 1476); // nil, or a value below zero, is DefaultCapPerHour; 0 is no cap at all. TellCapPerHour is its own and stays fixed. CapPerHour func() int + // Settle is how long a delivered walk holds what it touched after its end (the setting settle-seconds, novox/hq + // ADR 0505 §3); nil is DefaultSettle. + Settle func() time.Duration work sync.Mutex // one event, call or tick at a time mu sync.Mutex // what the status reads @@ -840,6 +843,7 @@ func (h *Holder) Flush() { now := h.Now() h.mu.Unlock() h.duePasses(now) + h.settledWalks(now) // a settle's end is told at the next flush, not the next minute (ADR 0505 §3) h.flush(now, false) } @@ -1050,11 +1054,21 @@ func (h *Holder) words(r *Record, what string) Message { // rule judges the message as it is sent. func (h *Holder) composeTracked(r *Record, what string, now time.Time, withhold int) (Message, string) { m := compose(r, what, now, h.zone(), withhold) - if !h.tracksAsked() || withhold >= 2 { - return m, "" + line := "" + if h.tracksAsked() && withhold < 2 { + issues, known := h.trackedBy(r.Key) + m, line = withTracking(m, r, what, issues, known, now, h.zone()) } - issues, known := h.trackedBy(r.Key) - return withTracking(m, r, what, issues, known, now, h.zone()) + if withhold < 2 && carriesDeliveryLine(r, what) { + // Last, after the since-when line, the delivery line (ADR 0505 §1): judged with the body by the content rule. + dl := h.deliveryLine(r, now) + if m.Body == "" { + m.Body = dl + } else { + m.Body += "\n" + dl + } + } + return m, line } // allowedWords is the message the content rule leaves of a record: its own words when they may leave the diff --git a/modules/messenger/cmd/messenger/main.go b/modules/messenger/cmd/messenger/main.go index 5fbfa29b..57bccaaa 100644 --- a/modules/messenger/cmd/messenger/main.go +++ b/modules/messenger/cmd/messenger/main.go @@ -35,6 +35,9 @@ type Settings struct { // MessagesPerHour is the most messages one channel gets in an hour (issue 1476); 0, not given, is // DefaultCapPerHour; 0 is no cap at all. MessagesPerHour *int `json:"messages-per-hour"` + // SettleSeconds is how long a delivered walk still holds what it touched after its end (novox/hq ADR 0505 §3): + // nil, not given, is DefaultSettle; 0 holds nothing after the end. + SettleSeconds *int `json:"settle-seconds"` } // zoneOf is the location a time-zone setting names, or this machine's own when it names none or one @@ -90,6 +93,17 @@ func readSettings(path string) (Settings, error) { default: return s, fmt.Errorf("only-what-needs-me is not a list of channel kinds") } + switch v := loose["settle-seconds"].(type) { + case nil: + case float64: + n := int(v) + if v < 0 || v != float64(n) { + return s, fmt.Errorf("settle-seconds is not a whole number of zero or more") + } + s.SettleSeconds = &n + default: + return s, fmt.Errorf("settle-seconds is not a number") + } return s, nil } @@ -351,6 +365,12 @@ func main() { } return DefaultCapPerHour }, + Settle: func() time.Duration { + if n := settings().SettleSeconds; n != nil && *n >= 0 { + return time.Duration(*n) * time.Second + } + return DefaultSettle + }, NeedsOnly: func(kind string) bool { for _, k := range settings().OnlyWhatNeedsMe { if k == kind { diff --git a/modules/messenger/cmd/messenger/outbox.go b/modules/messenger/cmd/messenger/outbox.go index b8b2c880..496e5a7f 100644 --- a/modules/messenger/cmd/messenger/outbox.go +++ b/modules/messenger/cmd/messenger/outbox.go @@ -39,6 +39,11 @@ func (h *Holder) deliver(r *Record, what string) { // An open walk touches it: told when the walk ends or passes its bound (ADR 0308 §2). return } + h.route(r, what) +} + +// route sends a record's message where its severity routes it, held by no walk. +func (h *Holder) route(r *Record, what string) { var to []Channel if kinds := h.askKinds(r); len(kinds) > 0 { // An ask goes to every channel that carries one of its answers (novox/hq ADR 0259): the desk for an diff --git a/modules/messenger/cmd/messenger/walks.go b/modules/messenger/cmd/messenger/walks.go index 365937f7..ada2b575 100644 --- a/modules/messenger/cmd/messenger/walks.go +++ b/modules/messenger/cmd/messenger/walks.go @@ -42,6 +42,13 @@ package main // that the walk is still running and since when, and the cleared ones counted; it holds nothing more after // that. A walk whose end never comes is forgotten a day after it started. // +// **The settle (novox/hq ADR 0505 §3, §7).** A walk that ended delivered holds on, settling, for the setting +// settle-seconds (two minutes): what it touched stays held, a condition raised then on what it touched is held with +// it, and its end is told when the settle has passed. A walk that failed or stopped is told at once. The bound of +// §5 runs with the settle added: an open walk holds at most its bound and its settle. What a walk touches includes +// the machines whose declaration its merges change (`declared` touches, §2) and, for a walk that moves +// mesh-controller, the controller's own lease, bus and health conditions. +// // **Kept in the module's state** (the bucket `walks`, one key per walk), so a router that restarts mid-walk // holds and tells as if it had not. @@ -68,6 +75,9 @@ const ( // DefaultWalkBound is a walk's bound when the controller gives none: the bound of a walk none of whose // deliveries has a budget (ADR 0308 §5). DefaultWalkBound = 15 * time.Minute + // DefaultSettle is how long a delivered walk still holds what it touched after its end when the setting + // settle-seconds gives none: the longest the first-node gate holds a healthy module (novox/hq ADR 0505 §3, ADR 0352). + DefaultSettle = 2 * time.Minute // WalkForget: a walk whose end never came is forgotten this long after it started. WalkForget = 24 * time.Hour // WalkEndWhat is the outbox's name for a walk's end or bound message: it goes alone, never in a digest. @@ -76,10 +86,25 @@ const ( MostNamed = 6 ) +// settle is how long a delivered walk still holds after its end (ADR 0505 §3). +func (h *Holder) settle() time.Duration { + if h.Settle == nil { + return DefaultSettle + } + if d := h.Settle(); d >= 0 { + return d + } + return DefaultSettle +} + // Touch is what a walk moves on one machine. type Touch struct { Machine string `json:"machine"` Modules []string `json:"modules"` + // Declared: the walk sends nothing to this machine, but its merges change the machine's declaration (an + // assignment, a provision or a requirement added or removed, ADR 0505 §2b). Held like any touch; never named + // among the machines the walk reached. + Declared bool `json:"declared,omitempty"` } // WalkEvent is a walk's start or end as the controller says it. @@ -100,8 +125,15 @@ type WalkEvent struct { type HeldMessage struct { At time.Time `json:"at"` What string `json:"what"` + // Until is the first hold's limit: the start, bound and settle of the walk that first held it, or that walk's + // settle's end when it was held settling (ADR 0505 §7). Kept when it is handed on: no walk holds it past this, so a + // fault on a machine walk after walk touches reaches the operator all the same. Zero in a hold kept before it was. + Until time.Time `json:"until,omitzero"` } +// past says whether a held message's first hold's limit has passed. +func (hm HeldMessage) past(now time.Time) bool { return !hm.Until.IsZero() && !now.Before(hm.Until) } + // Walk is one open walk as this router keeps it. type Walk struct { ID string `json:"id"` @@ -117,6 +149,13 @@ type Walk struct { // EndedSaid is the end's moment as the controller said it, by the controller's clock and never capped at // this router's now: a start heard after its end is compared with it on that one clock (issue 538 C). EndedSaid time.Time `json:"ended_said,omitempty"` + // SettleSeconds is the settle taken at its start (the setting settle-seconds, ADR 0505 §3): the hold of an open + // walk lasts its bound and this (§7), and a delivered walk holds this long after its end. + SettleSeconds int `json:"settle_seconds,omitempty"` + // SettleUntil is set on a walk that ended delivered and still holds, settling, until then (ADR 0505 §3); Outcome + // is how it ended. Its end is told when SettleUntil passes. + SettleUntil time.Time `json:"settle_until,omitempty"` + Outcome string `json:"outcome,omitempty"` } func (w *Walk) bound() time.Duration { @@ -126,9 +165,27 @@ func (w *Walk) bound() time.Duration { return time.Duration(w.BoundSeconds) * time.Second } -// holding says whether the walk still holds at a moment: open, and within its bound. +// settleFor is the settle the walk took at its start. +func (w *Walk) settleFor() time.Duration { return time.Duration(w.SettleSeconds) * time.Second } + +// limit is the longest a walk holds anything: its start, its bound and its settle (ADR 0505 §7). +func (w *Walk) limit() time.Time { return w.Started.Add(w.bound() + w.settleFor()) } + +// holdEnd is the last moment the walk holds anything it holds now: its limit, or its settle's end when that is +// sooner. +func (w *Walk) holdEnd() time.Time { + if w.settling() && w.SettleUntil.Before(w.limit()) { + return w.SettleUntil + } + return w.limit() +} + +// settling says whether the walk ended delivered and holds on until its settle has passed (ADR 0505 §3). +func (w *Walk) settling() bool { return !w.SettleUntil.IsZero() } + +// holding says whether the walk still holds at a moment: open or settling, and within its bound and settle. func (w *Walk) holding(now time.Time) bool { - return !w.BoundSaid && now.Before(w.Started.Add(w.bound())) + return !w.BoundSaid && now.Before(w.limit()) && (!w.settling() || now.Before(w.SettleUntil)) } // touches says whether the walk touches a subject: a machine it sends to, or — when the subject names no @@ -141,7 +198,7 @@ func (w *Walk) touches(s subject) bool { } } } - if s.machineNamed { + if s.machineNamed && !s.controller { return false } for _, t := range w.Touches { @@ -215,9 +272,10 @@ func DecodeWalk(body []byte) (WalkEvent, bool, error) { } if v, ok := raw["touches"]; ok && string(v) != "null" { var list []struct { - Machine string `json:"machine"` - Node string `json:"node"` - Modules []string `json:"modules"` + Machine string `json:"machine"` + Node string `json:"node"` + Modules []string `json:"modules"` + Declared bool `json:"declared"` } if json.Unmarshal(v, &list) != nil { return WalkEvent{}, false, fmt.Errorf("walk %s: touches is not a list of {machine, modules}", ev.Walk) @@ -228,7 +286,7 @@ func DecodeWalk(body []byte) (WalkEvent, bool, error) { m = t.Node } if m != "" { - ev.Touches = append(ev.Touches, Touch{Machine: m, Modules: t.Modules}) + ev.Touches = append(ev.Touches, Touch{Machine: m, Modules: t.Modules, Declared: t.Declared}) } } } @@ -252,9 +310,11 @@ func DecodeWalk(body []byte) (WalkEvent, bool, error) { return ev, true, nil } -// mergeTouches is what two sayings of a walk's touches name together. +// mergeTouches is what two sayings of a walk's touches name together. A machine is declared only while no saying +// sends to it (ADR 0505 §2b). func mergeTouches(a, b []Touch) []Touch { by := map[string]map[string]bool{} + sent := map[string]bool{} var order []string for _, list := range [][]Touch{a, b} { for _, t := range list { @@ -265,6 +325,9 @@ func mergeTouches(a, b []Touch) []Touch { for _, m := range t.Modules { by[t.Machine][m] = true } + if !t.Declared { + sent[t.Machine] = true + } } } sort.Strings(order) @@ -275,7 +338,7 @@ func mergeTouches(a, b []Touch) []Touch { mods = append(mods, m) } sort.Strings(mods) - out = append(out, Touch{Machine: machine, Modules: mods}) + out = append(out, Touch{Machine: machine, Modules: mods, Declared: !sent[machine]}) } return out } @@ -294,7 +357,8 @@ func (h *Holder) Walked(ev WalkEvent) { } switch ev.Phase { case WalkStarted: - w := &Walk{ID: ev.Walk, Started: at, BoundSeconds: ev.BoundSeconds, Class: ev.Class} + w := &Walk{ID: ev.Walk, Started: at, BoundSeconds: ev.BoundSeconds, Class: ev.Class, + SettleSeconds: int(h.settle() / time.Second)} h.mu.Lock() end := h.ended[ev.Walk] h.mu.Unlock() @@ -324,6 +388,13 @@ func (h *Holder) Walked(ev WalkEvent) { case WalkEnded: h.mu.Lock() w := h.walks[ev.Walk] + if w != nil && w.settling() { + // Its end said again while it settles: the same end, its touches as both sayings name them. + w.Touches = mergeTouches(w.Touches, ev.Touches) + h.mu.Unlock() + h.keepWalk(w) + return + } if w != nil && !ev.StartedAt.IsZero() && w.Started.After(ev.StartedAt) { // The end of an earlier walk under the same id, heard after the next one started: that one stays open. h.mu.Unlock() @@ -332,18 +403,38 @@ func (h *Holder) Walked(ev WalkEvent) { return } if w != nil { - delete(h.walks, ev.Walk) w.Touches = mergeTouches(w.Touches, ev.Touches) if !ev.StartedAt.IsZero() { w.Started = ev.StartedAt } } - tomb := &Walk{ID: ev.Walk, Started: ev.StartedAt, Ended: at, EndedSaid: ev.At} + tomb := &Walk{ID: ev.Walk, Started: ev.StartedAt, Ended: at, EndedSaid: ev.At, Outcome: ev.Outcome, + Touches: mergeTouches(ev.Touches, nil)} + if w != nil { + tomb.Touches, tomb.SettleSeconds = w.Touches, w.SettleSeconds + } if prev := h.ended[ev.Walk]; prev != nil && prev.Ended.After(at) { tomb = prev } h.ended[ev.Walk] = tomb + settles := w != nil && ev.Outcome == WalkDelivered && !w.BoundSaid && w.settleFor() > 0 + if settles { + // Delivered: it holds on, settling, until its settle has passed and never past its limit (ADR 0505 §3, §7). + w.Ended, w.EndedSaid, w.Outcome = at, ev.At, ev.Outcome + w.SettleUntil = at.Add(w.settleFor()) + if l := w.limit(); w.SettleUntil.After(l) { + w.SettleUntil = l + } + } else if w != nil { + delete(h.walks, ev.Walk) + } h.mu.Unlock() + if settles { + h.keepWalk(w) // settling, in place of the open walk: read back as settling after a restart + h.record(Sent{At: now, Channel: "-", Key: "walk." + ev.Walk, What: "ended " + ev.Outcome, + Outcome: "settling: holding what it touched until " + w.SettleUntil.In(h.zone()).Format("15:04:05")}) + return + } h.keepWalk(tomb) // in place of the open walk: a start heard after this end opens nothing if w == nil { h.Logf("[messenger] walk %s %s, and its start was not heard here: nothing held, nothing said", ev.Walk, ev.Outcome) @@ -408,11 +499,12 @@ func (h *Holder) release(w *Walk, now time.Time) (open []*Record, whats map[stri if o.ID == w.ID || !o.holding(now) { continue } - if _, ok := o.Held[key]; ok { - elsewhere = true + if other, ok := o.Held[key]; ok { + elsewhere = elsewhere || !other.past(now) continue } - if live && o.touches(s) { + if live && o.touches(s) && !hm.past(now) { + // Handed on with its first hold's limit: never held past it (ADR 0505 §7). if o.Held == nil { o.Held = map[string]HeldMessage{} } @@ -456,7 +548,11 @@ func (h *Holder) release(w *Walk, now time.Time) (open []*Record, whats map[stri // endWalk tells a walk's end once (ADR 0308 §4). func (h *Holder) endWalk(w *Walk, outcome string, ended, now time.Time) { open, whats, cleared := h.release(w, now) - if now.Sub(ended) > FreshFor && len(open) == 0 { + due := ended + if w.settling() { + due = w.SettleUntil + } + if now.Sub(due) > FreshFor && len(open) == 0 { h.Logf("[messenger] walk %s %s %s ago, heard late: history, nothing said (%d held cleared meanwhile)", w.ID, outcome, roughly(now.Sub(ended)), cleared) h.record(Sent{At: now, Channel: "-", Key: "walk." + w.ID, What: "ended " + outcome, Outcome: "quiet: heard late"}) @@ -474,17 +570,102 @@ func (h *Holder) endWalk(w *Walk, outcome string, ended, now time.Time) { m = Message{Title: head + ": " + reached + ", in " + roughly(took), Quiet: true} } else { lines := []string{"It took " + roughly(took) + "."} - lines = append(lines, h.heldLines(open, whats, cleared)...) + lines = append(lines, h.heldLines(open, whats, cleared, "Still open after the delivery of "+deliveryWords(w.Touches)+":")...) m = Message{Title: head + ": " + reached, Body: strings.Join(lines, "\n")} } h.tellWalk(w, m, open, whats, oneLine, "ended "+outcome, now) } +// settledWalks tells the end of every delivered walk whose settle has passed (ADR 0505 §3), oldest first. +func (h *Holder) settledWalks(now time.Time) { + h.overdueHolds(now) + h.mu.Lock() + var settled []*Walk + for _, w := range h.walks { + if w.settling() && !now.Before(w.SettleUntil) { + settled = append(settled, w) + } + } + h.mu.Unlock() + sort.Slice(settled, func(i, j int) bool { return settled[i].SettleUntil.Before(settled[j].SettleUntil) }) + for _, w := range settled { + h.endSettled(w, now) + } +} + +// overdueHolds says every held message whose first hold's limit has passed while a walk that took it over still holds, +// on its own, with its delivery line (ADR 0505 §7): no walk holds it past that limit. A walk whose own end or bound is +// due tells what it holds in its message instead. Called at each flush. +func (h *Holder) overdueHolds(now time.Time) { + h.mu.Lock() + // What a walk whose own end or bound is due holds is told in that walk's message, and nowhere else: one place + // says it, so a message two walks hold is never said twice. + tellsItself := map[string]bool{} + for _, w := range h.walks { + if !now.Before(w.holdEnd()) { + for key := range w.Held { + tellsItself[key] = true + } + } + } + due := map[string]HeldMessage{} + var touched []*Walk + for _, w := range h.walks { + changed := false + if !now.Before(w.holdEnd()) { + continue // its own end or bound tells what it holds, in its message + } + for key, hm := range w.Held { + if hm.past(now) { + if prev, ok := due[key]; !tellsItself[key] && (!ok || hm.At.Before(prev.At)) { + due[key] = hm + } + delete(w.Held, key) + changed = true + } + } + if changed { + touched = append(touched, w) + } + } + var recs []*Record + for key, hm := range due { + if r := h.open[key]; r != nil && r.Cleared.IsZero() && !r.silenced(now) && !lastSaid(r).After(hm.At) { + recs = append(recs, r) + } + } + h.mu.Unlock() + for _, w := range touched { + h.keepWalk(w) + } + sort.Slice(recs, func(i, j int) bool { return recs[i].Key < recs[j].Key }) + for _, r := range recs { + what := due[r.Key].What + h.record(Sent{At: now, Channel: "-", Key: r.Key, What: what, Outcome: "released: past its first hold's limit"}) + h.route(r, what) + } +} + +// endSettled tells the end of a delivered walk whose settle has passed (ADR 0505 §3): what it held still open, one +// line each, and the cleared counted; then it is only the tomb that keeps a late start from opening it again. +func (h *Holder) endSettled(w *Walk, now time.Time) { + h.mu.Lock() + delete(h.walks, w.ID) + tomb := h.ended[w.ID] + if tomb == nil { + tomb = &Walk{ID: w.ID, Started: w.Started, Ended: w.Ended, EndedSaid: w.EndedSaid} + h.ended[w.ID] = tomb + } + h.mu.Unlock() + h.keepWalk(tomb) + h.endWalk(w, w.Outcome, w.Ended, now) +} + // heldLines are the lines a walk's end or bound says of what it held: each still open, then the cleared count. -func (h *Holder) heldLines(open []*Record, whats map[string]string, cleared int) []string { +func (h *Holder) heldLines(open []*Record, whats map[string]string, cleared int, heading string) []string { var lines []string if len(open) > 0 { - lines = append(lines, "Still open after it:") + lines = append(lines, heading) for _, r := range open { what := whats[r.Key] if what == "" { @@ -510,7 +691,7 @@ func (h *Holder) boundWalks(now time.Time) { var due, gone []*Walk var stale []string for _, w := range h.walks { - if !w.BoundSaid && !now.Before(w.Started.Add(w.bound())) { + if !w.settling() && !w.BoundSaid && !now.Before(w.limit()) { due = append(due, w) } if now.Sub(w.Started) >= WalkForget { @@ -543,6 +724,7 @@ func (h *Holder) boundWalks(now time.Time) { h.forgetWalk(w.ID) } }() + h.settledWalks(now) sort.Slice(due, func(i, j int) bool { return due[i].Started.Before(due[j].Started) }) for _, w := range due { h.mu.Lock() @@ -562,7 +744,7 @@ func (h *Holder) boundWalks(now time.Time) { if _, ok := Check(lines[0]); !ok { lines[0] = "The walk is still running, since " + since + "." } - lines = append(lines, h.heldLines(open, whats, cleared)...) + lines = append(lines, h.heldLines(open, whats, cleared, "Still open after it:")...) m := Message{Title: "Still running: the delivery to " + touchWords(w.Touches), Body: strings.Join(lines, "\n")} h.tellWalk(w, m, open, whats, false, "past its bound", now) } @@ -670,6 +852,9 @@ func touchWords(touches []Touch) string { mods := map[string]bool{} var machines []string for _, t := range touches { + if t.Declared { + continue // its declaration changed; nothing was sent to it (ADR 0505 §2b) + } machines = append(machines, t.Machine) for _, m := range t.Modules { mods[m] = true @@ -690,6 +875,37 @@ func touchWords(touches []Touch) string { return listed(names) + " on " + listed(machines) } +// deliveryWords names a delivery as the operator says it: its modules, then "to" the machines it sent them to +// (ADR 0505 §1); a machine whose declaration alone changed is not among them. +func deliveryWords(touches []Touch) string { + mods := map[string]bool{} + var machines []string + for _, t := range touches { + if t.Declared { + continue + } + machines = append(machines, t.Machine) + for _, m := range t.Modules { + mods[m] = true + } + } + var names []string + for m := range mods { + names = append(names, m) + } + sort.Strings(names) + sort.Strings(machines) + switch { + case len(names) == 0 && len(machines) == 0: + return "nothing" + case len(machines) == 0: + return listed(names) + case len(names) == 0: + return "its builds to " + listed(machines) + } + return listed(names) + " to " + listed(machines) +} + // listed is at most MostNamed names, then how many more. func listed(names []string) string { if len(names) <= MostNamed { @@ -705,8 +921,18 @@ type subject struct { machineNamed bool // tokens are every name it carries, to tell a message about a walk itself. tokens []string + // controller: the subject is the controller itself — its lease, its bus connection, its health — matched to the + // module mesh-controller wherever a walk moves it, whatever machine or host the condition names (ADR 0505 §2a). + controller bool } +// controllerNames are the names the controller's own conditions give it in their keys (`core.controller.lease.lost`, +// `bus.controller.bus-reconnects`, `module.controller...`): each is the module ControllerModule (ADR 0505 §2a). +var controllerNames = map[string]bool{"controller": true, ControllerModule: true} + +// ControllerModule is the controller's module, as a walk that moves it names it. +const ControllerModule = "mesh-controller" + // subjectOf is a record's subject: a condition's scope and id (`..` when the record kept no // subject of its own), a notice's subject words. func subjectOf(r *Record) subject { @@ -728,6 +954,11 @@ func subjectOf(r *Record) subject { if r.Machine != "" { s.machines, s.machineNamed = append(s.machines, r.Machine), true } + if (scope == "core" || scope == "bus" || scope == "module" || scope == "seat") && len(tokens) > 0 && controllerNames[tokens[0]] { + // The controller's own subject: the module mesh-controller, wherever it runs (ADR 0505 §2a). + s.modules, s.controller = append(s.modules, ControllerModule), true + return s + } switch scope { case "machine", "node", "bus": s.machines, s.machineNamed = append(s.machines, tokens[0]), true @@ -797,6 +1028,33 @@ func (h *Holder) hold(r *Record, what string) bool { now := h.Now() h.mu.Lock() s := subjectOf(r) + if f := h.failedJustNow(s, now); f != nil { + // A failure is the case the operator most needs the cause of: sent at once, with its delivery line (ADR 0505 §6). + h.mu.Unlock() + h.record(Sent{At: now, Channel: "-", Key: r.Key, What: what + ", " + roughly(now.Sub(f.Ended)) + " after walk " + f.ID + " " + f.Outcome, + Outcome: "not held: its walk " + f.Outcome}) + return false + } + // The first hold's limit: kept by whichever walk holds it now, else the soonest end of the walks about to. + var until time.Time + for _, w := range h.walks { + if hm, ok := w.Held[r.Key]; ok && !hm.Until.IsZero() && (until.IsZero() || hm.Until.Before(until)) { + until = hm.Until + } + } + if until.IsZero() { + for _, w := range h.walks { + if w.holding(now) && w.touches(s) && (until.IsZero() || w.holdEnd().Before(until)) { + until = w.holdEnd() + } + } + } + if !until.IsZero() && !now.Before(until) { + // Held to its first hold's limit already: said now, with its delivery line (ADR 0505 §7). + h.mu.Unlock() + h.record(Sent{At: now, Channel: "-", Key: r.Key, What: what, Outcome: "not held: past its first hold's limit"}) + return false + } var by []*Walk var ids []string fresh := false @@ -805,7 +1063,7 @@ func (h *Holder) hold(r *Record, what string) bool { continue } prev, had := w.Held[r.Key] - hm := HeldMessage{At: now, What: what} + hm := HeldMessage{At: now, What: what, Until: until} if had { hm.At = prev.At if !r.told() && prev.What == "raised" { @@ -837,6 +1095,32 @@ func (h *Holder) hold(r *Record, what string) bool { return true } +// failedJustNow is the walk that failed or stopped within its settle and touched a subject (ADR 0505 §6): nothing +// on it is held then. Under the lock. +func (h *Holder) failedJustNow(s subject, now time.Time) *Walk { + var newest *Walk + for _, e := range h.ended { + if e.Outcome != WalkFailed && e.Outcome != WalkStopped { + continue + } + if now.Before(e.Ended) || !now.Before(e.Ended.Add(h.settleOf(e))) || !e.touches(s) { + continue + } + if newest == nil || e.Ended.After(newest.Ended) { + newest = e + } + } + return newest +} + +// settleOf is the settle a walk took at its start, or the setting's for one kept before it was. +func (h *Holder) settleOf(w *Walk) time.Duration { + if w.SettleSeconds > 0 { + return w.settleFor() + } + return h.settle() +} + // heldBy is the walks holding a record now. func (h *Holder) heldBy(key string, now time.Time) []string { var ids []string @@ -886,6 +1170,16 @@ func (h *Holder) loadWalks() error { } for i := range walks { w := walks[i] + if !w.Ended.IsZero() && w.settling() { + // Settling when the router stopped: it holds on until its settle has passed, and its end keeps a late + // start from opening it again (ADR 0505 §3). + if w.Held == nil { + w.Held = map[string]HeldMessage{} + } + h.walks[w.ID] = &w + h.ended[w.ID] = &Walk{ID: w.ID, Started: w.Started, Ended: w.Ended, EndedSaid: w.EndedSaid} + continue + } if !w.Ended.IsZero() { h.ended[w.ID] = &w continue diff --git a/modules/messenger/cmd/messenger/walks_test.go b/modules/messenger/cmd/messenger/walks_test.go index a7b86909..84fd2e33 100644 --- a/modules/messenger/cmd/messenger/walks_test.go +++ b/modules/messenger/cmd/messenger/walks_test.go @@ -131,7 +131,7 @@ func TestAMessageTouchedByTwoOverlappingWalksIsHeldUntilTheSecondEnds(t *testing h.Condition(EventRaised, k) runFor(h, c, time.Minute) walk(t, h, "plan-a", WalkEnded, WalkDelivered, c.now(), 0, novox("mesh-tools")) - runFor(h, c, time.Minute) + runFor(h, c, DefaultSettle+time.Minute) // its end is told once it settled (ADR 0505 §3) if heard(headlineOf(k.Key), tg, dt) { t.Fatalf("said at the first walk's end, while the second still holds it: %+v %+v", tg.sends, dt.sends) } @@ -139,8 +139,8 @@ func TestAMessageTouchedByTwoOverlappingWalksIsHeldUntilTheSecondEnds(t *testing t.Fatalf("the first walk's end was not told: %+v", dt.sends) } walk(t, h, "plan-b", WalkEnded, WalkDelivered, c.now(), 0) - runFor(h, c, time.Minute) - if !heard("Still open after it:\n- Urgent: "+headlineOf(k.Key), tg, dt) { + runFor(h, c, DefaultSettle+time.Minute) + if !heard("Still open after the delivery of node-tools to ace, novox:\n- Urgent: "+headlineOf(k.Key), tg, dt) { t.Fatalf("the second walk's end did not tell it: telegram %+v, desk %+v", tg.sends, dt.sends) } } @@ -222,7 +222,7 @@ func TestAWalksEndIsToldOnceWithWhatIsStillOpen(t *testing.T) { if m.Title != "Delivery failed: mesh-tools on novox" || !strings.Contains(m.Body, "It took 7 min.") { t.Fatalf("the end does not say its outcome, what it reached and how long: %q", m.Text()) } - want := "Still open after it:\n- " + headlineOf(still.Key) + "\n- Urgent: " + headlineOf(other.Key) + + want := "Still open after the delivery of mesh-tools to novox:\n- " + headlineOf(still.Key) + "\n- Urgent: " + headlineOf(other.Key) + "\n1 problem it raised resolved during it." if !strings.Contains(m.Body, want) || strings.Contains(m.Text(), headlineOf(gone.Key)) { t.Fatalf("the end message %q does not say %q", m.Body, want) @@ -241,7 +241,7 @@ func TestADeliveredWalkWithNothingHeldIsOneLineOrNothing(t *testing.T) { walk(t, h, "plan-4", WalkStarted, "", c.now(), 600, novox("mesh-tools"), Touch{Machine: "ace", Modules: []string{"mesh-tools"}}) runFor(h, c, 3*time.Minute) walk(t, h, "plan-4", WalkEnded, WalkDelivered, c.now(), 0) - runFor(h, c, time.Minute) + runFor(h, c, DefaultSettle+time.Minute) if len(dt.sends) != 1 || len(tg.sends) != 0 { t.Fatalf("desk %+v, telegram %+v", dt.sends, tg.sends) } @@ -252,7 +252,7 @@ func TestADeliveredWalkWithNothingHeldIsOneLineOrNothing(t *testing.T) { walk(t, h, "plan-5", WalkStarted, "", c.now(), 600, novox("mesh-tools")) runFor(h, c, 3*time.Minute) walk(t, h, "plan-5", WalkEnded, WalkDelivered, c.now(), 0) - runFor(h, c, time.Minute) + runFor(h, c, DefaultSettle+time.Minute) if len(dt.sends) != 1 || len(tg.sends) != 0 { t.Fatalf("told on a kind that says only what needs the operator: desk %+v, telegram %+v", dt.sends, tg.sends) } @@ -262,8 +262,9 @@ func TestADeliveredWalkWithNothingHeldIsOneLineOrNothing(t *testing.T) { } // §5: the bound is the controller's (bound_seconds: twice the largest budget of the walk's deliveries; none -// given, 15 minutes). At it, what is held and still open is sent with the still-running line, and what -// cleared is counted; before it, nothing; after it, the walk holds nothing more. +// given, 15 minutes), and the settle is added to it (ADR 0505 §7). At it, what is held and still open is sent +// with the still-running line, and what cleared is counted; before it, nothing; after it, the walk holds nothing +// more. func TestAHoldEndsAtTheWalksBound(t *testing.T) { for _, tc := range []struct { name string @@ -287,7 +288,7 @@ func TestAHoldEndsAtTheWalksBound(t *testing.T) { h.Condition(EventRaised, gone) c.pass(30 * time.Second) h.Condition(EventCleared, Condition{Key: gone.Key, At: c.now()}) - runFor(h, c, tc.bound-time.Minute-30*time.Second) + runFor(h, c, tc.bound+DefaultSettle-time.Minute-30*time.Second) if saidOn(tg, dt) != 0 { t.Fatalf("said before the bound: %+v %+v", tg.sends, dt.sends) } @@ -330,7 +331,7 @@ func TestHeldMessagesSurviveARouterRestart(t *testing.T) { again.Start() c.pass(2 * time.Minute) walk(t, again, "plan-8", WalkEnded, WalkDelivered, c.now(), 0) - runFor(again, c, time.Minute) + runFor(again, c, DefaultSettle+time.Minute) if !heard("- Urgent: "+headlineOf(k.Key), dt) || saidOn(tg, dt) != 2 { t.Fatalf("what was held before the restart was not told at the walk's end: desk %+v, telegram %+v", dt.sends, tg.sends) } @@ -462,7 +463,7 @@ func TestWhatAWalkHeldIsSaidOnceAChannelCanSendAgain(t *testing.T) { walk(t, h, "plan-c", WalkEnded, WalkFailed, c.now(), 0) runFor(h, c, time.Minute) } else { - runFor(h, c, 10*time.Minute) + runFor(h, c, 10*time.Minute+DefaultSettle) // the bound and the settle (ADR 0505 §7) } if saidOn(tg, dt) != 0 { t.Fatalf("said on a channel that cannot send: %+v %+v", tg.sends, dt.sends) @@ -479,11 +480,12 @@ func TestWhatAWalkHeldIsSaidOnceAChannelCanSendAgain(t *testing.T) { } } -// Review of pull request 230, 2: a message held by walk A, about a machine walk B also touches, is held on at -// A's end while B — started after it was held — is still open, and told at B's end. +// Review of pull request 230, 2, as novox/hq ADR 0505 §7 bounds it: a message held by walk A, about a machine walk B +// also touches, is held on at A's end while B — started after it was held — is still open, and is said once A's own +// limit (its start, bound and settle) has passed, while B still runs, with B's delivery line. func TestAMessageIsHeldOnByALaterWalkThatTouchesIt(t *testing.T) { h, tg, dt, c, _ := newHolder(t) - walk(t, h, "plan-a", WalkStarted, "", c.now(), 1200, novox("mesh-tools")) + walk(t, h, "plan-a", WalkStarted, "", c.now(), 360, novox("mesh-tools")) // its limit: 6 min and the settle k := cond("machine.novox.network", Urgent, "novox lost its default route") k.Raised = c.now() h.Condition(EventRaised, k) @@ -491,17 +493,16 @@ func TestAMessageIsHeldOnByALaterWalkThatTouchesIt(t *testing.T) { walk(t, h, "plan-b", WalkStarted, "", c.now(), 1200, novox("node-tools")) runFor(h, c, time.Minute) walk(t, h, "plan-a", WalkEnded, WalkDelivered, c.now(), 0) - runFor(h, c, time.Minute) + runFor(h, c, DefaultSettle+time.Minute) if heard(headlineOf(k.Key), tg, dt) { t.Fatalf("told at the first walk's end while the second touches it: %+v %+v", tg.sends, dt.sends) } if got := h.heldBy(k.Key, c.now()); len(got) != 1 || got[0] != "plan-b" { t.Fatalf("the second walk does not hold it on: %v", got) } - walk(t, h, "plan-b", WalkEnded, WalkDelivered, c.now(), 0) - runFor(h, c, time.Minute) - if !heard("Still open after it:\n- Urgent: "+headlineOf(k.Key), tg, dt) { - t.Fatalf("the second walk's end did not tell it: %+v %+v", tg.sends, dt.sends) + runFor(h, c, 4*time.Minute) // past the first walk's limit, 8 minutes after it was held + if !heard("During the delivery of node-tools to novox.", tg, dt) || !heard(headlineOf(k.Key), tg, dt) { + t.Fatalf("held past its first hold's limit: %+v %+v", tg.sends, dt.sends) } } @@ -651,7 +652,7 @@ func TestAHeldMessageIsToldOnlyOnceTheWalksMessageWasSent(t *testing.T) { tg.fail, dt.fail = nil, nil if then == "sent" { runFor(h, c, 2*time.Minute) - if !heard("Still open after it:\n- Urgent: "+headlineOf(k.Key), tg, dt) || saidOn(tg, dt) != 2 { + if !heard("Still open after the delivery of mesh-tools to novox:\n- Urgent: "+headlineOf(k.Key), tg, dt) || saidOn(tg, dt) != 2 { t.Fatalf("not told once in the walk's message: telegram %+v, desk %+v", tg.sends, dt.sends) } if r := h.open[k.Key]; r == nil || !r.told() || r.Owed != "" || r.Sent["telegram"] != "" || r.Sent["desktop"] != "" { @@ -726,7 +727,7 @@ func TestAWalksEndHandsOnOnlyWhatALaterWalkWouldHold(t *testing.T) { } before := map[string]int{quiet.Key: helds(quiet.Key), asked.Key: helds(asked.Key)} walk(t, h, "plan-a", WalkEnded, WalkDelivered, c.now(), 0) - runFor(h, c, time.Minute) + runFor(h, c, DefaultSettle+time.Minute) for _, key := range []string{quiet.Key, asked.Key} { if got := h.heldBy(key, c.now()); len(got) != 0 { t.Errorf("%s was handed on to %v, which a first hold would never hold", key, got) diff --git a/modules/messenger/cmd/messenger/words_test.go b/modules/messenger/cmd/messenger/words_test.go index f646a7cc..5403bdf4 100644 --- a/modules/messenger/cmd/messenger/words_test.go +++ b/modules/messenger/cmd/messenger/words_test.go @@ -58,7 +58,7 @@ var examples = []example{{ resolved: "openrazer delivery no longer waiting", popup: true, title: "Urgent: openrazer delivery waiting to start", body: "Needs you: start it, or stop it. The change to openrazer is merged and built, and mesh-delivery (the module " + - "that decides when a delivery goes out) has not let it start for 5 hours, so mesh-delivery may be stuck.\nNo issue tracks this yet.\nSince 12:40.", + "that decides when a delivery goes out) has not let it start for 5 hours, so mesh-delivery may be stuck.\nNo issue tracks this yet.\nSince 12:40.\nNo delivery running.", offers: "Details", choose: "Details", cleared: "Resolved: openrazer delivery no longer waiting, after 5.0 h", openFor: 5 * time.Hour, @@ -80,7 +80,7 @@ var examples = []example{{ title: "openrazer not working on g14", body: "Needs you: restart its service openrazer-daemon on g14; if it fails again, the details say why. openrazer " + "on g14 is not healthy: its service openrazer-daemon stopped with an error. It clears as soon as it runs " + - "again.\nNo issue tracks this yet.\nSince 12:40.", + "again.\nNo issue tracks this yet.\nSince 12:40.\nNo delivery running.", offers: "Details", choose: "Details", cleared: "Resolved: openrazer works again on g14, after 2.0 h", openFor: 2 * time.Hour, }, { @@ -104,7 +104,7 @@ var examples = []example{{ title: "3 failed services on shanks", body: "Needs you: mend or remove them on shanks, or silence this if they do not matter. On shanks, mnt-recalbox " + "(a mount), storage-media (a mount) and greenclip failed. No module manages them, so the mesh does not repair " + - "them.\nNo issue tracks this yet.\nSince 12:40.", + "them.\nNo issue tracks this yet.\nSince 12:40.\nNo delivery running.", offers: "Details", choose: "Details", cleared: "Resolved: no failed services on shanks any more, after 45 min", openFor: 45 * time.Minute, }, { @@ -135,7 +135,7 @@ var examples = []example{{ explanation: "Needs you: release it, or stop it. A delivery of hq has been held for 36 hours, past its limit.", resolved: "Delivery of hq is no longer held", popup: true, title: "Delivery of hq held for 36 hours", - body: "Needs you: release it, or stop it. A delivery of hq has been held for 36 hours, past its limit.\nNo issue tracks this yet.\nSince 12:40.", + body: "Needs you: release it, or stop it. A delivery of hq has been held for 36 hours, past its limit.\nNo issue tracks this yet.\nSince 12:40.\nNo delivery running.", offers: "Details", choose: "Details", cleared: "Resolved: delivery of hq is no longer held, after 3 min", openFor: 3 * time.Minute, @@ -296,7 +296,7 @@ func TestAConditionWithoutPlainWordsIsSaidFromItsSummary(t *testing.T) { Summary: "ace has not been heard from: `push ace` sends it again", Raised: c.now()} h.Condition(EventRaised, k) m := tg.sends[0] - if m.Title != "Urgent: Silent on ace" || m.Body != "Ace has not been heard from: a command sends it again\nSince 12:00." { + if m.Title != "Urgent: Silent on ace" || m.Body != "Ace has not been heard from: a command sends it again\nSince 12:00.\nNo delivery running." { t.Errorf("%q / %q", m.Title, m.Body) } keyless(t, m) diff --git a/modules/messenger/files/settings.json b/modules/messenger/files/settings.json index 6d22854a..726c29cb 100644 --- a/modules/messenger/files/settings.json +++ b/modules/messenger/files/settings.json @@ -1,5 +1,6 @@ { "time-zone": "", "only-what-needs-me": [], - "messages-per-hour": 100 + "messages-per-hour": 100, + "settle-seconds": 120 } diff --git a/modules/messenger/module.json b/modules/messenger/module.json index 60451958..d7da1d68 100644 --- a/modules/messenger/module.json +++ b/modules/messenger/module.json @@ -140,6 +140,14 @@ "maximum": 1000, "trusted": false, "default": 100 + }, + "settle-seconds": { + "type": "number", + "description": "seconds a delivery that ended well still holds the messages about what it changed, so a problem that passes as the delivery settles is not sent (ADR 0505 §3); 0 holds nothing after the end.", + "minimum": 0, + "maximum": 3600, + "trusted": false, + "default": 120 } }, "resources": [ @@ -163,7 +171,7 @@ "type": "file", "path": "${dir:state}/settings.json", "mode": "0600", - "takes-config": ["time-zone", "desktop-machines", "only-what-needs-me", "messages-per-hour"], + "takes-config": ["time-zone", "desktop-machines", "only-what-needs-me", "messages-per-hour", "settle-seconds"], "merge": "json", "template": "files/settings.json", "owner": "messenger"