mesh-catalog/modules/messenger/cmd/messenger/adr505_test.go

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