From a79972577c5ce049fb9c5e1fb273ed8f15421853 Mon Sep 17 00:00:00 2001 From: jochen Date: Tue, 6 Oct 2026 01:45:34 +0200 Subject: [PATCH] Never say a reconcile's report after a newer apply's (hq issue 267) A reconcile that held the machine to the kept declaration just before a delivery arrived queued its report while the delivery's apply waited for it; the link published the apply's report and then the reconcile's, so the mesh's last word from the machine named the older declaration and the release plan waited on a report it had already been given. The link now sets aside an unasked report about a declaration other than the one it has applied since. --- internal/link/overtaken_test.go | 94 +++++++++++++++++++++++++++++++++ internal/link/run.go | 40 ++++++++++++++ 2 files changed, 134 insertions(+) create mode 100644 internal/link/overtaken_test.go diff --git a/internal/link/overtaken_test.go b/internal/link/overtaken_test.go new file mode 100644 index 0000000..5087b27 --- /dev/null +++ b/internal/link/overtaken_test.go @@ -0,0 +1,94 @@ +package link + +import ( + "context" + "testing" + "time" +) + +// A reconcile's report about the declaration kept before a delivery is never said after that +// delivery's report (novox/hq issue 267). + +// Measured on the home server: the reconcile timer fired three seconds before a declaration +// arrived. The reconcile held the machine to the declaration kept then; the delivery's apply waited +// for it, applied the new one and was reported — and then the reconcile's report, queued meanwhile, +// went out and was stored as the machine's latest account, naming the older declaration. The +// release plan waited on a report it had already been given. +func TestAReconcileReportOlderThanTheApplyIsNotSaidAfterIt(t *testing.T) { + m, key := aMember(t) + l := newQuietLink(&said{body: signedBy(t, key, []byte(`{"declaration":2}`))}) + outbox := make(chan Unasked, 1) + + ctx, stop := context.WithCancel(context.Background()) + defer stop() + settled := make(chan bool, 1) + apply := func(context.Context, []byte, []byte) Report { + // The reconcile ran first, on what was kept then, and queued its report while this waited. + outbox <- Unasked{Report: Report{Declared: "d1", Applied: []string{"a"}, Outward: []string{"eth0"}}, + Done: func(published bool) { settled <- published; stop() }} + return Report{Declared: "d2", Applied: []string{"a", "b"}, Outward: []string{"eth0"}} + } + + done := make(chan error, 1) + go func() { done <- serve(ctx, l, m, apply, nil, time.Second, outbox, &keptInMemory{}) }() + select { + case published := <-settled: + if published { + t.Fatal("the reconcile's report was counted as said") + } + case <-time.After(5 * time.Second): + t.Fatal("the reconcile's report was never settled") + } + if err := <-done; err != nil { + t.Fatal(err) + } + reports := l.said() + if len(reports) != 1 || reports[0].Declared != "d2" { + t.Fatalf("the mesh heard %+v; it should have heard only the apply of d2", reports) + } +} + +// A reconcile's report about the declaration this link applied is news, and is said. +func TestAReconcileReportAboutTheAppliedDeclarationIsSaid(t *testing.T) { + m, key := aMember(t) + l := newQuietLink(&said{body: signedBy(t, key, []byte(`{"declaration":2}`))}) + outbox := make(chan Unasked, 1) + + ctx, stop := context.WithCancel(context.Background()) + defer stop() + settled := make(chan bool, 1) + apply := func(context.Context, []byte, []byte) Report { + outbox <- Unasked{Report: Report{Declared: "d2", Applied: []string{"a", "b"}, Firewall: "nftables"}, + Done: func(published bool) { settled <- published; stop() }} + return Report{Declared: "d2", Applied: []string{"a", "b"}} + } + + go func() { _ = serve(ctx, l, m, apply, nil, time.Second, outbox, nil) }() + select { + case published := <-settled: + if !published { + t.Fatal("a reconcile's report about the applied declaration was not said") + } + case <-time.After(5 * time.Second): + t.Fatal("the reconcile's report was never settled") + } + if reports := l.said(); len(reports) != 2 || reports[1].Declared != "d2" { + t.Fatalf("the mesh heard %+v", reports) + } +} + +func TestOvertaken(t *testing.T) { + for _, c := range []struct { + declared, applied string + want bool + }{ + {"d1", "d2", true}, + {"d2", "d2", false}, + {"", "d2", false}, // names no declaration + {"d1", "", false}, // this link has applied nothing yet + } { + if got := overtaken(Report{Declared: c.declared}, c.applied); got != c.want { + t.Errorf("overtaken(%q, %q) = %v, want %v", c.declared, c.applied, got, c.want) + } + } +} diff --git a/internal/link/run.go b/internal/link/run.go index 8832183..8230ceb 100644 --- a/internal/link/run.go +++ b/internal/link/run.go @@ -243,6 +243,10 @@ func serve(ctx context.Context, link Link, m Membership, apply Applier, say Anno defer beat.Stop() publishAlive(ctx, link, m, say, timeout) + // **The declaration this link last applied**, so a report made about an older one is not said + // after it (novox/hq issue 267). Empty until something is applied or said again here. + var applied string + // **What the last apply did, if the mesh never heard it** — said before anything newly // delivered is applied, so it can never land after, and read as newer than, a later report. if unsaid != nil { @@ -251,6 +255,7 @@ func serve(ctx context.Context, link Link, m Membership, apply Applier, say Anno say("cannot read the report this node kept unsaid: " + err.Error()) case ok: say("saying again what the last apply did: its report never reached the mesh") + applied = kept.Declared if publishReport(reporting, link, m, kept, say, timeout) { if err := unsaid.Said(kept.Declared); err != nil { say("said the kept report, and cannot forget it: " + err.Error()) @@ -275,6 +280,23 @@ func serve(ctx context.Context, link Link, m Membership, apply Applier, say Anno case unasked := <-outbox: // Said without having been asked: a reconcile found what an adopted node holds, or // its firewall, changed since it last said. + // + // **Unless a newer declaration was applied while it waited** (novox/hq issue 267). A + // reconcile that held the machine a moment before a delivery arrived made its report + // about the declaration kept then; the delivery's apply waited for it, was reported, and + // only then did this loop get round to the reconcile's — which reached the mesh last, + // named the older declaration, and was stored as the machine's latest account. The plan + // waiting on the machine then waited on a report it had already been given. What the + // reconcile saw, the newer apply has said since, and fresher; the next reconcile says + // anything that is still news. + if overtaken(unasked.Report, applied) { + say(fmt.Sprintf("set aside a reconcile's report of declaration %s: %s was applied and "+ + "reported since", short(unasked.Report.Declared), short(applied))) + if unasked.Done != nil { + unasked.Done(false) + } + continue + } published := publishReport(ctx, link, m, unasked.Report, say, timeout) if unasked.Done != nil { unasked.Done(published) @@ -302,6 +324,9 @@ func serve(ctx context.Context, link Link, m Membership, apply Applier, say Anno _ = old.Handled() } report := handleBody(ctx, m, declaration.Body(), apply) + if report.Declared != "" { + applied = report.Declared + } if unsaid != nil { if err := unsaid.Keep(report); err != nil { say("cannot keep this apply's report until it is said: " + err.Error()) @@ -331,6 +356,21 @@ func serve(ctx context.Context, link Link, m Membership, apply Applier, say Anno } } +// overtaken says whether a report made unasked is about a declaration other than the one this link +// has applied since. Unanswerable is not overtaken: a report that names no declaration, or a link +// that has applied nothing yet, has nothing to be older than. +func overtaken(r Report, applied string) bool { + return r.Declared != "" && applied != "" && r.Declared != applied +} + +// short is a declaration's digest as a person reads it in a log line. +func short(digest string) string { + if len(digest) > 12 { + return digest[:12] + } + return digest +} + // drainDepth is how many declarations the host will hold unacknowledged while it looks for a newer // one; drainWindow is how long it waits for another to follow the one it has. Both small: a push is // rare and a backlog is the exception this exists for, not the shape of ordinary traffic.