From 37613ec6a9632e05ac9d71645992ebb830ca9fd3 Mon Sep 17 00:00:00 2001 From: jochen Date: Sun, 1 Nov 2026 16:09:50 +0100 Subject: [PATCH 1/7] pacman reads the node-engine's packages as mesh-host.packages, the bucket each engine writes (ADR 0565 clause 6, issue 1953) The read node-engine.packages named a bucket node-engine_packages that nothing writes: the engine's manifest is mesh-host's, so its state is mesh-host_packages, read as disk-load reads mesh-host.data. The view still names which source answered, the engine's key or the controller's mirror. Claude-Session: https://claude.ai/code/session_01NcbgfJ9Gum47zkFKWRaovL --- modules/pacman/README.md | 2 +- modules/pacman/cmd/pacman-tools/keeper_integration_test.go | 2 +- modules/pacman/cmd/pacman-tools/keeper_manifest_test.go | 4 +++- modules/pacman/cmd/pacman-tools/view.go | 5 +++-- modules/pacman/module.json | 2 +- 5 files changed, 9 insertions(+), 6 deletions(-) diff --git a/modules/pacman/README.md b/modules/pacman/README.md index d5df40c1..772c874b 100644 --- a/modules/pacman/README.md +++ b/modules/pacman/README.md @@ -30,7 +30,7 @@ that seat (ADR 0207). `package.changed`. A list over the bus's cap on a value is not written: the key keeps its last value and `.not-current` says the size and since when, which the health says too. `pacman_packages`, `pacman_updates`, `pacman_installed` and `pacman_foreign` answer every node from these states, and what no - module declares from the node-engine's `packages`, else the controller's `declared-packages` until its lease is written, without asking a machine. + module declares from the node-engine's `packages` (read as `mesh-host.packages`, the engine's manifest's name), else the controller's `declared-packages` until its lease is written, without asking a machine. - **Upgrades as runs, one node at a time (ADR 0508).** Every full upgrade and every rollback is a run in the state `runs` at `.`, written at each step and emitted as it: the package record taken and read back (`records`, kept `record-days`), the DKMS gate before the transaction (a kernel an installed DKMS module's own diff --git a/modules/pacman/cmd/pacman-tools/keeper_integration_test.go b/modules/pacman/cmd/pacman-tools/keeper_integration_test.go index d994641c..4ed30c81 100644 --- a/modules/pacman/cmd/pacman-tools/keeper_integration_test.go +++ b/modules/pacman/cmd/pacman-tools/keeper_integration_test.go @@ -102,7 +102,7 @@ func TestTheKeeperPutsTheNodesPackagesOnARealBusAndAnotherInstanceReadsThem(t *t } buckets[name] = kv } - declared, err := js.CreateKeyValue(ctx, jetstream.KeyValueConfig{Bucket: "node-engine_packages"}) + declared, err := js.CreateKeyValue(ctx, jetstream.KeyValueConfig{Bucket: "mesh-host_packages"}) if err != nil { t.Fatal(err) } diff --git a/modules/pacman/cmd/pacman-tools/keeper_manifest_test.go b/modules/pacman/cmd/pacman-tools/keeper_manifest_test.go index 917f8096..61d4fc6a 100644 --- a/modules/pacman/cmd/pacman-tools/keeper_manifest_test.go +++ b/modules/pacman/cmd/pacman-tools/keeper_manifest_test.go @@ -14,6 +14,8 @@ import ( "reflect" "strings" "testing" + + "git.novox.be/novox/mesh-sdk/go/delivery" ) // rawManifest is the manifest as written, every field kept. @@ -133,7 +135,7 @@ func TestTheKeeperDeclaresTheModulesStatesAndEvents(t *testing.T) { } // The verbs read which packages each node's modules declare; the process reads no other module's state // (ADR 0507 §5, ADR 0436 §1). - if got := strs(raw["reads"]); !reflect.DeepEqual(got, []string{"node-engine.packages", "mesh-controller.declared-packages"}) { + if got := strs(raw["reads"]); !reflect.DeepEqual(got, []string{delivery.EnginePackagesRead, "mesh-controller.declared-packages"}) { t.Errorf("reads: %v", got) } } diff --git a/modules/pacman/cmd/pacman-tools/view.go b/modules/pacman/cmd/pacman-tools/view.go index 6a1fea92..4521429b 100644 --- a/modules/pacman/cmd/pacman-tools/view.go +++ b/modules/pacman/cmd/pacman-tools/view.go @@ -24,9 +24,10 @@ const DeclaredPackagesState = SourceEngine // whose engine has written no key yet, until the controller's lease is written away (ADR 0565 clause 6). const ControllerDeclaredState = "mesh-controller.declared-packages" -// The sources a node's declaration is read from, said in the answer. +// The sources a node's declaration is read from, said in the answer: the node-engine's state, read by its manifest's +// name (mesh-host.packages, its bucket mesh-host_packages; mesh-sdk delivery.EnginePackagesRead), and the mirror. const ( - SourceEngine = "node-engine.packages" + SourceEngine = delivery.EnginePackagesRead SourceController = "mesh-controller.declared-packages" ) diff --git a/modules/pacman/module.json b/modules/pacman/module.json index 0aa330d4..7029d0fe 100644 --- a/modules/pacman/module.json +++ b/modules/pacman/module.json @@ -12,7 +12,7 @@ } ], "reads": [ - "node-engine.packages", + "mesh-host.packages", "mesh-controller.declared-packages" ], "uses": [ From 2b495c4818d30122fb6c9b3441e944e448d2a2f2 Mon Sep 17 00:00:00 2001 From: jochen Date: Sun, 1 Nov 2026 16:18:22 +0100 Subject: [PATCH 2/7] pacman keeps one mirror list for the mesh, ranked in the write that opens each round and written by every node (ADR 0585, issue 1876) Each node's reflector ranked its own list on its own timer, and on 2026-10-31 one node's lagging first mirror left it a Node.js version behind the rest. The list is now the module's state mirrors, key list: the node that opens a week's round ranks it with the module's reflector options, keeps only mirrors whose last sync is no older than the newest found, and the round's key names the list's revision. Every keeper writes /etc/pacman.d/mirrorlist whole from the key through the root helper's new verb mirrorlist, when the key changes and when the file differs, and never writes an empty or unreadable list. reflector.timer is declared stopped and disabled, and reflector.conf saves nothing. pacman_mirrors answers the shared list, its ranker and age and whether this node's file matches; with refresh it asks this node's keeper to rank again, refused while a round runs, naming it. The round's integration test proves the opening write and both nodes' files. Claude-Session: https://claude.ai/code/session_01NcbgfJ9Gum47zkFKWRaovL --- modules/pacman/README.md | 25 +- .../pacman/cmd/pacman-tools/busshapes_test.go | 7 +- modules/pacman/cmd/pacman-tools/keeper.go | 41 +- .../cmd/pacman-tools/keeper_hooks_test.go | 86 ++++ modules/pacman/cmd/pacman-tools/machine.go | 11 +- modules/pacman/cmd/pacman-tools/main.go | 11 +- .../pacman/cmd/pacman-tools/manifest_test.go | 11 +- modules/pacman/cmd/pacman-tools/mirrors.go | 381 ++++++++++++++++-- .../pacman/cmd/pacman-tools/pacman_test.go | 105 ++++- modules/pacman/cmd/pacman-tools/root.go | 43 +- modules/pacman/cmd/pacman-tools/root_test.go | 22 +- .../pacman-tools/round_integration_test.go | 45 ++- modules/pacman/cmd/pacman-tools/rounds.go | 11 +- modules/pacman/cmd/pacman-tools/shapes.go | 27 +- .../pacman/cmd/pacman-tools/transaction.go | 7 + .../cmd/pacman-tools/transaction_test.go | 20 + modules/pacman/cmd/pacman-tools/upgrades.go | 7 +- modules/pacman/files/reflector.conf | 8 +- modules/pacman/module.json | 13 +- 19 files changed, 770 insertions(+), 111 deletions(-) diff --git a/modules/pacman/README.md b/modules/pacman/README.md index 772c874b..c0b770d2 100644 --- a/modules/pacman/README.md +++ b/modules/pacman/README.md @@ -17,10 +17,15 @@ that seat (ADR 0207). - The manifest test runs `pacman-conf` on the rendered file and checks the repository list and the options as pacman reads them. It skips that check where `pacman-conf` is absent. - The host keeps the machine's previous file once, the first time it writes over it (ADR 0102). -- **Mirrors.** The `reflector` package, `/etc/xdg/reflector/reflector.conf` written whole (https, - Belgium, the Netherlands, Luxembourg, Germany, France, the 20 most recently synced, sorted by - rate, saved to `/etc/pacman.d/mirrorlist`), and `reflector.timer` running and enabled. The mirror - list stays reflector's to write, not the mesh's. +- **One mirror list for the mesh (ADR 0585).** The `reflector` package as the ranking tool, + `/etc/xdg/reflector/reflector.conf` written whole with its options (https, Belgium, the Netherlands, + Luxembourg, Germany, France, the 20 most recently synced, sorted by rate; nothing saved), and + `reflector.timer` declared stopped and disabled. The list is the module's state `mirrors`, one key + `list`: the node that opens a week's round ranks it with those options inside the write that opens + the round, keeps only the mirrors whose last sync is no older than the newest found, and the + round's key names the list's revision. Every node's keeper writes `/etc/pacman.d/mirrorlist` whole + from it through the root helper when the key changes and when the file differs, so a hand edit + comes back; an empty or unreadable list is never written. - **Cache cleaning.** The `pacman-contrib` package and `paccache.timer` running and enabled. Each week it keeps the last three versions of each package. - **The package view on the bus (ADR 0507).** A process of its own, the keeper (`pacman-tools keeper`, account @@ -65,15 +70,17 @@ that seat (ADR 0207). ## What it improves - Mirrors were generated once and never again: in 2022, 2023 and 2024, and on one machine by its - hosting provider's installer. The list is now refreshed weekly. The timer's first run is at the - next weekly boundary; `pacman_mirrors` with `refresh: true` runs it at once. + hosting provider's installer. Then each node's reflector ranked its own list weekly, and on + 2026-10-31 one node's lagging first mirror left it a version behind the rest. Now every node of a + round upgrades from one list ranked when the round opened; `pacman_mirrors` with `refresh: true` + ranks it again for the mesh, refused while a round runs. - Package caches were never cleaned. One workstation held 48 GB, of which paccache would free 33 GB. - Every machine has the same options. Only one had parallel downloads. ## What it leaves found -- `/etc/pacman.d/mirrorlist`, which reflector rewrites, and the stale `mirrorlist.pacnew`, - `.bak`, `.original` and similar copies beside it. +- The stale `mirrorlist.pacnew`, `.bak`, `.original` and similar copies beside the mirror list. + Until the first round opens (or a refresh), each node keeps the mirror list it has. - `/etc/pacman.d/hooks`, the keyring, and the AUR helper. Packages from outside the repositories are research 027 question 1. @@ -97,7 +104,7 @@ that seat (ADR 0207). | `pacman_remove_orphans` | a | `pacman -Rs` on named orphans, or all of them, as a unit of its own; a name that is not an orphan is refused | | `pacman_cache` | r/a | size, interrupted downloads, what paccache would free keeping N; `clean: true` removes them | | `pacman_history` | r | `/var/log/pacman.log`: installs, upgrades, downgrades, reinstalls and removals since a day, and the last full upgrade | -| `pacman_mirrors` | r/a | the list, its generator and age, reflector's options, timer and last run; `refresh: true` starts reflector | +| `pacman_mirrors` | r/a | the mesh's list, who ranked it and its age, and whether this node's file matches; `refresh: true` ranks it again for the mesh, refused during a round | | `pacman_foreign` | r | the foreign packages, from `installed` on the bus | | `pacman_news` | r | the distribution's news since the last full upgrade (or a day), over https; no network is `reachable: false` | | `pacman_config` | r | `pacman-conf`: options, repositories, and whether `/etc/pacman.conf` is the module's | diff --git a/modules/pacman/cmd/pacman-tools/busshapes_test.go b/modules/pacman/cmd/pacman-tools/busshapes_test.go index afabca1b..ac26c9e6 100644 --- a/modules/pacman/cmd/pacman-tools/busshapes_test.go +++ b/modules/pacman/cmd/pacman-tools/busshapes_test.go @@ -34,7 +34,8 @@ var busFields = map[string][]string{ "RollbackItem": {"name", "from", "to", "source", "location"}, "Record": {"node", "run", "at", "installed", "kernel", "failed_units", "dkms"}, "DKMSModule": {"module", "version", "kernels"}, - "Round": {"round", "opened", "opened_by", "order"}, + "Round": {"round", "opened", "opened_by", "order", "mirrors", "mirrors_note"}, + "MirrorList": {"servers", "ranked_at", "ranked_by", "options", "newest_sync", "round"}, "RoundNode": {"round", "node", "run", "pass"}, "Pass": {"reason", "ask", "asked", "answer", "answered"}, "Ask": {"id", "node", "act", "at", "of", "remove_added", "round", "pass", "reason"}, @@ -50,7 +51,7 @@ var busFields = map[string][]string{ } // The value of each state's keys. -var stateValues = []any{InstalledValue{}, NotCurrent{}, UpdatesValue{}, Run{}, Record{}, Round{}, RoundNode{}, Ask{}} +var stateValues = []any{InstalledValue{}, NotCurrent{}, UpdatesValue{}, Run{}, Record{}, Round{}, RoundNode{}, Ask{}, MirrorList{}} var stamp = time.Date(2026, 10, 24, 4, 0, 12, 0, time.UTC) @@ -64,6 +65,8 @@ func fill(v reflect.Value) { v.SetBool(true) case reflect.Int, reflect.Int64: v.SetInt(1) + case reflect.Uint64: + v.SetUint(1) case reflect.Pointer: v.Set(reflect.New(v.Type().Elem())) fill(v.Elem()) diff --git a/modules/pacman/cmd/pacman-tools/keeper.go b/modules/pacman/cmd/pacman-tools/keeper.go index 7c6eb981..eb6d4c61 100644 --- a/modules/pacman/cmd/pacman-tools/keeper.go +++ b/modules/pacman/cmd/pacman-tools/keeper.go @@ -8,7 +8,8 @@ package main // // - pacman's database lock released (an inotify watch on its directory: the lock file deleted) ends a // transaction, whoever ran it: `installed` and then `updates` are read again; -// - the mirror list rewritten (reflector writes /etc/pacman.d/mirrorlist): `updates` is read again; +// - the mirror list rewritten (the keeper writes /etc/pacman.d/mirrorlist from the mesh's list, ADR 0585): it is +// written again when it differs from that list, and `updates` is read again; // - a day after `updates` was last read: it is read again, since the repositories change what an upgrade // would do without any transaction on the node. // @@ -138,6 +139,8 @@ type Hooks struct { AfterTransaction []func(k *Keeper, t Transaction) error Changes []StateHook Wakes []Wake + // MirrorsRewritten: after the mirror list file was written or replaced, before `updates` is read again. + MirrorsRewritten []func(k *Keeper) error } // keeperHooks is the hooks the keeper runs with, built once the keeper is connected: the one place a part of @@ -159,7 +162,15 @@ func keeperHooks(k *Keeper) Hooks { u := &Upgrades{Node: k.Node, Config: k.Config, Machine: k.Machine, Root: root, Events: k.Events, Installed: k.State(StateInstalled), Updates: k.State(StateUpdates), Runs: k.State(StateRuns), Records: k.State(StateRecords), Rounds: k.State(StateRounds), Asks: k.State(StateAsks), AskRecord: k.AskRecord, - Check: k.Check} + Check: k.Check, Mirrors: k.State(StateMirrors), Rank: k.Rank} + // writeMirrors writes this node's mirror list file from the shared list when they differ (ADR 0585 §3). + writeMirrors := func(*Keeper) error { + wrote, err := u.WriteMirrors() + if wrote { + k.logf("[pacman] keeper: %s written from the mesh's mirror list", Mirrorlist) + } + return err + } k.upgrades = u const roundWake = 1 // the round's step is the second wake roundStep := func(k *Keeper, now time.Time) time.Time { @@ -199,7 +210,16 @@ func keeperHooks(k *Keeper) Hooks { }}, {State: StateRounds, Key: "**", Handle: onRoundChange}, {State: StateRuns, Key: "**", Handle: onRoundChange}, + // The mesh's mirror list: written to this node's file at the keeper's start and on every change (ADR 0585 §3). + {State: StateMirrors, Key: MirrorsKey, Handle: func(k *Keeper, c stdio.StateChange) error { + if c.Op != "put" { + return nil + } + return writeMirrors(k) + }}, }, + // And the file written again when it differs from the list: a hand edit, or reflector run by hand. + MirrorsRewritten: []func(*Keeper) error{writeMirrors}, Wakes: []Wake{ func(k *Keeper, now time.Time) time.Time { if !now.Equal(k.started) { @@ -239,6 +259,10 @@ func (noRoot) Rollback(run string, plan []RollbackItem) error { return errors.New(noRootSaid + ": no rollback can start") } +func (noRoot) Mirrorlist([]string) error { + return errors.New(noRootSaid + ": no mirror list can be written") +} + func (noRoot) Maps() ([]Mapped, error) { return nil, errors.New(noRootSaid + ": no process's maps can be read") } @@ -267,9 +291,11 @@ type Keeper struct { // AskRecord reads the operator channel's record of one of the module's asks (process.Conn.Ask). AskRecord func(id string) (*stdio.StateEntry, error) // Root carries out the acts that need root; nil is the root helper's client (newRootActs). Check is the - // after-upgrade check; nil is the machine's (AfterCheck). A test sets both. + // after-upgrade check; nil is the machine's (AfterCheck). Rank ranks the mesh's mirrors (RankMirrors, set by the + // process); nil ranks none. A test sets them. Root RootActs Check func(run Run, record *Record) Check + Rank func(conf []byte, round string) (MirrorList, error) upgrades *Upgrades @@ -390,6 +416,11 @@ func (k *Keeper) signal(s Signal) { } } case MirrorsRewritten: + for _, h := range k.Hooks.MirrorsRewritten { + if err := h(k); err != nil { + k.logf("[pacman] keeper: the mirror list rewritten: %v", err) + } + } k.refreshUpdates() } } @@ -606,6 +637,10 @@ func keeper() int { DBChanged: func() time.Time { return modified(filepath.Join(PacmanDBDir, "local")) }, MakeHooks: keeperHooks, } + // It ranks the mesh's mirrors with reflector when it opens a round or is asked a refresh (ADR 0585 §2, §4). + k.Rank = func(conf []byte, round string) (MirrorList, error) { + return RankMirrors(conf, k.Node, k.Clock.Now(), round) + } logf("[pacman] keeper of %s is starting as %s", account.Node, account.User) if err := runKeeper(ctx, account, k); err != nil && ctx.Err() == nil { logf("[pacman] keeper stopped: %v", err) diff --git a/modules/pacman/cmd/pacman-tools/keeper_hooks_test.go b/modules/pacman/cmd/pacman-tools/keeper_hooks_test.go index a2f8c13f..a314babc 100644 --- a/modules/pacman/cmd/pacman-tools/keeper_hooks_test.go +++ b/modules/pacman/cmd/pacman-tools/keeper_hooks_test.go @@ -118,8 +118,26 @@ func roundNodeOf(s *fakeStore, round, node string) RoundNode { // 1841/AC6 through the keeper's loop: the first of the order opens the week's round at its start on Saturday // 04:00 and starts its run in it; the round's parts get the operator channel's reader and the rounds state. +// +// ADR 0585 §2, §3: it ranks the mesh's mirrors inside the write that opens the round, before the round's key, which names +// the list's revision; and its keeper writes the list to its node's file. func TestTheFirstNodesKeeperOpensTheRoundAndTakesItsTurn(t *testing.T) { k, states, _ := roundKeeper(t, "node-a", []string{"node-a", "node-b"}) + root := &fakeRoot{} + k.Root = root + servers := []string{"https://nl.mirror.example/archlinux/$repo/os/$arch"} + k.Rank = func(conf []byte, round string) (MirrorList, error) { + if string(conf) != "--sort rate\n" { + t.Errorf("ranked with %q", conf) + } + return MirrorList{Servers: servers, RankedAt: t0, RankedBy: "node-a", Round: round}, nil + } + k.Machine.ReadFile = func(path string) ([]byte, error) { + if path == ReflectorConf { + return []byte("--sort rate\n"), nil + } + return nil, errNoFile + } ctx, cancel := context.WithCancel(context.Background()) defer cancel() go func() { _ = k.Run(ctx) }() @@ -130,6 +148,14 @@ func TestTheFirstNodesKeeperOpensTheRoundAndTakesItsTurn(t *testing.T) { if rn := roundNodeOf(rounds, round, "node-b"); rn.Run != "" { t.Errorf("node-b started in node-a's keeper: %+v", rn) } + var opened Round + e, _ := rounds.Get(round) + _ = json.Unmarshal(e.Value, &opened) + list, rev, err := readMirrorList(states.store(StateMirrors)) + if err != nil || list == nil || list.Round != round || opened.Mirrors != rev || rev == 0 || opened.MirrorsNote != "" { + t.Errorf("the round opened with mirrors %d (%q), the list is %+v at %d (%v)", opened.Mirrors, opened.MirrorsNote, list, rev, err) + } + until(t, "the list written to the node's file", func() bool { w := root.written(); return len(w) == 1 && w[0][0] == servers[0] }) } // 1841/AC6 through the keeper's loop: a node waits until the node before it passed its check, and starts on @@ -169,4 +195,64 @@ func TestTheKeeperHandsTheOperatorChannelsReaderToTheRound(t *testing.T) { if len(h.Wakes) < 2 { t.Fatalf("no wake for the round: %d wakes", len(h.Wakes)) } + // ADR 0585 §3: the node's file is written from the shared list when they differ, and never from a list that is empty + // or unreadable; the file is written again when it differs (the watch's MirrorsRewritten). + if len(h.MirrorsRewritten) != 1 { + t.Fatalf("the mirror list file is not written again when it changes: %d hooks", len(h.MirrorsRewritten)) + } + root := &fakeRoot{} + u := k.upgrades + u.Root = root + file := []byte(nil) + u.Machine.ReadFile = func(path string) ([]byte, error) { + if path == Mirrorlist && file != nil { + return file, nil + } + return nil, errNoFile + } + mirrors := states.store(StateMirrors) + good := []string{"https://a.example/$repo/os/$arch", "https://b.example/archlinux/$repo/os/$arch"} + for _, step := range []struct { + name string + put any + file []byte + wrote bool + failed bool + }{ + {name: "no shared list yet writes nothing"}, + {name: "an empty list is never written", put: MirrorList{Servers: []string{}}, failed: true}, + {name: "an unreadable list is never written", put: "not a list", failed: true}, + {name: "a list the file differs from is written whole", put: MirrorList{Servers: good}, file: []byte(mirrorlistReflector), wrote: true}, + {name: "a file holding the list is not written again", put: MirrorList{Servers: good}, file: RenderMirrorlist(good)}, + } { + if step.put != nil { + mirrors.Put(MirrorsKey, step.put) + } + file = step.file + before := len(root.written()) + wrote, err := u.WriteMirrors() + if wrote != step.wrote || (err != nil) != step.failed || len(root.written()) != before+map[bool]int{true: 1}[step.wrote] { + t.Errorf("%s: wrote %v (%v), the root helper wrote %v", step.name, wrote, err, root.written()) + } + } + // ADR 0585 §4: a refresh asked of the keeper is refused while a round runs, and ranks the list when none does; the + // ask is taken once either way. + asks, rounds := states.store(StateAsks), states.store(StateRounds) + ranked := 0 + u.Rank = func([]byte, string) (MirrorList, error) { ranked++; return MirrorList{Servers: good}, nil } + u.Machine.ReadFile = func(string) ([]byte, error) { return []byte("--sort rate\n"), nil } + rounds.Put("2026-W43", Round{Round: "2026-W43", Opened: t0, OpenedBy: "node-a", Order: []string{"node-a"}}) + for _, running := range []bool{true, false} { + if !running { + rounds.Delete("2026-W43") + } + key := NodeKey("node-a", "ask-m") + asks.Put(key, Ask{ID: "ask-m", Node: "node-a", Act: ActMirrors, At: t0}) + e, _ := asks.Get(key) + err := u.TakeAsk(stdio.StateChange{Op: "put", Key: key, Value: e.Value}) + if left, _ := asks.Get(key); left != nil || (err != nil) != running || ranked != map[bool]int{true: 0, false: 1}[running] || + (running && !strings.Contains(err.Error(), "round 2026-W43 runs")) { + t.Errorf("a refresh with a round running %v: %v, ranked %d, ask left %v", running, err, ranked, left) + } + } } diff --git a/modules/pacman/cmd/pacman-tools/machine.go b/modules/pacman/cmd/pacman-tools/machine.go index adc85428..fbc04b85 100644 --- a/modules/pacman/cmd/pacman-tools/machine.go +++ b/modules/pacman/cmd/pacman-tools/machine.go @@ -64,16 +64,21 @@ func (b *bounded) Write(p []byte) (int, error) { // ExecRunner runs a command on this machine, in the C locale so what is parsed is one language. func ExecRunner(ctx context.Context, name string, args ...string) Ran { - ctx, cancel := context.WithTimeout(ctx, CallTimeout) + return execWithin(ctx, CallTimeout, nil, name, args...) +} + +// execWithin runs a command on this machine within timeout, in the C locale, with env added to this process's. +func execWithin(ctx context.Context, timeout time.Duration, env []string, name string, args ...string) Ran { + ctx, cancel := context.WithTimeout(ctx, timeout) defer cancel() cmd := exec.CommandContext(ctx, name, args...) - cmd.Env = append(os.Environ(), "LC_ALL=C") + cmd.Env = append(append(os.Environ(), "LC_ALL=C"), env...) var out, errb bounded cmd.Stdout, cmd.Stderr = &out, &errb err := cmd.Run() r := Ran{Stdout: out.String(), Stderr: errb.String()} if ctx.Err() == context.DeadlineExceeded { - r.Status, r.Err = 124, fmt.Sprintf("no answer within %d s", int(CallTimeout.Seconds())) + r.Status, r.Err = 124, fmt.Sprintf("no answer within %d s", int(timeout.Seconds())) return r } var exit *exec.ExitError diff --git a/modules/pacman/cmd/pacman-tools/main.go b/modules/pacman/cmd/pacman-tools/main.go index 2e777b36..43c25752 100644 --- a/modules/pacman/cmd/pacman-tools/main.go +++ b/modules/pacman/cmd/pacman-tools/main.go @@ -433,15 +433,18 @@ func tools(m *Machine) []stdio.Tool { }, }, { - Name: "pacman_mirrors", - Description: "The mirror list in force (servers, commented ones, who generated it and when), reflector's options, its timer and its last run. With refresh: true, start reflector now (sudo -n), without waiting.", - Input: schema(map[string]any{"refresh": map[string]any{"type": "boolean", "description": "rank and rewrite the list now"}}), + Name: "pacman_mirrors", + Description: "The mesh's one mirror list from the bus (ADR 0585): its servers, when and by which node it was ranked, its " + + "age and reflector's options, and whether this node's /etc/pacman.d/mirrorlist matches it (the file as found when " + + "not), with reflector's timer, which stays disabled. With refresh: true, this node's keeper ranks the list again " + + "for the whole mesh and every node writes it; refused while an upgrade round runs, naming the round.", + Input: schema(map[string]any{"refresh": map[string]any{"type": "boolean", "description": "rank the mesh's list again now"}}), Run: func(args map[string]any) (any, error) { refresh, err := flag(args, "refresh") if err != nil { return nil, err } - return m.MirrorList(refresh) + return m.MirrorsView(refresh) }, }, { diff --git a/modules/pacman/cmd/pacman-tools/manifest_test.go b/modules/pacman/cmd/pacman-tools/manifest_test.go index af36b100..6cf1df71 100644 --- a/modules/pacman/cmd/pacman-tools/manifest_test.go +++ b/modules/pacman/cmd/pacman-tools/manifest_test.go @@ -24,9 +24,11 @@ func TestItHoldsThePackageManagerSeatAndDeclaresItsPackage(t *testing.T) { t.Errorf("%s: %v", id, r) } } - for id, unit := range map[string]string{"mirror-refresh": "reflector.timer", "cache-cleaning": "paccache.timer"} { + // ADR 0585 §3: reflector's weekly timer is declared stopped and disabled, the mesh's list ranked in the round instead. + for id, unit := range map[string][3]string{"mirror-refresh": {"reflector.timer", "stopped", "disabled"}, + "cache-cleaning": {"paccache.timer", "running", "enabled"}} { r := m.resource(t, id) - if r["unit"] != unit || r["state"] != "running" || r["boot"] != "enabled" { + if r["unit"] != unit[0] || r["state"] != unit[1] || r["boot"] != unit[2] { t.Errorf("%s: %v", id, r) } } @@ -103,7 +105,7 @@ func provenConf(t *testing.T, content, dir string) string { return strings.ReplaceAll(content, "Include = "+Mirrorlist, "Include = "+list) } -func TestReflectorWritesTheListPacmanReads(t *testing.T) { +func TestReflectorRanksWithTheModulesOptionsAndSavesNoList(t *testing.T) { content := templateText(t, manifest(t).resource(t, "mirrors")) opts := map[string]string{} for _, l := range strings.Split(content, "\n") { @@ -113,7 +115,8 @@ func TestReflectorWritesTheListPacmanReads(t *testing.T) { k, v, _ := strings.Cut(l, " ") opts[k] = v } - if opts["--save"] != Mirrorlist || opts["--protocol"] != "https" || opts["--latest"] != "20" || opts["--sort"] != "rate" || opts["--country"] == "" { + // ADR 0585 §3: nothing saves a list but the keeper, from the mesh's. + if _, saves := opts["--save"]; saves || opts["--protocol"] != "https" || opts["--latest"] != "20" || opts["--sort"] != "rate" || opts["--country"] == "" { t.Fatalf("%v", opts) } if manifest(t).resource(t, "mirrors")["path"] != ReflectorConf { diff --git a/modules/pacman/cmd/pacman-tools/mirrors.go b/modules/pacman/cmd/pacman-tools/mirrors.go index 9b772a65..eaebcb7c 100644 --- a/modules/pacman/cmd/pacman-tools/mirrors.go +++ b/modules/pacman/cmd/pacman-tools/mirrors.go @@ -1,36 +1,62 @@ package main -// The mirror list and its refresher (novox/hq to-be 42 Phase 1). On 2026-10-04 every machine's list -// had been generated once — by a tool no longer installed, or by a hosting provider's installer — and -// never again. The module installs reflector, owns its configuration and enables its weekly timer; -// this reads the list and the refresher's last run, and starts a refresh on demand. +// The mesh's one mirror list (novox/hq ADR 0585). Before it each node's reflector ranked its own list on its own weekly +// timer (to-be 42 Phase 1), and on 2026-10-31 one node's first mirror lagged, so its upgrade found nothing to install +// while the others moved on. Now: +// +// - the list is one key of the module's own state, `mirrors.list` (§1): the servers in order, when and by which node +// they were ranked, and the options; +// - it is ranked once per weekly round, by the node that opens it, inside the write that opens it (§2): reflector +// ranks with the module's options (reflector.conf, its `--save` left out), only the mirrors whose last sync is no +// older than the newest found are kept, and the round's key names the list's revision; +// - each node's keeper writes /etc/pacman.d/mirrorlist whole from the key, through the root helper, when the key +// changes and when the file differs (the keeper watches the file), so a hand edit comes back; a list that is +// empty or cannot be read is never written, and the node keeps its last (§3); reflector stays installed as the +// ranking tool, and its weekly timer is declared stopped and disabled; +// - `pacman_mirrors` answers the shared list, its age, its ranker and whether this node's file matches; with +// refresh it asks this node's keeper to rank again for the mesh, refused while a round runs, naming it (§4). import ( + "bytes" + "context" + "encoding/json" + "errors" + "fmt" + "os" + "regexp" "strings" + "time" + + stdio "git.novox.be/novox/mesh-sdk/go" ) -// Where the list is and how reflector is told to write it. +// Where the list is and where the module's reflector options are. const ( Mirrorlist = "/etc/pacman.d/mirrorlist" ReflectorConf = "/etc/xdg/reflector/reflector.conf" ) -// Mirrors is the mirror list and its refresher. +// RankTimeout bounds one ranking: reflector downloads from every candidate mirror to rate it, which takes longer than +// a tool call may (CallTimeout), so the keeper ranks, never a call. +const RankTimeout = 3 * time.Minute + +// mostMirrors bounds a list the root helper writes: far more than a ranking keeps (the module's --latest). +const mostMirrors = 100 + +// Mirrors is a mirror list file as found: the servers in force, those commented out, and the generator's header. type Mirrors struct { - Servers []string `json:"servers"` - Commented int `json:"commented_servers"` - GeneratedBy string `json:"generated_by,omitempty"` - When string `json:"generated_when,omitempty"` - Reflector []string `json:"reflector_options"` - Timer map[string]string `json:"reflector_timer,omitempty"` - LastRun map[string]string `json:"reflector_last_run,omitempty"` - Refreshing bool `json:"refresh_started"` - Note string `json:"note,omitempty"` + Servers []string `json:"servers"` + Commented int `json:"commented_servers"` + GeneratedBy string `json:"generated_by,omitempty"` + When string `json:"generated_when,omitempty"` } +// mirrorlistHeader is the first line of the file the mesh writes, by which it is known as the mesh's. +const mirrorlistHeader = "# The mesh's mirror list (module pacman, novox/hq ADR 0585)" + // ParseMirrorlist reads the servers in force, those commented out, and the generator's header. func ParseMirrorlist(text string) Mirrors { - m := Mirrors{Servers: []string{}, Reflector: []string{}} + m := Mirrors{Servers: []string{}} for _, l := range lines(text) { l = strings.TrimSpace(l) switch { @@ -40,6 +66,8 @@ func ParseMirrorlist(text string) Mirrors { } case strings.HasPrefix(strings.TrimLeft(l, "# "), "Server"): m.Commented++ + case l == mirrorlistHeader: + m.GeneratedBy = "the mesh" case strings.Contains(l, "generated by Reflector"): m.GeneratedBy = "reflector" case strings.HasPrefix(l, "# When:"): @@ -51,36 +79,307 @@ func ParseMirrorlist(text string) Mirrors { return m } -// MirrorList answers the list, reflector's options, its timer and its last run; refresh starts -// reflector now, without waiting, since ranking mirrors by rate takes longer than a call may. -func (m *Machine) MirrorList(refresh bool) (Mirrors, error) { - text, err := m.ReadFile(Mirrorlist) - if err != nil { - return Mirrors{}, err +// mirrorServer is a server line's value pacman takes from the mesh: http(s), a host, a path, and the repository and +// architecture left to pacman. Nothing else reaches the file: not a newline, not a second option. +var mirrorServer = regexp.MustCompile(`^https?://[A-Za-z0-9.-]+(:[0-9]+)?(/[A-Za-z0-9._~%+@-]+)*/\$repo/os/\$arch$`) + +// checkServers refuses a list that is empty, too long, or holds anything but a server. +func checkServers(servers []string) error { + if len(servers) == 0 { + return errors.New("the list is empty") } - out := ParseMirrorlist(string(text)) - if conf, err := m.ReadFile(ReflectorConf); err == nil { - for _, l := range lines(string(conf)) { - if l = strings.TrimSpace(l); !strings.HasPrefix(l, "#") { - out.Reflector = append(out.Reflector, l) + if len(servers) > mostMirrors { + return fmt.Errorf("the list holds %d servers, more than %d", len(servers), mostMirrors) + } + for _, s := range servers { + if !mirrorServer.MatchString(s) { + return fmt.Errorf("%q is not a mirror's server", s) + } + } + return nil +} + +// RenderMirrorlist is the mirror list file whole, as every node writes it from the shared list: the same servers are +// the same bytes, so a node compares its file with the list by its bytes. +func RenderMirrorlist(servers []string) []byte { + var b bytes.Buffer + b.WriteString(mirrorlistHeader + "\n") + b.WriteString("# Written whole from the bus (the state mirrors of the module pacman): a hand edit is written back.\n") + b.WriteString("# pacman_mirrors says when it was ranked and by which node.\n") + for _, s := range servers { + b.WriteString("Server = " + s + "\n") + } + return b.Bytes() +} + +// ReflectorOptions is the options reflector.conf sets, each line split into its flag and its value as reflector reads +// them: a `--save` is left out, since the keeper writes the file (ADR 0585 §3). +func ReflectorOptions(conf string) []string { + out := []string{} + for _, l := range lines(conf) { + l = strings.TrimSpace(l) + if l == "" || strings.HasPrefix(l, "#") { + continue + } + flag, value, _ := strings.Cut(l, " ") + if flag == "--save" { + continue + } + out = append(out, flag) + if value = strings.Trim(strings.TrimSpace(value), `"'`); value != "" { + out = append(out, value) + } + } + return out +} + +// rankedMirror is one mirror reflector ranked, in its order, with its last sync (zero when the status says none). +type rankedMirror struct { + URL string + LastSync time.Time +} + +// reflectorTime is how reflector's --info writes a last sync. +const reflectorTime = "2006-01-02 15:04:05 MST" + +// ParseReflectorInfo reads reflector's --info: one block per mirror in the order it ranked them, its server first and +// then `field : value` lines, of which last_sync is read. +func ParseReflectorInfo(text string) []rankedMirror { + var out []rankedMirror + open := false + for _, l := range strings.Split(text, "\n") { + l = strings.TrimSpace(l) + switch { + case l == "": + open = false + case !open && strings.Contains(l, "://") && !strings.Contains(l, " "): + out, open = append(out, rankedMirror{URL: l}), true + case open: + if k, v, ok := strings.Cut(l, ":"); ok && strings.TrimSpace(k) == "last_sync" { + if t, err := time.Parse(reflectorTime, strings.TrimSpace(v)); err == nil { + out[len(out)-1].LastSync = t.UTC() + } } } } - if t, err := m.unitProps("reflector.timer", "LoadState", "ActiveState", "UnitFileState", "LastTriggerUSec", "NextElapseUSecRealtime"); err == nil { - out.Timer = t - } - if s, err := m.unitProps("reflector.service", "LoadState", "ActiveState", "Result", "ExecMainExitTimestamp", "ExecMainStatus"); err == nil { - out.LastRun = s - } - if out.Timer["LoadState"] == "not-found" { - out.Note = "reflector is not installed here; the module installs it" - } - if refresh { - if _, err := m.Root("systemctl", "start", "--no-block", "reflector.service"); err != nil { - return out, err + return out +} + +// Freshest keeps, in their order, only the mirrors whose last sync is no older than the newest found (ADR 0585 §2), so +// a mirror lagging behind the others is never in the list; one whose last sync is unknown is left out. +func Freshest(ranked []rankedMirror) (servers []string, newest time.Time) { + for _, m := range ranked { + if m.LastSync.After(newest) { + newest = m.LastSync } - out.Refreshing = true - out.Note = "reflector is ranking mirrors now; call again in a minute for the new list" } + for _, m := range ranked { + if !m.LastSync.IsZero() && !m.LastSync.Before(newest) { + servers = append(servers, m.URL) + } + } + return servers, newest +} + +// reflectorRun runs reflector with args on this machine, within RankTimeout; its cache in the temporary directory, since +// the keeper's account has no home of its own. A test replaces it. +var reflectorRun = func(ctx context.Context, args ...string) Ran { + return execWithin(ctx, RankTimeout, []string{"XDG_CACHE_HOME=" + os.TempDir()}, "reflector", args...) +} + +// RankMirrors ranks the mirrors with reflector and the module's options (conf, reflector.conf's text) and keeps the +// freshest: the mesh's list, ranked by node at now for round (none for a refresh). A ranking that fails or keeps no +// mirror is an error, never an empty list (ADR 0585 §3). +func RankMirrors(conf []byte, node string, now time.Time, round string) (MirrorList, error) { + opts := ReflectorOptions(string(conf)) + r := reflectorRun(context.Background(), append(append([]string(nil), opts...), "--info")...) + if r.Status != 0 || r.Err != "" { + return MirrorList{}, failure("reflector", "reflector", r) + } + ranked := ParseReflectorInfo(r.Stdout) + servers, newest := Freshest(ranked) + if err := checkServers(servers); err != nil { + return MirrorList{}, fmt.Errorf("reflector ranked no list the mesh can use (%d mirrors read): %w", len(ranked), err) + } + return MirrorList{Servers: servers, RankedAt: now.UTC(), RankedBy: node, Options: opts, Newest: newest, Round: round}, nil +} + +// readMirrorList is the shared list and its revision; nil when there is none yet. +func readMirrorList(r interface { + Get(key string) (*stdio.StateEntry, error) +}) (*MirrorList, uint64, error) { + e, err := r.Get(MirrorsKey) + if err != nil || e == nil { + return nil, 0, err + } + var l MirrorList + if err := json.Unmarshal(e.Value, &l); err != nil { + return nil, e.Revision, fmt.Errorf("%s.%s is not readable: %w", StateMirrors, MirrorsKey, err) + } + return &l, e.Revision, nil +} + +// ---- the keeper's part ------------------------------------------------------------------------------------------- + +// rankMirrors ranks the mesh's list and writes it to the shared key, answering its revision. +func (u *Upgrades) rankMirrors(round string) (uint64, error) { + if u.Rank == nil || u.Mirrors == nil { + return 0, errors.New("this keeper ranks no mirrors") + } + conf, err := u.Machine.ReadFile(ReflectorConf) + if err != nil { + return 0, fmt.Errorf("the module's reflector options cannot be read: %w", err) + } + list, err := u.Rank(conf, round) + if err != nil { + return 0, err + } + return u.Mirrors.Put(MirrorsKey, list) +} + +// mirrorsForRound ranks the list in the write that opens round (ADR 0585 §2): the revision the round opens with, and +// why it was not ranked again when it was not, the round then opening with the list there is. +func (u *Upgrades) mirrorsForRound(round string) (uint64, string) { + rev, err := u.rankMirrors(round) + if err == nil { + return rev, "" + } + note := "the mirrors were not ranked again: " + err.Error() + if u.Mirrors != nil { + if _, kept, rerr := readMirrorList(u.Mirrors); rerr == nil && kept > 0 { + return kept, note + fmt.Sprintf("; the round opens with the list at revision %d", kept) + } + } + return 0, note + "; there is no shared list yet, and every node keeps its own" +} + +// runningRound is the round that runs now, none when every node of the latest round passed: a refresh is refused +// while one runs, so every node of a round upgrades from the list it opened with (ADR 0585 §4). +func runningRound(rounds, runs Bucket, now time.Time) (string, error) { + id, err := latestRound(rounds) + if err != nil || id == "" { + return "", err + } + v, err := readRound(rounds, runs, id) + if err != nil || v == nil { + return "", err + } + for _, n := range RoundState(v, now, 0) { + if n.State != InRoundPassed { + return id, nil + } + } + return "", nil +} + +// refreshRefused is the words of a refresh refused during round. +func refreshRefused(round string) error { + return fmt.Errorf("round %s runs: every node of it upgrades from the list it opened with, so the mirrors are ranked "+ + "again only once every node of it passed (pacman_round says where it stands)", round) +} + +// takeMirrorsAsk ranks the list again for the mesh on a refresh, unless a round runs. +func (u *Upgrades) takeMirrorsAsk() error { + if round, err := runningRound(u.Rounds, u.Runs, u.Machine.Now()); err != nil { + return err + } else if round != "" { + return refreshRefused(round) + } + _, err := u.rankMirrors("") + return err +} + +// WriteMirrors writes this node's mirror list file whole from the shared list when they differ, through the root +// helper, answering whether it wrote. No list yet writes nothing; a list that is empty or cannot be read is never +// written, and the node keeps its last (ADR 0585 §3). +func (u *Upgrades) WriteMirrors() (bool, error) { + if u.Mirrors == nil { + return false, nil + } + list, _, err := readMirrorList(u.Mirrors) + if err != nil { + return false, fmt.Errorf("%v; this node keeps its mirror list", err) + } + if list == nil { + return false, nil + } + if err := checkServers(list.Servers); err != nil { + return false, fmt.Errorf("the shared mirror list is not written: %v; this node keeps its mirror list", err) + } + want := RenderMirrorlist(list.Servers) + if have, err := u.Machine.ReadFile(Mirrorlist); err == nil && bytes.Equal(have, want) { + return false, nil + } + if err := u.Root.Mirrorlist(list.Servers); err != nil { + return false, fmt.Errorf("writing %s: %w", Mirrorlist, err) + } + return true, nil +} + +// ---- the tool ----------------------------------------------------------------------------------------------------- + +// MirrorsView answers pacman_mirrors (ADR 0585 §4): the shared list, its revision and age and who ranked it, and this +// node's file beside it; with refresh, the ask of this node's keeper to rank again for the mesh, refused while a round +// runs. +func (m *Machine) MirrorsView(refresh bool) (map[string]any, error) { + if err := m.states(); err != nil { + return nil, err + } + out := map[string]any{"node": m.Node} + list, rev, err := readMirrorList(m.States(StateMirrors)) + if err != nil { + return nil, err + } + out["shared"], out["revision"] = list, rev + text, ferr := m.ReadFile(Mirrorlist) + if ferr != nil { + out["file_error"] = ferr.Error() + } + file := ParseMirrorlist(string(text)) + if list == nil { + out["note"] = "no shared list yet: it is ranked when the next round opens, or by pacman_mirrors with refresh" + out["file"] = file + } else { + out["age"] = m.Now().Sub(list.RankedAt).Round(time.Minute).String() + out["ranked_by"] = list.RankedBy + matches := ferr == nil && bytes.Equal(text, RenderMirrorlist(list.Servers)) + out["file_matches"] = matches + if !matches { + out["file"] = file + } + } + if t, err := m.unitProps("reflector.timer", "LoadState", "UnitFileState", "ActiveState"); err == nil { + out["reflector_timer"] = t + } + if !refresh { + return out, nil + } + now := m.Now() + round, err := runningRound(upgradeState(StateRounds), upgradeState(StateRuns), now) + if err != nil { + return nil, err + } + if round != "" { + return nil, refreshRefused(round) + } + a, err := AskMirrors(upgradeState(StateAsks), thisNode(), now) + if err != nil { + return nil, err + } + out["asked"] = a.ID + out["next"] = "the keeper of " + a.Node + " ranks the mirrors for the mesh now, which takes a minute or two; every " + + "node writes the new list once it lands, and pacman_mirrors says it" return out, nil } + +// AskMirrors writes an ask for node's keeper to rank the mesh's mirrors again. +func AskMirrors(asks Bucket, node string, now time.Time) (Ask, error) { + if node == "" { + return Ask{}, errors.New("no node to ask: the runtime names none (MESH_NODE)") + } + a := Ask{ID: AskID(now), Node: node, Act: ActMirrors, At: now.UTC()} + if _, err := asks.Create(NodeKey(node, a.ID), a); err != nil { + return Ask{}, fmt.Errorf("writing the ask: %w", err) + } + return a, nil +} diff --git a/modules/pacman/cmd/pacman-tools/pacman_test.go b/modules/pacman/cmd/pacman-tools/pacman_test.go index 0c7f1d43..aad2b590 100644 --- a/modules/pacman/cmd/pacman-tools/pacman_test.go +++ b/modules/pacman/cmd/pacman-tools/pacman_test.go @@ -1,6 +1,7 @@ package main import ( + "context" "strings" "testing" "time" @@ -287,29 +288,91 @@ Server = https://mirror2.example.org/$repo/os/$arch #Server = https://old.example.org/$repo/os/$arch ` -func TestMirrorsReadTheListAndRefreshWithoutWaiting(t *testing.T) { - var calls []call - m := machine(fake(func(c call) Ran { - if c.name == "systemctl" && c.args[0] == "show" { - return Ran{Stdout: "LoadState=loaded\nActiveState=active\nUnitFileState=enabled\n"} - } - return Ran{} - }, &calls), 1000) - m.ReadFile = func(p string) ([]byte, error) { - switch p { - case Mirrorlist: - return []byte(mirrorlistReflector), nil - case ReflectorConf: - return []byte("# comment\n--save /etc/pacman.d/mirrorlist\n--sort rate\n"), nil - } - return nil, errNoFile +// reflectorInfo is reflector's --info as it answered on 2026-11-01 (reflector 2023, its fields cut to those +// read and one more), the ranked order kept: two mirrors at the newest last sync, one behind, one with none. +const reflectorInfo = `https://nl.mirror.example/archlinux/$repo/os/$arch +active : True +country : Netherlands +last_sync : 2026-11-01 14:32:01 UTC + +https://be.mirror.example/archlinux/$repo/os/$arch +active : True +last_sync : 2026-11-01 14:01:45 UTC + +https://de.mirror.example/$repo/os/$arch +last_sync : 2026-11-01 14:32:01 UTC + +https://fr.mirror.example/archlinux/$repo/os/$arch +last_sync : None +` + +// ADR 0585 §2, §4: the ranking keeps only mirrors as fresh as the newest, in reflector's order, with the module's options +// and never its --save; a ranking that fails or keeps none is no list. pacman_mirrors answers the shared list, its +// ranker and age and whether this node's file matches it (the file as found when not); with refresh it asks this node's +// keeper to rank again, refused while a round runs, naming it. +func TestTheMeshsMirrorListIsRankedFreshAndAnsweredWithThisNodesFile(t *testing.T) { + conf := "# comment\n--save /etc/pacman.d/mirrorlist\n--country Belgium,Netherlands\n--sort rate\n" + if o := strings.Join(ReflectorOptions(conf), " "); o != "--country Belgium,Netherlands --sort rate" { + t.Errorf("the options are %q", o) } - r, err := m.MirrorList(true) - if err != nil || len(r.Servers) != 2 || r.Commented != 1 || r.GeneratedBy != "reflector" || r.When != "2024-06-12 21:26:34 UTC" || len(r.Reflector) != 2 || !r.Refreshing { - t.Fatalf("%+v %v", r, err) + var asked []string + answer := Ran{Stdout: reflectorInfo} + saved := reflectorRun + reflectorRun = func(_ context.Context, args ...string) Ran { asked = args; return answer } + defer func() { reflectorRun = saved }() + l, err := RankMirrors([]byte(conf), "node-a", t0, "2026-W43") + if err != nil || strings.Join(l.Servers, " ") != "https://nl.mirror.example/archlinux/$repo/os/$arch https://de.mirror.example/$repo/os/$arch" || + !l.Newest.Equal(time.Date(2026, 11, 1, 14, 32, 1, 0, time.UTC)) || l.RankedBy != "node-a" || l.Round != "2026-W43" || + strings.Join(asked, " ") != "--country Belgium,Netherlands --sort rate --info" { + t.Fatalf("ranked %+v (%v), reflector asked %v", l, err, asked) } - if calls[len(calls)-1].String() != "sudo -n systemctl start --no-block reflector.service" { - t.Fatalf("%v", calls[len(calls)-1]) + for _, a := range []Ran{{Status: 1, Stderr: "error: no mirrors"}, {Stdout: "https://x.example/$repo/os/$arch\nlast_sync : None\n"}} { + answer = a + if _, err := RankMirrors([]byte(conf), "node-a", t0, ""); err == nil { + t.Errorf("a ranking from %+v is a list", a) + } + } + if checkServers([]string{"https://ok.example/$repo/os/$arch\nServer = https://evil.example/$repo/os/$arch"}) == nil { + t.Error("a server carrying a second line is taken") + } + + states := &fakeStates{} + states.store(StateMirrors).Put(MirrorsKey, l) + file := RenderMirrorlist(l.Servers) + m := machine(func(context.Context, string, ...string) Ran { + return Ran{Stdout: "LoadState=loaded\nUnitFileState=disabled\nActiveState=inactive\n"} + }, 1000) + m.Node, m.States = "node-a", readerOf(states) + m.Now = func() time.Time { return t0.Add(90 * time.Minute) } + m.ReadFile = func(string) ([]byte, error) { return file, nil } + v, err := m.MirrorsView(false) + if err != nil || v["file_matches"] != true || v["ranked_by"] != "node-a" || v["age"] != "1h30m0s" || v["file"] != nil || + v["reflector_timer"].(map[string]string)["UnitFileState"] != "disabled" { + t.Fatalf("the view is %v (%v)", v, err) + } + file = []byte(mirrorlistReflector) + if v, _ := m.MirrorsView(false); v["file_matches"] != false || v["file"].(Mirrors).GeneratedBy != "reflector" { + t.Errorf("a file other than the list is %v", v) + } + + rounds, runs, asks := newBucket(), newBucket(), newBucket() + savedState, savedNode := upgradeState, thisNode + upgradeState = func(name string) Bucket { + return map[string]Bucket{StateRounds: rounds, StateRuns: runs, StateAsks: asks}[name] + } + thisNode = func() string { return "node-a" } + defer func() { upgradeState, thisNode = savedState, savedNode }() + rounds.Put("2026-W43", Round{Round: "2026-W43", Opened: t0, OpenedBy: "node-a", Order: []string{"node-a", "node-b"}}) + if _, err := m.MirrorsView(true); err == nil || !strings.Contains(err.Error(), "round 2026-W43 runs") { + t.Errorf("a refresh during a round: %v", err) + } + if keys, _ := asks.Keys(); len(keys) != 0 { + t.Errorf("a refused refresh asked %v", keys) + } + rounds.Delete("2026-W43") + v, err = m.MirrorsView(true) + if keys, _ := asks.Keys(); err != nil || len(keys) != 1 || !strings.HasPrefix(keys[0], "node-a.") || v["asked"] == nil { + t.Errorf("a refresh asked %v (%v): %v", keys, err, v) } } diff --git a/modules/pacman/cmd/pacman-tools/root.go b/modules/pacman/cmd/pacman-tools/root.go index df21a062..1f5e4454 100644 --- a/modules/pacman/cmd/pacman-tools/root.go +++ b/modules/pacman/cmd/pacman-tools/root.go @@ -51,6 +51,7 @@ const ( VerbRollback = "rollback" VerbMaps = "maps" VerbJournal = "journal" + VerbMirrorlist = "mirrorlist" ) // The helper's environment, and the keeper's word for where the helper listens. @@ -78,6 +79,8 @@ type RootRequest struct { Plan []RollbackItem `json:"plan,omitempty"` Unit string `json:"unit,omitempty"` Lines int `json:"lines,omitempty"` + // Servers are the mirror list's servers, in order, for the verb mirrorlist. + Servers []string `json:"servers,omitempty"` } // RootAnswer is the helper's answer: an error, or what the verb read. @@ -95,7 +98,9 @@ type RootHelper struct { ProcRoot string PlanDir string Self string - Peer int + // MirrorlistPath is the mirror list file the verb mirrorlist writes: Mirrorlist, a test's own elsewhere. + MirrorlistPath string + Peer int // PeerOf is the account at the other end of a connection; nil reads it from the socket (SO_PEERCRED). PeerOf func(net.Conn) (int, error) Logf func(format string, a ...any) @@ -221,8 +226,17 @@ func (h *RootHelper) Handle(req RootRequest) RootAnswer { return RootAnswer{Error: failure("journalctl", "journalctl", r).Error()} } return RootAnswer{Lines: lines(r.Stdout)} + case VerbMirrorlist: + if err := checkServers(req.Servers); err != nil { + return refused("%v", err) + } + if err := writeWhole(h.MirrorlistPath, RenderMirrorlist(req.Servers), 0o644); err != nil { + return RootAnswer{Error: "writing the mirror list: " + err.Error()} + } + return RootAnswer{} } - return refused("%q is not a verb of the root helper (%s, %s, %s, %s)", req.Verb, VerbTransaction, VerbRollback, VerbMaps, VerbJournal) + return refused("%q is not a verb of the root helper (%s, %s, %s, %s, %s)", req.Verb, VerbTransaction, VerbRollback, VerbMaps, + VerbJournal, VerbMirrorlist) } // startUnit starts command as a transient unit of the service manager and answers once it started. @@ -341,6 +355,28 @@ func (c rootClient) Rollback(run string, plan []RollbackItem) error { return err } +func (c rootClient) Mirrorlist(servers []string) error { + _, err := c.ask(RootRequest{Verb: VerbMirrorlist, Servers: servers}) + return err +} + +// writeWhole writes a file whole: into a file beside it, then renamed over it, so a reader never meets half of it. +func writeWhole(path string, content []byte, mode os.FileMode) error { + tmp := filepath.Join(filepath.Dir(path), "."+filepath.Base(path)+".mesh") + if err := os.WriteFile(tmp, content, mode); err != nil { + return err + } + if err := os.Chmod(tmp, mode); err != nil { + _ = os.Remove(tmp) + return err + } + if err := os.Rename(tmp, path); err != nil { + _ = os.Remove(tmp) + return err + } + return nil +} + func (c rootClient) Journal(unit string, n int) ([]string, error) { a, err := c.ask(RootRequest{Verb: VerbJournal, Unit: unit, Lines: n}) return a.Lines, err @@ -398,7 +434,8 @@ func rootHelper() int { } ctx, stop := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM) defer stop() - h := &RootHelper{Run: ExecRunner, Proc: osProc{}, ProcRoot: "/proc", PlanDir: filepath.Join(dir, "plans"), Self: self, Peer: uid, Logf: logf} + h := &RootHelper{Run: ExecRunner, Proc: osProc{}, ProcRoot: "/proc", PlanDir: filepath.Join(dir, "plans"), Self: self, + MirrorlistPath: Mirrorlist, Peer: uid, Logf: logf} logf("[pacman] root helper listening on %s for account %s (%d)", sock, peerName, uid) if err := h.Serve(ctx, l); err != nil { logf("[pacman] root helper stopped: %v", err) diff --git a/modules/pacman/cmd/pacman-tools/root_test.go b/modules/pacman/cmd/pacman-tools/root_test.go index 8d9d2962..c5303f7e 100644 --- a/modules/pacman/cmd/pacman-tools/root_test.go +++ b/modules/pacman/cmd/pacman-tools/root_test.go @@ -34,10 +34,11 @@ func newRootBed(t *testing.T) *rootBed { } return Ran{} }, - Proc: stubProc{"/proc": {"1"}, "/proc/1/maps": {"7f00 r-xp 0 0:1 1 /usr/lib/libc.so.6 (deleted)"}, "/proc/1/cgroup": {"0::/system.slice/sshd.service"}, "/proc/1/exe": {"/usr/bin/sshd"}}, - ProcRoot: "/proc", - PlanDir: t.TempDir(), - Self: "/var/lib/mesh/daemons/pacman-root/pacman-tools", + Proc: stubProc{"/proc": {"1"}, "/proc/1/maps": {"7f00 r-xp 0 0:1 1 /usr/lib/libc.so.6 (deleted)"}, "/proc/1/cgroup": {"0::/system.slice/sshd.service"}, "/proc/1/exe": {"/usr/bin/sshd"}}, + ProcRoot: "/proc", + PlanDir: t.TempDir(), + Self: "/var/lib/mesh/daemons/pacman-root/pacman-tools", + MirrorlistPath: filepath.Join(t.TempDir(), "mirrorlist"), } return b } @@ -113,8 +114,16 @@ func TestTheRootHelperStartsARollbackWithThePlanInTheRequest(t *testing.T) { } } +// And (ADR 0585 §3) the verb mirrorlist writes the mirror list file whole from the servers it is sent, running nothing. func TestTheRootHelperReadsTheReplacedFilesMappings(t *testing.T) { b := newRootBed(t) + servers := []string{"https://a.example/$repo/os/$arch", "https://b.example/archlinux/$repo/os/$arch"} + if a := b.h.Handle(RootRequest{Verb: VerbMirrorlist, Servers: servers}); a.Error != "" { + t.Fatalf("the mirror list refused: %s", a.Error) + } + if got, err := os.ReadFile(b.h.MirrorlistPath); err != nil || string(got) != string(RenderMirrorlist(servers)) || len(b.ran) != 0 { + t.Fatalf("the mirror list file holds %q (%v), ran %v", got, err, b.ran) + } a := b.h.Handle(RootRequest{Verb: VerbMaps}) want := []Mapped{{Unit: "sshd.service", Executable: "/usr/bin/sshd"}} if a.Error != "" || !reflect.DeepEqual(a.Mapped, want) { @@ -169,6 +178,11 @@ func TestTheRootHelperRefusesEverythingOffItsList(t *testing.T) { "a removal with a location": {Verb: VerbRollback, Run: aRun, Plan: with(func(i *RollbackItem) { i.Source, i.To = SourceRemoved, "" })}, + // ADR 0585 §3: never an empty mirror list, nor anything but a server in it. + "an empty mirror list": {Verb: VerbMirrorlist}, + "a mirror list carrying a line": {Verb: VerbMirrorlist, Servers: []string{"https://a.example/$repo/os/$arch\nInclude = /tmp/x"}}, + "a mirror list of a local file": {Verb: VerbMirrorlist, Servers: []string{"file:///tmp/$repo/os/$arch"}}, + "a mirror list of another shape": {Verb: VerbMirrorlist, Servers: []string{"https://a.example/x"}}, } for name, req := range cases { b := newRootBed(t) diff --git a/modules/pacman/cmd/pacman-tools/round_integration_test.go b/modules/pacman/cmd/pacman-tools/round_integration_test.go index a6855d9b..099f22ff 100644 --- a/modules/pacman/cmd/pacman-tools/round_integration_test.go +++ b/modules/pacman/cmd/pacman-tools/round_integration_test.go @@ -25,6 +25,7 @@ import ( type countingRoot struct { mu sync.Mutex started []string + mirrors []string } func (r *countingRoot) Transaction(kind, run string, ignore []string) error { @@ -36,6 +37,20 @@ func (r *countingRoot) Transaction(kind, run string, ignore []string) error { func (r *countingRoot) Rollback(string, []RollbackItem) error { return nil } func (r *countingRoot) Journal(string, int) ([]string, error) { return nil, nil } func (r *countingRoot) Maps() ([]Mapped, error) { return []Mapped{}, nil } + +// Mirrorlist keeps the mirror list written last (ADR 0585 §3). +func (r *countingRoot) Mirrorlist(servers []string) error { + r.mu.Lock() + defer r.mu.Unlock() + r.mirrors = append([]string(nil), servers...) + return nil +} + +func (r *countingRoot) mirrorlist() []string { + r.mu.Lock() + defer r.mu.Unlock() + return r.mirrors +} func (r *countingRoot) count() int { r.mu.Lock() defer r.mu.Unlock() @@ -69,20 +84,30 @@ func startRoundNode(t *testing.T, ctx context.Context, url, node string, order [ began := time.Now() m.Now = func() time.Time { return t0.Add(time.Since(began)) } m.ReadFile = func(path string) ([]byte, error) { - if path == OSRelease { + switch path { + case OSRelease: return []byte("7.2.8-arch1-2\n"), nil + case ReflectorConf: + return []byte("--sort rate\n"), nil } return nil, errNoFile } n := &roundNode{root: &countingRoot{}, signals: make(chan Signal)} k := &Keeper{Config: KeeperConfig{UpgradeOrder: order, RecordDays: 180, RoundStartMinutes: 120}, Machine: m, Clock: realClock{}, Watcher: fakeWatcher{n.signals}, Logf: func(f string, a ...any) { t.Logf(node+": "+f, a...) }, MakeHooks: keeperHooks, - Root: n.root, Check: func(Run, *Record) Check { return Check{Passed: passes} }} + Root: n.root, Check: func(Run, *Record) Check { return Check{Passed: passes} }, + // The mesh's mirrors, ranked by the node that opens the round (ADR 0585 §2): reflector stood in for. + Rank: func(_ []byte, round string) (MirrorList, error) { + return MirrorList{Servers: roundMirrors, RankedAt: t0, RankedBy: node, Round: round}, nil + }} account := process.Account{URL: url, Node: node, Module: "pacman", User: node + ".pacman.keeper", Password: "pw"} go func() { _ = runKeeper(ctx, account, k) }() return n } +// roundMirrors is the mirror list the round's opener ranks. +var roundMirrors = []string{"https://nl.mirror.example/archlinux/$repo/os/$arch", "https://de.mirror.example/$repo/os/$arch"} + func roundBus(t *testing.T) (string, map[string]jetstream.KeyValue) { t.Helper() url := newTestBus(t) @@ -152,6 +177,22 @@ func TestTheRoundGoesNodeByNodeOnARealBus(t *testing.T) { if a.root.count() != 1 { t.Errorf("node-a ran again: %v", a.root.started) } + // ADR 0585 §2, §3: the round opened naming the revision of the list node-a ranked in the write that opened it, and + // both nodes wrote that list whole to their mirror list file, from the bus. + e, err := buckets[StateRounds].Get(context.Background(), round) + var opened Round + if err == nil { + _ = json.Unmarshal(e.Value(), &opened) + } + l, lerr := buckets[StateMirrors].Get(context.Background(), MirrorsKey) + if err != nil || lerr != nil || opened.Mirrors == 0 || opened.Mirrors != l.Revision() || !strings.Contains(string(l.Value()), `"round":"`+round+`"`) { + t.Errorf("the round opened with mirrors %d (%q), the list %v (%v, %v)", opened.Mirrors, opened.MirrorsNote, l, err, lerr) + } + for _, n := range []*roundNode{a, b} { + eventually(t, "each node wrote the mesh's mirror list", 10*time.Second, func() bool { + return strings.Join(n.root.mirrorlist(), " ") == strings.Join(roundMirrors, " ") + }) + } } func TestAFailedCheckStopsTheRoundOnARealBus(t *testing.T) { diff --git a/modules/pacman/cmd/pacman-tools/rounds.go b/modules/pacman/cmd/pacman-tools/rounds.go index dcb10823..a606531b 100644 --- a/modules/pacman/cmd/pacman-tools/rounds.go +++ b/modules/pacman/cmd/pacman-tools/rounds.go @@ -238,8 +238,15 @@ func (u *Upgrades) RoundStep() (time.Time, error) { soonest(opening.AddDate(0, 0, 7)) id := RoundID(now) round := Round{Round: id, Opened: now.UTC(), OpenedBy: u.Node, Order: append([]string(nil), order...)} - if _, err := u.Rounds.Create(id, round); err != nil && !errors.Is(err, stdio.ErrChanged) { - errs = append(errs, fmt.Errorf("opening round %s: %w", id, err)) + // The mirrors are ranked inside the write that opens the round, before its key, which names the list's + // revision (ADR 0585 §2): every node of the round upgrades from that list. + if e, err := u.Rounds.Get(id); err != nil { + errs = append(errs, fmt.Errorf("reading round %s: %w", id, err)) + } else if e == nil { + round.Mirrors, round.MirrorsNote = u.mirrorsForRound(id) + if _, err := u.Rounds.Create(id, round); err != nil && !errors.Is(err, stdio.ErrChanged) { + errs = append(errs, fmt.Errorf("opening round %s: %w", id, err)) + } } } } diff --git a/modules/pacman/cmd/pacman-tools/shapes.go b/modules/pacman/cmd/pacman-tools/shapes.go index 3c364538..f79aedb3 100644 --- a/modules/pacman/cmd/pacman-tools/shapes.go +++ b/modules/pacman/cmd/pacman-tools/shapes.go @@ -35,10 +35,17 @@ const ( // StateAsks holds the acts asked of a node: key `.` an Ask, taken by that node's keeper alone // (ADR 0508 §8). StateAsks = "asks" + // StateMirrors holds the mesh's one mirror list: key `list` (MirrorsKey) a MirrorList, written by the keeper that + // ranks it, in the write that opens a round or on a refresh, and written to every node's mirror list file by that + // node's keeper (novox/hq ADR 0585). + StateMirrors = "mirrors" ) +// MirrorsKey is StateMirrors' one key. +const MirrorsKey = "list" + // States are the module's states, in the manifest's order. -var States = []string{StateInstalled, StateUpdates, StateRuns, StateRecords, StateRounds, StateAsks} +var States = []string{StateInstalled, StateUpdates, StateRuns, StateRecords, StateRounds, StateAsks, StateMirrors} // The events the keeper emits (the keeper's `bus` `emits`, and the manifest's `emits`). const ( @@ -319,6 +326,23 @@ type Round struct { Opened time.Time `json:"opened"` OpenedBy string `json:"opened_by"` Order []string `json:"order"` + // Mirrors is the revision of `mirrors.list` the round opened with, ranked in the write that opened it (ADR 0585 + // §2); MirrorsNote says why the list was not ranked again, when it was not (the round then opens with the list + // there is, at revision Mirrors, zero when there is none). + Mirrors uint64 `json:"mirrors,omitempty"` + MirrorsNote string `json:"mirrors_note,omitempty"` +} + +// MirrorList is `mirrors.list`, the mesh's one mirror list (ADR 0585 §1): the servers in order, when and by which +// node they were ranked, the options reflector ranked them with, the newest last sync found among them (only mirrors as +// fresh as it are kept, §2), and the round it was ranked for (none for a refresh). +type MirrorList struct { + Servers []string `json:"servers"` + RankedAt time.Time `json:"ranked_at"` + RankedBy string `json:"ranked_by"` + Options []string `json:"options"` + Newest time.Time `json:"newest_sync"` + Round string `json:"round,omitempty"` } // RoundNode is `rounds..`: the node's place in the round. Run is the run it started in its turn, @@ -354,6 +378,7 @@ const ( ActUpgrade = "upgrade" // pacman_upgrade ActRollback = "rollback" // pacman_rollback with apply ActPass = "pass" // pacman_round with pass + ActMirrors = "mirrors" // pacman_mirrors with refresh: the mesh's list ranked again (ADR 0585 §4) ) // Ask is `asks..`: an act asked of a node, taken by that node's keeper alone, which answers in `runs` diff --git a/modules/pacman/cmd/pacman-tools/transaction.go b/modules/pacman/cmd/pacman-tools/transaction.go index 13fcd6ca..515394eb 100644 --- a/modules/pacman/cmd/pacman-tools/transaction.go +++ b/modules/pacman/cmd/pacman-tools/transaction.go @@ -403,6 +403,13 @@ func (u *Upgrades) TakeAsk(c stdio.StateChange) error { return err } return u.Asks.Delete(c.Key) + case ActMirrors: + // Ranked once, whatever came of it: a refresh refused during a round or failed is said and not tried again. + err := u.takeMirrorsAsk() + if derr := u.Asks.Delete(c.Key); derr != nil { + err = errors.Join(err, fmt.Errorf("deleting the ask %s: %w", c.Key, derr)) + } + return err default: return fmt.Errorf("ask %s asks %q, which this keeper does not carry out yet", c.Key, a.Act) } diff --git a/modules/pacman/cmd/pacman-tools/transaction_test.go b/modules/pacman/cmd/pacman-tools/transaction_test.go index 7902d29e..1ea5466a 100644 --- a/modules/pacman/cmd/pacman-tools/transaction_test.go +++ b/modules/pacman/cmd/pacman-tools/transaction_test.go @@ -7,6 +7,7 @@ import ( "encoding/json" "errors" "strings" + "sync" "testing" "time" @@ -20,6 +21,25 @@ type fakeRoot struct { journal []string mapped []Mapped mapsErr error + // mirrors is each mirror list written, whole (ADR 0585 §3), under mu: the keeper's loop writes it. + mu sync.Mutex + mirrors [][]string +} + +func (f *fakeRoot) Mirrorlist(servers []string) error { + if f.fail != nil { + return f.fail + } + f.mu.Lock() + defer f.mu.Unlock() + f.mirrors = append(f.mirrors, append([]string(nil), servers...)) + return nil +} + +func (f *fakeRoot) written() [][]string { + f.mu.Lock() + defer f.mu.Unlock() + return append([][]string(nil), f.mirrors...) } func (f *fakeRoot) Transaction(kind, run string, ignore []string) error { diff --git a/modules/pacman/cmd/pacman-tools/upgrades.go b/modules/pacman/cmd/pacman-tools/upgrades.go index 1ed15457..bbcea4c3 100644 --- a/modules/pacman/cmd/pacman-tools/upgrades.go +++ b/modules/pacman/cmd/pacman-tools/upgrades.go @@ -43,6 +43,8 @@ type RootActs interface { // run), carrying out the plan in the request (ADR 0510: the plan travels with the verb), and answers once it // started. Rollback(run string, plan []RollbackItem) error + // Mirrorlist writes the node's mirror list file whole with these servers (ADR 0585 §3). + Mirrorlist(servers []string) error // Journal is the last n lines a transaction unit logged. Journal(unit string, n int) ([]string, error) // Maps is every process still mapping a replaced file, by its unit or container and its executable. @@ -62,7 +64,10 @@ type Upgrades struct { Root RootActs Events EventSink // The module's states. - Installed, Updates, Runs, Records, Rounds, Asks Bucket + Installed, Updates, Runs, Records, Rounds, Asks, Mirrors Bucket + // Rank ranks the mesh's mirrors with the module's reflector options (ADR 0585 §2); nil ranks none, and a round + // then opens with the list there is. + Rank func(conf []byte, round string) (MirrorList, error) // AskRecord reads the operator channel's record of one of this module's asks (process.Conn.Ask on // MessengerAsksBucket): how a pass is answered. AskRecord func(id string) (*stdio.StateEntry, error) diff --git a/modules/pacman/files/reflector.conf b/modules/pacman/files/reflector.conf index eb9e731b..91bad4c7 100644 --- a/modules/pacman/files/reflector.conf +++ b/modules/pacman/files/reflector.conf @@ -1,7 +1,7 @@ -# The mesh's (module pacman, novox/hq to-be 42): how reflector refreshes the mirror list, weekly, -# through reflector.timer. Written whole at every push. Before the module, every machine's list was -# generated once and never again. ---save /etc/pacman.d/mirrorlist +# The mesh's (module pacman, novox/hq ADR 0585): the options reflector ranks the mesh's one mirror list with. +# The keeper of the node that opens a week's upgrade round runs reflector with them (and --info) and keeps only the +# mirrors as fresh as the newest; every node writes /etc/pacman.d/mirrorlist from that list. reflector's own timer +# stays disabled, and nothing here saves a list. Written whole at every push. --protocol https --country Belgium,Netherlands,Luxembourg,Germany,France --latest 20 diff --git a/modules/pacman/module.json b/modules/pacman/module.json index 7029d0fe..2213c136 100644 --- a/modules/pacman/module.json +++ b/modules/pacman/module.json @@ -53,7 +53,8 @@ "runs", "records", "rounds", - "asks" + "asks", + "mirrors" ], "emits": [ "package.changed", @@ -122,11 +123,8 @@ "id": "mirror-refresh", "type": "service", "unit": "reflector.timer", - "state": "running", - "boot": "enabled", - "health": { - "kind": "unit" - } + "state": "stopped", + "boot": "disabled" }, { "id": "cache-cleaning", @@ -207,7 +205,8 @@ "runs", "records", "rounds", - "asks" + "asks", + "mirrors" ], "emits": [ "package.changed", From a6c2f7b31ac533130404aed9a045e4a4262a0156 Mon Sep 17 00:00:00 2001 From: jochen Date: Sun, 1 Nov 2026 16:19:13 +0100 Subject: [PATCH 3/7] mesh-provisioner: compose a node once and read its own states from the copy (issue 1954) provisioner_compose took 2.6-13.6 s per node with nothing changed, CPU bound. The node is now composed at its wanted and its newest builds over one read (frombus.PlansHeldTwice, whose composer resolves each machine once), its own plans, provisions and refusals and the providers' entries are read from the watched copy, its own writes taken in at once, and a provider's manifest once by digest: no read by key per composition is left. The result says where the time went, phase by phase, and a slow composition that changed nothing says it in the log. BenchmarkComposeNode times it over a mesh captured with the read tools (MESH_COMPOSE_CAPTURE): novox 11.7 s to 0.49 s, ace 0.49 s, g14 and shanks 0.39 s; plans and provisions identical to before over nine compositions of the four nodes. Needs mesh-sdk feat/compose-once (5d26c65); go.mod still pins the old mesh-sdk until the group pins its head. Claude-Session: https://claude.ai/code/session_01NcbgfJ9Gum47zkFKWRaovL --- .../mesh-provisioner/compose_bench_test.go | 225 ++++++++++++++++++ .../cmd/mesh-provisioner/holder.go | 151 ++++++++++-- .../holder_integration_test.go | 5 +- .../cmd/mesh-provisioner/holder_test.go | 28 ++- .../cmd/mesh-provisioner/main.go | 24 +- 5 files changed, 389 insertions(+), 44 deletions(-) create mode 100644 modules/mesh-provisioner/cmd/mesh-provisioner/compose_bench_test.go diff --git a/modules/mesh-provisioner/cmd/mesh-provisioner/compose_bench_test.go b/modules/mesh-provisioner/cmd/mesh-provisioner/compose_bench_test.go new file mode 100644 index 00000000..0b901b32 --- /dev/null +++ b/modules/mesh-provisioner/cmd/mesh-provisioner/compose_bench_test.go @@ -0,0 +1,225 @@ +package main + +// BenchmarkComposeNode times ComposeNode of an unchanged node over a mesh captured from the bus (issue 1954): the +// placement, wants, haves, the indexer's modules and manifests, the builder's builds, mesh-config's resolved values and +// the templates archives, read with the read tools (mesh-placement.placement, mesh-delivery-view.assigner_wants, +// node_haves, indexer_modules, builder_build, mesh-config.config) and the manifests and archives by digest. The capture +// is not kept in this repository (a few megabytes, and the mesh's own addresses and keys): the benchmark reads the +// directory MESH_COMPOSE_CAPTURE names and is skipped without it. MESH_COMPOSE_NODE names the node (novox when unset). +// +// The capture's layout: placement.json, wants.json, haves.json, modules.json and config.json as those tools answer, +// builds/..json as builder_build answers, manifests/ and archives/ as their bytes. + +import ( + "context" + "encoding/json" + "os" + "path/filepath" + "strings" + "sync/atomic" + "testing" + "time" + + stdio "git.novox.be/novox/mesh-sdk/go" + "git.novox.be/novox/mesh-sdk/go/compose/frombus" + "git.novox.be/novox/mesh-sdk/go/compose/fromruntime" + "git.novox.be/novox/mesh-sdk/go/delivery" +) + +// countingStore counts the holder's reads of its own states (and the providers' entries), each a bus request live. +type countingStore struct { + Store + gets, keys atomic.Int64 +} + +func (c *countingStore) Get(state, key string) (*Entry, error) { + c.gets.Add(1) + return c.Store.Get(state, key) +} + +func (c *countingStore) Keys(state string) ([]string, error) { + c.keys.Add(1) + return c.Store.Keys(state) +} + +// captured is the captured mesh as the states the holder reads, and the archives by digest. +func captured(b *testing.B, dir string) (map[string]map[string][]byte, map[string][]byte) { + b.Helper() + read := func(name string, into any) { + raw, err := os.ReadFile(filepath.Join(dir, name)) + if err != nil { + b.Fatal(err) + } + if err := json.Unmarshal(raw, into); err != nil { + b.Fatalf("%s: %v", name, err) + } + } + states := map[string]map[string][]byte{} + put := func(state, key string, raw []byte) { + if states[state] == nil { + states[state] = map[string][]byte{} + } + states[state][key] = raw + } + var placement struct { + Keys map[string]struct { + Placement json.RawMessage `json:"placement"` + } `json:"keys"` + } + read("placement.json", &placement) + for node, k := range placement.Keys { + var p delivery.Placement + if err := json.Unmarshal(k.Placement, &p); err != nil { + b.Fatal(err) + } + p.Node = node + raw, err := delivery.EncodePlacement(p) + if err != nil { + b.Fatal(err) + } + put(PlacementRead, "placement."+node, raw) + } + var wants struct { + Wants map[string]json.RawMessage `json:"wants"` + } + read("wants.json", &wants) + for k, v := range wants.Wants { + put(WantsRead, k, v) + } + var haves struct { + Keys map[string]json.RawMessage `json:"keys"` + } + read("haves.json", &haves) + for k, v := range haves.Keys { + put(HaveRead, k, v) + } + var modules struct { + Modules map[string]json.RawMessage `json:"modules"` + } + read("modules.json", &modules) + for m, v := range modules.Modules { + key, err := delivery.ModulesKey(m) + if err != nil { + b.Fatal(err) + } + put(ModulesRead, key, v) + } + var config struct { + Resolved []struct { + Key, Module, Node, Source string + Value any + } `json:"resolved"` + } + read("config.json", &config) + for _, r := range config.Resolved { + raw, _ := json.Marshal(map[string]any{"value": r.Value, "source": r.Source}) + put(ResolvedRead, r.Node+"."+r.Module+"."+r.Key, raw) + } + manifests, _ := filepath.Glob(filepath.Join(dir, "manifests", "*")) + for _, f := range manifests { + raw, err := os.ReadFile(f) + if err != nil { + b.Fatal(err) + } + digest := filepath.Base(f) + v, err := delivery.EncodeManifest(delivery.Manifest{Module: "captured", JSON: string(raw)}) + if err != nil { + b.Fatal(err) + } + key, err := delivery.ManifestsKey(digest) + if err != nil { + b.Fatal(err) + } + put(ManifestsRead, key, v) + } + builds, _ := filepath.Glob(filepath.Join(dir, "builds", "*.json")) + for _, f := range builds { + var bb struct { + Module string `json:"module"` + Fingerprint string `json:"fingerprint"` + Build json.RawMessage `json:"build"` + } + read(strings.TrimPrefix(f, dir+"/"), &bb) + key, err := delivery.BuilderBuildKey(bb.Module, bb.Fingerprint) + if err != nil { + b.Fatal(err) + } + put(BuildsRead, key, bb.Build) + } + archives := map[string][]byte{} + files, _ := filepath.Glob(filepath.Join(dir, "archives", "*")) + for _, f := range files { + raw, err := os.ReadFile(f) + if err != nil { + b.Fatal(err) + } + archives[filepath.Base(f)] = raw + } + return states, archives +} + +func BenchmarkComposeNode(b *testing.B) { + dir := os.Getenv("MESH_COMPOSE_CAPTURE") + if dir == "" { + b.Skip("MESH_COMPOSE_CAPTURE names no captured mesh") + } + node := os.Getenv("MESH_COMPOSE_NODE") + if node == "" { + node = "novox" + } + states, archives := captured(b, dir) + ws := stdio.WatchedStatesOver(func(state string, handle func(stdio.StateChange) error) error { + for k, v := range states[state] { + if err := handle(stdio.StateChange{State: state, Key: k, Op: stdio.OpPut, Value: v, Current: true}); err != nil { + return err + } + } + return nil + }, func(state, key string) ([]byte, bool, error) { + v, ok := states[state][key] + return v, ok, nil + }) + fetch := fromruntime.KeptFetch(func(_ context.Context, url string) ([]byte, error) { + _, hex, _ := strings.Cut(url, "sha256:") + raw, ok := archives[hex] + if !ok { + return nil, os.ErrNotExist + } + return raw, nil + }) + own := &countingStore{Store: newStore()} + h := &Holder{Store: Watching(own, ws), Compose: composerOver(frombus.StatesReader(fromruntime.Watched{WatchedStates: ws}, fetch)), + Now: time.Now, Logf: func(string, ...any) {}} + // Composed twice before it is timed: a provision's state follows the states of those it depends on, which the first + // composition writes, so the second may still change a key; from then on nothing changes. + first, err := h.ComposeNode(context.Background(), node) + if err != nil { + b.Fatal(err) + } + if second, err := h.ComposeNode(context.Background(), node); err != nil { + b.Fatal(err) + } else if len(second.Changed) > 0 { + b.Logf("the second composition of %s changed %v", node, second.Changed) + } + b.Logf("first composition of %s: %d plans written, %d held, %d problems, %d keys changed", node, len(first.Plans), + len(first.Held), len(first.Problems), len(first.Changed)) + for _, p := range first.Problems { + b.Logf("problem: %s", p) + } + own.gets.Store(0) + own.keys.Store(0) + b.ResetTimer() + var c Composed + for b.Loop() { + c, err = h.ComposeNode(context.Background(), node) + if err != nil { + b.Fatal(err) + } + if len(c.Plans)+len(c.Gone)+len(c.Changed) > 0 { + b.Fatalf("an unchanged node composed changes: %+v", c) + } + } + b.Logf("the last composition of %s: %s", node, TookSaid(c.Took)) + b.ReportMetric(float64(own.gets.Load())/float64(b.N), "own-gets/op") + b.ReportMetric(float64(own.keys.Load())/float64(b.N), "own-keys/op") +} diff --git a/modules/mesh-provisioner/cmd/mesh-provisioner/holder.go b/modules/mesh-provisioner/cmd/mesh-provisioner/holder.go index 2a7ee6bd..a15e1abc 100644 --- a/modules/mesh-provisioner/cmd/mesh-provisioner/holder.go +++ b/modules/mesh-provisioner/cmd/mesh-provisioner/holder.go @@ -75,12 +75,18 @@ var BoundReads = []string{"gitea", "keycloak", "postgres", "route-adapter", "rou // boundRead is a provider's entries as this module reads them. func boundRead(module string) string { return module + ".bound" } -// Composer is each module's provisioning plan on a node, composed from the bus: at the builds keptAt names -// (module → fingerprint), the newest build of every other placed module. A module whose build or plan refuses is held -// (frombus.PlansHeld; issue 774, one bad module must not drop its node): in held with why, none of its plan in plans. -// err is a refusal that is no single module's. -type Composer func(ctx context.Context, node string, keptAt map[string]string) (plans map[string]catalogue.Plan, - held map[string]string, err error) +// Composer is a node's provisioning plans, composed from the bus over one read: at the builds keptAt names (module → +// fingerprint, the newest build of every other placed module), and at the newest build of each placed module (issue +// 1954: once, not twice). A module whose build or plan refuses is held (frombus.PlansHeld; issue 774, one bad module +// must not drop its node): in held with why, none of its plan in plans; a scope's Err is a refusal that is no single +// module's. +type Composer func(ctx context.Context, node string, keptAt map[string]string) Composition + +// Composition is a node's plans at its wanted builds and at its newest, and where the time went. +type Composition struct { + AtWants, Newest frombus.HeldPlans + Took []frombus.Phase +} // Asker is the operator's channel as this module asks on it: publish an ask under its own name, and read the router's // record of it. @@ -111,13 +117,40 @@ type Composed struct { // stay as they were, and every other module is composed (issue 774). Held map[string]string `json:"modules-held,omitempty"` Problems []string `json:"problems,omitempty"` + // Took is where the composition's time went, phase by phase in milliseconds, its whole last (issue 1954). + Took []Took `json:"took"` +} + +// Took is one phase of a composition and its milliseconds. +type Took struct { + Phase string `json:"phase"` + MS int64 `json:"ms"` +} + +// TookSaid says a composition's phases in one line. +func TookSaid(took []Took) string { + var said []string + for _, t := range took { + said = append(said, fmt.Sprintf("%s %d ms", t.Phase, t.MS)) + } + return strings.Join(said, ", ") } // ComposeNode composes one node: its plans and its provisions. -func (h *Holder) ComposeNode(ctx context.Context, node string) (Composed, error) { +func (h *Holder) ComposeNode(ctx context.Context, node string) (out Composed, err error) { h.mu.Lock() defer h.mu.Unlock() - out := Composed{Node: node} + out = Composed{Node: node} + began, start := time.Now(), time.Now() + mark := func(phase string, took time.Duration) { + out.Took = append(out.Took, Took{Phase: phase, MS: took.Milliseconds()}) + } + lap := func(phase string) { + now := time.Now() + mark(phase, now.Sub(start)) + start = now + } + defer func() { mark("whole", time.Since(began)) }() wanted, err := h.wantedOn(node) if err != nil { return out, err @@ -129,14 +162,19 @@ func (h *Holder) ComposeNode(ctx context.Context, node string) (Composed, error) wanted[module] = fp } } - atWants, heldAtWants, err := h.Compose(ctx, node, wanted) - if err != nil { - return out, fmt.Errorf("the plans of %s cannot be composed: %w", node, err) + lap("wants") + c := h.Compose(ctx, node, wanted) + for _, p := range c.Took { + mark(p.Name, p.Took) } - newest, heldNewest, err := h.Compose(ctx, node, nil) - if err != nil { - return out, fmt.Errorf("the plans of %s at the newest builds cannot be composed: %w", node, err) + start = time.Now() + if c.AtWants.Err != nil { + return out, fmt.Errorf("the plans of %s cannot be composed: %w", node, c.AtWants.Err) } + if c.Newest.Err != nil { + return out, fmt.Errorf("the plans of %s at the newest builds cannot be composed: %w", node, c.Newest.Err) + } + atWants, heldAtWants, newest, heldNewest := c.AtWants.Plans, c.AtWants.Held, c.Newest.Plans, c.Newest.Held // A module held at its wanted build has no plan composed: its last plan and its provisions are kept, said in // `refused`. One held at its newest build alone keeps its plan at its want; what its newest build needs ahead waits. if len(heldAtWants) > 0 { @@ -153,6 +191,7 @@ func (h *Holder) ComposeNode(ctx context.Context, node string) (Composed, error) if err := h.writePlans(node, atWants, heldAtWants, &out); err != nil { out.Problems = append(out.Problems, err.Error()) } + lap("plans written") needed := map[string]provisions.Provision{} elsewhere := map[string]provisions.Provision{} vaultNode := h.vaultNode() @@ -199,6 +238,7 @@ func (h *Holder) ComposeNode(ctx context.Context, node string) (Composed, error) } h.judgeElsewhere(elsewhere, &out) h.judgeNode(node, needed, heldAtWants, &out) + lap("provisions judged") return out, nil } @@ -1046,21 +1086,40 @@ func orSaid(words ...string) string { } // FromWatched is the holder's composer over one watched copy of its reads (novox/hq ADR 0580 clause 2): frombus's plans -// of a node, at the builds keptAt names, read from the copy (placement, haves, modules, resolved values), a build by key -// and a manifest once per digest; no state is read key by key per composition. A plan names no value, so no own secret -// and no credential is read (compose.Planning). +// of a node, at the builds keptAt names and at the newest over one read of the copy (placement, haves, modules, +// resolved values), a build by key and a manifest once per digest; no state is read key by key per composition. A plan +// names no value, so no own secret and no credential is read (compose.Planning). func FromWatched(ws *stdio.WatchedStates) Composer { - r := fromruntime.WatchedReader(ws) - return func(ctx context.Context, node string, keptAt map[string]string) (map[string]catalogue.Plan, map[string]string, error) { - return frombus.PlansHeld(ctx, r, frombus.Mesh{}, frombus.Scope{Node: node, KeptAt: keptAt}) + return composerOver(fromruntime.WatchedReader(ws)) +} + +// composerOver is the holder's composer over a reader: both scopes over one read (frombus.PlansHeldTwice). +func composerOver(r frombus.Reader) Composer { + return func(ctx context.Context, node string, keptAt map[string]string) Composition { + at, newest, took := frombus.PlansHeldTwice(ctx, r, frombus.Mesh{}, frombus.Scope{Node: node, KeptAt: keptAt}) + return Composition{AtWants: at, Newest: newest, Took: took} } } // WatchedReads are the states the holder reads whole, each from the watched copy: what the composer reads and the -// wants (ADR 0580 clause 2). Its own states and the providers' entries stay read from the bus, after its own writes. -var WatchedReads = []string{PlacementRead, WantsRead, ModulesRead, HaveRead, ResolvedRead} +// wants (ADR 0580 clause 2), and the providers' entries, whose watch is also what rejudges a key. +var WatchedReads = append([]string{PlacementRead, WantsRead, ModulesRead, HaveRead, ResolvedRead}, boundReads()...) -// Watching is a Store whose WatchedReads come from the copy; every other state, and every write, from s. +// OwnStates are the states the holder alone writes (ADR 0570 clause 1), read from the watched copy too (issue 1954: some +// 250 to 400 reads by key per composition): each of its own writes is taken into the copy at once (WatchedStates.Wrote), +// so it reads back what it wrote before the watch hands it back. +var OwnStates = []string{PlansState, ProvisionsState, RefusedState} + +func boundReads() []string { + out := make([]string, 0, len(BoundReads)) + for _, p := range BoundReads { + out = append(out, boundRead(p)) + } + return out +} + +// Watching is a Store whose WatchedReads and OwnStates come from the copy, its writes of OwnStates taken into the copy as +// they land, and a manifest read once by its digest; every other state, and every write, from s. func Watching(s Store, ws *stdio.WatchedStates) Store { return watchingStore{Store: s, ws: ws} } type watchingStore struct { @@ -1068,11 +1127,24 @@ type watchingStore struct { ws *stdio.WatchedStates } +// RevisionPutter is a Store that says the revision a put landed at (the bus does), so the copy keeps it exactly. +type RevisionPutter interface { + PutRevision(state, key string, value any) (uint64, error) +} + +func (w watchingStore) copied(state string) bool { + return slices.Contains(WatchedReads, state) || slices.Contains(OwnStates, state) +} + func (w watchingStore) Get(state, key string) (*Entry, error) { - if !slices.Contains(WatchedReads, state) { + get := w.ws.Get + switch { + case state == ManifestsRead: + get = w.ws.Once // a manifest by its digest never changes: read once, kept (ADR 0580 clause 1) + case !w.copied(state): return w.Store.Get(state, key) } - v, found, err := w.ws.Get(state, key) + v, found, err := get(state, key) if err != nil || !found { return nil, err } @@ -1080,12 +1152,39 @@ func (w watchingStore) Get(state, key string) (*Entry, error) { } func (w watchingStore) Keys(state string) ([]string, error) { - if !slices.Contains(WatchedReads, state) { + if !w.copied(state) { return w.Store.Keys(state) } return w.ws.Keys(state) } +func (w watchingStore) Put(state, key string, value any) error { + if !slices.Contains(OwnStates, state) { + return w.Store.Put(state, key, value) + } + raw, err := json.Marshal(value) + if err != nil { + return err + } + var revision uint64 + if rp, ok := w.Store.(RevisionPutter); ok { + revision, err = rp.PutRevision(state, key, json.RawMessage(raw)) + } else { + err = w.Store.Put(state, key, json.RawMessage(raw)) + } + if err != nil { + return err + } + return w.ws.Wrote(state, key, raw, revision) +} + +func (w watchingStore) Delete(state, key string) error { + if err := w.Store.Delete(state, key); err != nil || !slices.Contains(OwnStates, state) { + return err + } + return w.ws.Removed(state, key) +} + // NodesOfNodeKey is the node a key that starts with it names: a resolved value's `..`, a have's // `.` or `.node`. A change of either recomposes that node (ADR 0580 clause 2). func NodesOfNodeKey(key string) []string { diff --git a/modules/mesh-provisioner/cmd/mesh-provisioner/holder_integration_test.go b/modules/mesh-provisioner/cmd/mesh-provisioner/holder_integration_test.go index 708f4571..e5a56156 100644 --- a/modules/mesh-provisioner/cmd/mesh-provisioner/holder_integration_test.go +++ b/modules/mesh-provisioner/cmd/mesh-provisioner/holder_integration_test.go @@ -22,7 +22,6 @@ import ( stdio "git.novox.be/novox/mesh-sdk/go" "git.novox.be/novox/mesh-sdk/go/asks" - "git.novox.be/novox/mesh-sdk/go/catalogue" "git.novox.be/novox/mesh-sdk/go/compose/frombus" "git.novox.be/novox/mesh-sdk/go/compose/frombus/frombustest" "git.novox.be/novox/mesh-sdk/go/compose/fromruntime" @@ -262,9 +261,7 @@ func TestTheHolderComposesProvidesAndAsksOnTheBus(t *testing.T) { reader := frombus.StatesReader(fromruntime.Watched{WatchedStates: ws}, fetch) a := &asked{} h := &Holder{Store: Watching(s, ws), Asks: a, Now: time.Now, Logf: t.Logf, - Compose: func(ctx context.Context, node string, keptAt map[string]string) (map[string]catalogue.Plan, map[string]string, error) { - return frombus.PlansHeld(ctx, reader, frombus.Mesh{}, frombus.Scope{Node: node, KeptAt: keptAt}) - }} + Compose: composerOver(reader)} state := func(key string) provisions.Provision { e, _ := s.Get(ProvisionsState, key) if e == nil { diff --git a/modules/mesh-provisioner/cmd/mesh-provisioner/holder_test.go b/modules/mesh-provisioner/cmd/mesh-provisioner/holder_test.go index 96c53213..31638dc1 100644 --- a/modules/mesh-provisioner/cmd/mesh-provisioner/holder_test.go +++ b/modules/mesh-provisioner/cmd/mesh-provisioner/holder_test.go @@ -15,6 +15,7 @@ import ( stdio "git.novox.be/novox/mesh-sdk/go" "git.novox.be/novox/mesh-sdk/go/asks" "git.novox.be/novox/mesh-sdk/go/catalogue" + "git.novox.be/novox/mesh-sdk/go/compose/frombus" "git.novox.be/novox/mesh-sdk/go/delivery" "git.novox.be/novox/mesh-sdk/go/provisions" ) @@ -68,12 +69,10 @@ func newMesh() *mesh { now := time.Date(2026, 10, 29, 22, 0, 0, 0, time.UTC) m.h = &Holder{Store: m.s, Asks: m.r, Logf: func(string, ...any) {}, Now: func() time.Time { now = now.Add(time.Second); return now }, - Compose: func(_ context.Context, node string, keptAt map[string]string) (map[string]catalogue.Plan, map[string]string, error) { + Compose: func(_ context.Context, node string, keptAt map[string]string) Composition { m.composed = append(m.composed, node) - if keptAt != nil { - return m.atWant[node], m.heldAt[node], nil - } - return m.atNewest[node], nil, nil + return Composition{AtWants: frombus.HeldPlans{Plans: m.atWant[node], Held: m.heldAt[node]}, + Newest: frombus.HeldPlans{Plans: m.atNewest[node]}} }} // What each provider's manifest declares: postgres, keycloak and the vault keep entries, the others report by their // have. @@ -385,12 +384,9 @@ func TestAModuleHeldWithoutAWantIsComposedAtTheBuildItRuns(t *testing.T) { m.s.write(t, HaveRead, "novox.nats", `{"v":1,"fp":"`+fp+`","phase":"running","health":"ok"}`) m.s.write(t, HaveRead, "g14.dunst", `{"v":1,"fp":"src2:`+strings.Repeat("ee", 32)+`","phase":"running","health":"ok"}`) var keptAt map[string]string - m.h.Compose = func(_ context.Context, node string, at map[string]string) (map[string]catalogue.Plan, map[string]string, error) { - if at != nil { - keptAt = at - return map[string]catalogue.Plan{"nats": {}}, nil, nil - } - return nil, nil, nil + m.h.Compose = func(_ context.Context, node string, at map[string]string) Composition { + keptAt = at + return Composition{AtWants: frombus.HeldPlans{Plans: map[string]catalogue.Plan{"nats": {}}}} } // ADR 0580 clause 2: the reads come from one watched copy, each state watched once and none read key by key from the // bus, and a change the copy takes wakes the node it touches (a resolved value its node). @@ -419,8 +415,16 @@ func TestAModuleHeldWithoutAWantIsComposedAtTheBuildItRuns(t *testing.T) { if i == 0 && !slices.Contains(c.Plans, "novox.nats") { t.Fatalf("no plan written for a module held without a want: %+v", c) } + // Issue 1954: its own states come from the copy too, its own writes read back at once (nothing is written + // again), and the result says where the time went, its whole last. + if i == 1 && len(c.Plans)+len(c.Changed) > 0 { + t.Fatalf("composed again unchanged, it wrote %+v: its own writes were not read back", c) + } + if n := len(c.Took); n == 0 || c.Took[n-1].Phase != "whole" || c.Took[0].Phase != "wants" { + t.Fatalf("the composition says its phases as %v", c.Took) + } } - for _, r := range WatchedReads { + for _, r := range append(slices.Clone(WatchedReads), OwnStates...) { if bus.read[r] != 0 || watches[r] > 1 { t.Errorf("%s was read %d times from the bus and watched %d times", r, bus.read[r], watches[r]) } diff --git a/modules/mesh-provisioner/cmd/mesh-provisioner/main.go b/modules/mesh-provisioner/cmd/mesh-provisioner/main.go index dcc74524..33d50c83 100644 --- a/modules/mesh-provisioner/cmd/mesh-provisioner/main.go +++ b/modules/mesh-provisioner/cmd/mesh-provisioner/main.go @@ -43,6 +43,11 @@ func (runtimeStore) Put(state, key string, value any) error { return err } +// PutRevision is Put, saying the revision it landed at. +func (runtimeStore) PutRevision(state, key string, value any) (uint64, error) { + return stdio.State(state).Put(key, value) +} + func (runtimeStore) Delete(state, key string) error { return stdio.State(state).Delete(key) } func (runtimeStore) Keys(state string) ([]string, error) { return stdio.State(state).Keys() } @@ -95,14 +100,28 @@ func (w *work) run(h *Holder) { c, err := h.ComposeNode(context.Background(), n) switch { case err != nil: - logf("[%s] %s is not composed: %v", Module, n, err) + logf("[%s] %s is not composed (%s): %v", Module, n, TookSaid(c.Took), err) case len(c.Plans)+len(c.Gone)+len(c.Changed)+len(c.Asked)+len(c.Problems) > 0: logf("[%s] composed %s: %+v", Module, n, c) + case slowest(c.Took) >= slowAt: + // Nothing changed and it took long: where the time went is said, so a slow composition is seen (issue 1954). + logf("[%s] composed %s, nothing changed: %s", Module, n, TookSaid(c.Took)) } } } } +// slowAt is how long a composition that changed nothing may take before its phases are said. +const slowAt = time.Second + +// slowest is a composition's whole time: its last phase, "whole". +func slowest(took []Took) time.Duration { + if len(took) == 0 { + return 0 + } + return time.Duration(took[len(took)-1].MS) * time.Millisecond +} + func main() { s := runtimeStore{} ws := stdio.NewWatchedStates() // one copy of what it reads, each state by its watch (ADR 0580 clause 2) @@ -122,7 +141,8 @@ func main() { return nil }) for _, provider := range BoundReads { - go stdio.State(boundRead(provider)).Follow("", func(c stdio.StateChange) error { + // Into the copy the holder reads them from, its handler run after the copy took the change. + go ws.Follow(boundRead(provider), func(c stdio.StateChange) error { if said, err := h.Rejudge(c.Key); err != nil { logf("[%s] %s is not judged again: %v", Module, c.Key, err) } else if said != "" { From 7375d613b4119eb16684f722f5de5ecdff03cef4 Mon Sep 17 00:00:00 2001 From: jochen Date: Sun, 1 Nov 2026 16:24:04 +0100 Subject: [PATCH 4/7] Pin pacman and mesh-provisioner to the group's mesh-sdk head b2a27ed5 (issues 1953, 1876, 1954) The delivery group feat/node-packages pins one mesh-sdk head in every member: pacman reads EnginePackagesRead from it, and mesh-provisioner composes a node once with it. Claude-Session: https://claude.ai/code/session_01NcbgfJ9Gum47zkFKWRaovL --- modules/mesh-provisioner/go.mod | 2 +- modules/mesh-provisioner/go.sum | 4 ++-- modules/pacman/go.mod | 2 +- modules/pacman/go.sum | 4 ++-- 4 files changed, 6 insertions(+), 6 deletions(-) diff --git a/modules/mesh-provisioner/go.mod b/modules/mesh-provisioner/go.mod index e9f8e457..19748507 100644 --- a/modules/mesh-provisioner/go.mod +++ b/modules/mesh-provisioner/go.mod @@ -3,7 +3,7 @@ module mesh-provisioner go 1.26.0 require ( - git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261101085317-790d1c82d027 + git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261101151945-b2a27ed5cec4 github.com/nats-io/nats.go v1.54.0 ) diff --git a/modules/mesh-provisioner/go.sum b/modules/mesh-provisioner/go.sum index 37e06a87..4903c2c3 100644 --- a/modules/mesh-provisioner/go.sum +++ b/modules/mesh-provisioner/go.sum @@ -1,5 +1,5 @@ -git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261101085317-790d1c82d027 h1:a33dsavoaqllh40eVICbhxi6Kero1EGSjt1V+2fa2Hk= -git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261101085317-790d1c82d027/go.mod h1:ouERNpZizzwZ0HLEtAypsY9FR20FyUgUYRni6J7kVCY= +git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261101151945-b2a27ed5cec4 h1:xeuMBwOHNKrVUdGVg7Bdv5tkdueBvngwJFyk6n10rp0= +git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261101151945-b2a27ed5cec4/go.mod h1:ouERNpZizzwZ0HLEtAypsY9FR20FyUgUYRni6J7kVCY= github.com/antithesishq/antithesis-sdk-go v0.7.0-default-no-op h1:Z/MZK75wC/NSrkgqeNIa7jexam9uWzhLmFTSCPI/kn0= github.com/antithesishq/antithesis-sdk-go v0.7.0-default-no-op/go.mod h1:FQyySiasQQM8735Ddel3MRojmy4dA1IqCeyJ5jmPMbI= github.com/google/go-tpm v0.9.8 h1:slArAR9Ft+1ybZu0lBwpSmpwhRXaa85hWtMinMyRAWo= diff --git a/modules/pacman/go.mod b/modules/pacman/go.mod index 179b9905..4937e020 100644 --- a/modules/pacman/go.mod +++ b/modules/pacman/go.mod @@ -3,7 +3,7 @@ module pacman go 1.26.0 require ( - git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261101085317-790d1c82d027 + git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261101151945-b2a27ed5cec4 github.com/nats-io/nats-server/v2 v2.11.17 ) diff --git a/modules/pacman/go.sum b/modules/pacman/go.sum index 37e06a87..4903c2c3 100644 --- a/modules/pacman/go.sum +++ b/modules/pacman/go.sum @@ -1,5 +1,5 @@ -git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261101085317-790d1c82d027 h1:a33dsavoaqllh40eVICbhxi6Kero1EGSjt1V+2fa2Hk= -git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261101085317-790d1c82d027/go.mod h1:ouERNpZizzwZ0HLEtAypsY9FR20FyUgUYRni6J7kVCY= +git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261101151945-b2a27ed5cec4 h1:xeuMBwOHNKrVUdGVg7Bdv5tkdueBvngwJFyk6n10rp0= +git.novox.be/novox/mesh-sdk/go v0.1.14-0.20261101151945-b2a27ed5cec4/go.mod h1:ouERNpZizzwZ0HLEtAypsY9FR20FyUgUYRni6J7kVCY= github.com/antithesishq/antithesis-sdk-go v0.7.0-default-no-op h1:Z/MZK75wC/NSrkgqeNIa7jexam9uWzhLmFTSCPI/kn0= github.com/antithesishq/antithesis-sdk-go v0.7.0-default-no-op/go.mod h1:FQyySiasQQM8735Ddel3MRojmy4dA1IqCeyJ5jmPMbI= github.com/google/go-tpm v0.9.8 h1:slArAR9Ft+1ybZu0lBwpSmpwhRXaa85hWtMinMyRAWo= From 3d1a4504064e963f56ea988d0c4e9801c9cd4bfc Mon Sep 17 00:00:00 2001 From: jochen Date: Sun, 1 Nov 2026 16:32:05 +0100 Subject: [PATCH 5/7] =?UTF-8?q?pacman=20starts=20a=20round's=20run=20only?= =?UTF-8?q?=20once=20the=20node's=20file=20holds=20the=20round's=20mirror?= =?UTF-8?q?=20list,=20and=20a=20refresh=20never=20writes=20after=20a=20rou?= =?UTF-8?q?nd=20opened=20(ADR=200585=20=C2=A72,=20=C2=A74;=20review=20roun?= =?UTF-8?q?d=201)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The opener ranked the list and took its turn in the same step, so its upgrade started before the keeper's change hook wrote /etc/pacman.d/mirrorlist, and a failed write on any node was only logged. A round's run now writes the list first and checks the file holds the revision the round opened with; otherwise the run is refused with why and tried again an hour later, as every refused run is. A refresh asks again for a running round right before its write, since ranking takes minutes. Claude-Session: https://claude.ai/code/session_01NcbgfJ9Gum47zkFKWRaovL --- .gitignore | 1 + .../cmd/pacman-tools/keeper_hooks_test.go | 57 +++++++++++++++- modules/pacman/cmd/pacman-tools/mirrors.go | 66 ++++++++++++++++--- .../pacman-tools/round_integration_test.go | 16 ++++- .../pacman/cmd/pacman-tools/transaction.go | 6 ++ 5 files changed, 134 insertions(+), 12 deletions(-) diff --git a/.gitignore b/.gitignore index 6f3d049b..bab11407 100644 --- a/.gitignore +++ b/.gitignore @@ -2,6 +2,7 @@ node_modules/ dist/ # Go tool bundles built in place (go build in a module's cmd/-tools) are build output. +modules/pacman/pacman-tools modules/slack/cmd/slack-tools/slack-tools modules/jetbrains-toolbox/cmd/toolbox-tools/toolbox-tools modules/messenger/cmd/messenger/messenger diff --git a/modules/pacman/cmd/pacman-tools/keeper_hooks_test.go b/modules/pacman/cmd/pacman-tools/keeper_hooks_test.go index a314babc..5b2a0565 100644 --- a/modules/pacman/cmd/pacman-tools/keeper_hooks_test.go +++ b/modules/pacman/cmd/pacman-tools/keeper_hooks_test.go @@ -6,6 +6,7 @@ package main import ( "context" "encoding/json" + "errors" "strings" "testing" "time" @@ -132,9 +133,13 @@ func TestTheFirstNodesKeeperOpensTheRoundAndTakesItsTurn(t *testing.T) { } return MirrorList{Servers: servers, RankedAt: t0, RankedBy: "node-a", Round: round}, nil } + // The node's mirror list file holds what the root helper last wrote. k.Machine.ReadFile = func(path string) ([]byte, error) { - if path == ReflectorConf { + switch w := root.written(); { + case path == ReflectorConf: return []byte("--sort rate\n"), nil + case path == Mirrorlist && len(w) > 0: + return RenderMirrorlist(w[len(w)-1]), nil } return nil, errNoFile } @@ -156,6 +161,17 @@ func TestTheFirstNodesKeeperOpensTheRoundAndTakesItsTurn(t *testing.T) { t.Errorf("the round opened with mirrors %d (%q), the list is %+v at %d (%v)", opened.Mirrors, opened.MirrorsNote, list, rev, err) } until(t, "the list written to the node's file", func() bool { w := root.written(); return len(w) == 1 && w[0][0] == servers[0] }) + // The opener's run starts only once its file holds the round's list (written before the run, not refused for it). + var run Run + if e, _ := states.store(StateRuns).Get(NodeKey("node-a", roundNodeOf(rounds, round, "node-a").Run)); e != nil { + _ = json.Unmarshal(e.Value, &run) + } + if lastStep(run) == StepRefused && strings.Contains(run.Steps[len(run.Steps)-1].Why, "mirror") { + t.Errorf("node-a's run was refused for its mirror list: %+v", run.Steps) + } + if len(root.written()) != 1 { + t.Errorf("the list was written %d times", len(root.written())) + } } // 1841/AC6 through the keeper's loop: a node waits until the node before it passed its check, and starts on @@ -235,8 +251,34 @@ func TestTheKeeperHandsTheOperatorChannelsReaderToTheRound(t *testing.T) { t.Errorf("%s: wrote %v (%v), the root helper wrote %v", step.name, wrote, err, root.written()) } } + // ADR 0585 §2: a round's run starts only once the node's file holds the list the round opened with: none asked of a + // round that opened with no list; refused, naming why, when the bus holds another revision or the file is not written. + rounds0 := states.store(StateRounds) + _, listRev, _ := readMirrorList(mirrors) + file = RenderMirrorlist(good) + for _, c := range []struct { + name, refusal string + opened uint64 + fail error + }{ + {name: "a round that opened with no list", opened: 0}, + {name: "a round whose list the file holds", opened: listRev}, + {name: "a round that opened with another revision", opened: listRev + 7, refusal: "the bus holds revision"}, + {name: "a file that cannot be written", opened: listRev, fail: errors.New("no root"), refusal: "is not written"}, + } { + rounds0.Put("2026-W40", Round{Round: "2026-W40", Opened: t0, Order: []string{"node-a"}, Mirrors: c.opened}) + if c.fail != nil { + file = []byte(mirrorlistReflector) + } + root.fail = c.fail + if why := u.roundMirrorsWritten("2026-W40"); (c.refusal == "") != (why == "") || !strings.Contains(why, c.refusal) { + t.Errorf("%s: %q", c.name, why) + } + } + root.fail = nil + rounds0.Delete("2026-W40") // ADR 0585 §4: a refresh asked of the keeper is refused while a round runs, and ranks the list when none does; the - // ask is taken once either way. + // ask is taken once either way. A round that opens while it ranks refuses its write, naming the round. asks, rounds := states.store(StateAsks), states.store(StateRounds) ranked := 0 u.Rank = func([]byte, string) (MirrorList, error) { ranked++; return MirrorList{Servers: good}, nil } @@ -255,4 +297,15 @@ func TestTheKeeperHandsTheOperatorChannelsReaderToTheRound(t *testing.T) { t.Errorf("a refresh with a round running %v: %v, ranked %d, ask left %v", running, err, ranked, left) } } + _, before, _ := readMirrorList(mirrors) + u.Rank = func([]byte, string) (MirrorList, error) { + rounds.Put("2026-W44", Round{Round: "2026-W44", Opened: t0, OpenedBy: "node-a", Order: []string{"node-a"}}) + return MirrorList{Servers: good}, nil + } + asks.Put(NodeKey("node-a", "ask-r"), Ask{ID: "ask-r", Node: "node-a", Act: ActMirrors, At: t0}) + e, _ := asks.Get(NodeKey("node-a", "ask-r")) + err := u.TakeAsk(stdio.StateChange{Op: "put", Key: NodeKey("node-a", "ask-r"), Value: e.Value}) + if _, after, _ := readMirrorList(mirrors); err == nil || !strings.Contains(err.Error(), "round 2026-W44 runs") || after != before { + t.Errorf("a refresh whose round opened while it ranked: %v, the list at %d (was %d)", err, after, before) + } } diff --git a/modules/pacman/cmd/pacman-tools/mirrors.go b/modules/pacman/cmd/pacman-tools/mirrors.go index eaebcb7c..27564916 100644 --- a/modules/pacman/cmd/pacman-tools/mirrors.go +++ b/modules/pacman/cmd/pacman-tools/mirrors.go @@ -221,8 +221,9 @@ func readMirrorList(r interface { // ---- the keeper's part ------------------------------------------------------------------------------------------- -// rankMirrors ranks the mesh's list and writes it to the shared key, answering its revision. -func (u *Upgrades) rankMirrors(round string) (uint64, error) { +// rankMirrors ranks the mesh's list and writes it to the shared key, answering its revision. guard, when set, is asked +// right before the write and refuses it with its error: ranking takes minutes, and what held when it began may not. +func (u *Upgrades) rankMirrors(round string, guard func() error) (uint64, error) { if u.Rank == nil || u.Mirrors == nil { return 0, errors.New("this keeper ranks no mirrors") } @@ -234,13 +235,18 @@ func (u *Upgrades) rankMirrors(round string) (uint64, error) { if err != nil { return 0, err } + if guard != nil { + if err := guard(); err != nil { + return 0, err + } + } return u.Mirrors.Put(MirrorsKey, list) } // mirrorsForRound ranks the list in the write that opens round (ADR 0585 §2): the revision the round opens with, and // why it was not ranked again when it was not, the round then opening with the list there is. func (u *Upgrades) mirrorsForRound(round string) (uint64, string) { - rev, err := u.rankMirrors(round) + rev, err := u.rankMirrors(round, nil) if err == nil { return rev, "" } @@ -278,17 +284,59 @@ func refreshRefused(round string) error { "again only once every node of it passed (pacman_round says where it stands)", round) } -// takeMirrorsAsk ranks the list again for the mesh on a refresh, unless a round runs. +// takeMirrorsAsk ranks the list again for the mesh on a refresh, unless a round runs: asked before the ranking and again +// right before its write, so a refresh that began before a round opened never writes after the round's key exists. func (u *Upgrades) takeMirrorsAsk() error { - if round, err := runningRound(u.Rounds, u.Runs, u.Machine.Now()); err != nil { - return err - } else if round != "" { - return refreshRefused(round) + noRound := func() error { + if round, err := runningRound(u.Rounds, u.Runs, u.Machine.Now()); err != nil { + return err + } else if round != "" { + return refreshRefused(round) + } + return nil } - _, err := u.rankMirrors("") + if err := noRound(); err != nil { + return err + } + _, err := u.rankMirrors("", noRound) return err } +// roundMirrorsWritten is why this node may not start its run in round yet, empty when it may: its mirror list file +// must hold the list the round opened with (Round.Mirrors), written now when it does not (ADR 0585 §2: every node of +// the round upgrades from that list). A round that opened with no list (none ranked yet) asks nothing of the file. +// A refusal is a refused run, tried again an hour later as every refused run of a round is. +func (u *Upgrades) roundMirrorsWritten(round string) string { + e, err := u.Rounds.Get(round) + if err != nil || e == nil { + return fmt.Sprintf("round %s cannot be read to know its mirror list: %v", round, err) + } + var r Round + if err := json.Unmarshal(e.Value, &r); err != nil { + return fmt.Sprintf("round %s is not readable: %v", round, err) + } + if r.Mirrors == 0 { + return "" + } + if u.Mirrors == nil { + return "this keeper reads no mirror list, and round " + round + " opened with one" + } + list, rev, err := readMirrorList(u.Mirrors) + switch { + case err != nil: + return "the mesh's mirror list cannot be read: " + err.Error() + case list == nil || rev != r.Mirrors: + return fmt.Sprintf("round %s opened with the mirror list at revision %d, and the bus holds revision %d", round, r.Mirrors, rev) + } + if _, err := u.WriteMirrors(); err != nil { + return "the round's mirror list is not written to " + Mirrorlist + ": " + err.Error() + } + if have, err := u.Machine.ReadFile(Mirrorlist); err != nil || !bytes.Equal(have, RenderMirrorlist(list.Servers)) { + return fmt.Sprintf("%s does not hold the mirror list round %s opened with (revision %d)", Mirrorlist, round, r.Mirrors) + } + return "" +} + // WriteMirrors writes this node's mirror list file whole from the shared list when they differ, through the root // helper, answering whether it wrote. No list yet writes nothing; a list that is empty or cannot be read is never // written, and the node keeps its last (ADR 0585 §3). diff --git a/modules/pacman/cmd/pacman-tools/round_integration_test.go b/modules/pacman/cmd/pacman-tools/round_integration_test.go index 099f22ff..5eec1f51 100644 --- a/modules/pacman/cmd/pacman-tools/round_integration_test.go +++ b/modules/pacman/cmd/pacman-tools/round_integration_test.go @@ -26,12 +26,15 @@ type countingRoot struct { mu sync.Mutex started []string mirrors []string + // mirrorsAtStart is the mirror list the node's file held when each transaction started (ADR 0585 §2). + mirrorsAtStart [][]string } func (r *countingRoot) Transaction(kind, run string, ignore []string) error { r.mu.Lock() defer r.mu.Unlock() r.started = append(r.started, kind+" "+run) + r.mirrorsAtStart = append(r.mirrorsAtStart, append([]string(nil), r.mirrors...)) return nil } func (r *countingRoot) Rollback(string, []RollbackItem) error { return nil } @@ -83,16 +86,20 @@ func startRoundNode(t *testing.T, ctx context.Context, url, node string, order [ m := machine(run, 1000) began := time.Now() m.Now = func() time.Time { return t0.Add(time.Since(began)) } + n := &roundNode{root: &countingRoot{}, signals: make(chan Signal)} m.ReadFile = func(path string) ([]byte, error) { switch path { case OSRelease: return []byte("7.2.8-arch1-2\n"), nil case ReflectorConf: return []byte("--sort rate\n"), nil + case Mirrorlist: // the file holds what the root helper last wrote + if l := n.root.mirrorlist(); l != nil { + return RenderMirrorlist(l), nil + } } return nil, errNoFile } - n := &roundNode{root: &countingRoot{}, signals: make(chan Signal)} k := &Keeper{Config: KeeperConfig{UpgradeOrder: order, RecordDays: 180, RoundStartMinutes: 120}, Machine: m, Clock: realClock{}, Watcher: fakeWatcher{n.signals}, Logf: func(f string, a ...any) { t.Logf(node+": "+f, a...) }, MakeHooks: keeperHooks, Root: n.root, Check: func(Run, *Record) Check { return Check{Passed: passes} }, @@ -192,6 +199,13 @@ func TestTheRoundGoesNodeByNodeOnARealBus(t *testing.T) { eventually(t, "each node wrote the mesh's mirror list", 10*time.Second, func() bool { return strings.Join(n.root.mirrorlist(), " ") == strings.Join(roundMirrors, " ") }) + // And each started its run only once its file held the round's list, the opener too. + n.root.mu.Lock() + at := n.root.mirrorsAtStart + n.root.mu.Unlock() + if len(at) != 1 || strings.Join(at[0], " ") != strings.Join(roundMirrors, " ") { + t.Errorf("a node's run started with the mirror list file holding %v, want the round's %v", at, roundMirrors) + } } } diff --git a/modules/pacman/cmd/pacman-tools/transaction.go b/modules/pacman/cmd/pacman-tools/transaction.go index 515394eb..0d724693 100644 --- a/modules/pacman/cmd/pacman-tools/transaction.go +++ b/modules/pacman/cmd/pacman-tools/transaction.go @@ -140,6 +140,12 @@ func (u *Upgrades) startUpgrade(r *openRun) error { if u.Machine.locked() { return u.refuse(r, "another pacman holds "+DBLock+": a transaction is running, or one was killed and left its lock") } + // A round's run upgrades from the mirror list the round opened with, written to this node's file first (ADR 0585 §2). + if r.Run.From == FromRound { + if why := u.roundMirrorsWritten(r.Run.Round); why != "" { + return u.refuse(r, why) + } + } rec, why := u.TakeRecord(r.Run.Run) if why != "" { return u.refuse(r, why) From b3fcf408f242b0c65bb5d8b3d3fcf6226dd5205f Mon Sep 17 00:00:00 2001 From: jochen Date: Sun, 1 Nov 2026 17:24:19 +0100 Subject: [PATCH 6/7] Make tests that wait for concurrent work wait on the event or a condition with a long deadline (issue 1814) A test that slept a fixed time and then asserted what a goroutine, process or watcher did failed under the checker's load. Each now waits for its positive evidence (a started baseline, a call counted, a state reached) within 30 s, and the concurrency-limit tests meet at a barrier instead of overlapping by sleep. Claude-Session: https://claude.ai/code/session_01NcbgfJ9Gum47zkFKWRaovL --- .../holder_integration_test.go | 2 +- .../cmd/zephyrus/switcher_test.go | 2 +- modules/brother/cmd/brother/feeder_test.go | 2 +- modules/brother/cmd/brother/glass_test.go | 2 +- modules/brother/cmd/brother/printlink_test.go | 11 +++++++--- .../cmd/claude-code/agent_account_test.go | 4 ++-- .../claude-code/cmd/claude-code/judge_test.go | 12 +++++------ .../cmd/claude-code/memory_test.go | 4 ++-- .../cmd/claude-code/proposals_test.go | 2 +- .../cmd/claude-code/questions_test.go | 4 ++-- .../cmd/clipmenu-tools/manifest_test.go | 14 +++++++------ modules/dbus/cmd/dbus-tools/watcher_test.go | 4 ++-- modules/disk-load/cmd/disk-load/data_test.go | 4 ++-- .../cmd/docker-compose-tools/jobs_test.go | 8 ++++++-- modules/dunst/cmd/dunst-tools/actions_test.go | 2 +- .../flatpak/cmd/flatpak-tools/jobs_test.go | 8 ++++++-- .../forge-account-provider/service_test.go | 2 +- modules/i3/cmd/i3-tools/i3_test.go | 20 +++++++++++++------ .../cmd/keycloak-provider/admin_test.go | 2 +- .../cmd/keycloak-provider/grant_moved_test.go | 2 +- .../cmd/keycloak-provider/moved_test.go | 2 +- .../cmd/mesh-build-go/asks_test.go | 2 +- .../cmd/mesh-build-go/fetch_test.go | 2 +- .../cmd/mesh-build-go/lint_test.go | 13 +++++++++++- .../cmd/mesh-build-go/module_test.go | 4 ++-- .../cmd/mesh-build-go/selected_dirs_test.go | 2 +- .../test_real_integration_test.go | 2 +- .../cmd/mesh-build-go/verify_once_test.go | 13 +++++++++++- .../mesh-files/cmd/mesh-files/reads_test.go | 2 +- .../cmd/mesh-issues/caller_test.go | 2 +- .../cmd/mesh-knowledge/bus_test.go | 2 +- .../cmd/mesh-knowledge/caller_test.go | 2 +- .../cmd/mesh-mail-notifier/run_test.go | 12 +++++------ .../cmd/mesh-mail-reader/batch_test.go | 2 +- .../cmd/mesh-provisioner-client/asks_test.go | 4 ++-- .../mesh-provisioner-client/client_test.go | 7 ++++--- .../socket_integration_test.go | 2 +- .../mesh-reads/cmd/mesh-reads/reads_test.go | 2 +- .../mesh-vault/cmd/mesh-vault/core_test.go | 2 +- .../mesh-vault/cmd/mesh-vault/nodekey_test.go | 2 +- .../messenger/cmd/messenger/answers_test.go | 2 +- .../messenger/cmd/messenger/review_test.go | 2 +- modules/mounts/cmd/mounts/failed_test.go | 4 ++-- .../nats/cmd/mesh-nats-snapshot/live_test.go | 4 ++-- .../cmd/postgres-provider/moved_test.go | 2 +- .../restic/cmd/restic-backups/data_test.go | 2 +- .../restic/cmd/restic-backups/health_test.go | 2 +- .../cmd/screen-lock-tools/lock_test.go | 7 ++++++- .../sensors/cmd/sensors/second_review_test.go | 4 ++-- .../cmd/ssh-client-tools/sweep_test.go | 2 +- .../cmd/resolver-tools/guard_test.go | 4 ++-- modules/zfs/cmd/zfs-tools/review_test.go | 8 +++++--- 52 files changed, 144 insertions(+), 91 deletions(-) diff --git a/modules/artifact-store-tools/cmd/artifact-store-tools/holder_integration_test.go b/modules/artifact-store-tools/cmd/artifact-store-tools/holder_integration_test.go index 5cac1aff..d9d1b1ae 100644 --- a/modules/artifact-store-tools/cmd/artifact-store-tools/holder_integration_test.go +++ b/modules/artifact-store-tools/cmd/artifact-store-tools/holder_integration_test.go @@ -215,7 +215,7 @@ func TestTheSeatSweepsAtABuildsEndOnARealBusOnceTheLeaseIsAway(t *testing.T) { t.Fatal(err) } ended() - deadline := time.Now().Add(5 * time.Second) + deadline := time.Now().Add(30 * time.Second) for { mu.Lock() n := len(gone) diff --git a/modules/asus-zephyrus-g14/cmd/zephyrus/switcher_test.go b/modules/asus-zephyrus-g14/cmd/zephyrus/switcher_test.go index 6506426f..c43f7501 100644 --- a/modules/asus-zephyrus-g14/cmd/zephyrus/switcher_test.go +++ b/modules/asus-zephyrus-g14/cmd/zephyrus/switcher_test.go @@ -171,7 +171,7 @@ func TestTheSwitcherDoesNotActOnAnotherModel(t *testing.T) { go func() { sw.Run(context.Background()); close(done) }() select { case <-done: - case <-time.After(2 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("the switcher ran on another model") } if r := sw.Report(); r.Running || r.Disabled == "" || len(f.calls) != 0 { diff --git a/modules/brother/cmd/brother/feeder_test.go b/modules/brother/cmd/brother/feeder_test.go index 8d4d43ec..e24f9f1b 100644 --- a/modules/brother/cmd/brother/feeder_test.go +++ b/modules/brother/cmd/brother/feeder_test.go @@ -181,7 +181,7 @@ func standInCapture(release <-chan struct{}, fail error) func(ctx context.Contex // waitFor polls until the condition holds. func waitFor(t *testing.T, what string, cond func() bool) { t.Helper() - for i := 0; i < 400; i++ { + for i := 0; i < 3000; i++ { if cond() { return } diff --git a/modules/brother/cmd/brother/glass_test.go b/modules/brother/cmd/brother/glass_test.go index 6c5efcbc..7d689c18 100644 --- a/modules/brother/cmd/brother/glass_test.go +++ b/modules/brother/cmd/brother/glass_test.go @@ -181,7 +181,7 @@ func TestAFinishedGlassDocumentIsNotFiledAgainByItsExpiry(t *testing.T) { if _, err := r.call(t, "scanner.scan", docArgs(id, true)); err != nil { t.Fatal(err) } - time.Sleep(400 * time.Millisecond) + waitFor(t, "the expired document to be closed and filed", func() bool { e, _ := os.ReadDir(folder); return len(e) >= 1 }) if e, _ := os.ReadDir(folder); len(e) != 1 { t.Errorf("%d files, want 1", len(e)) } diff --git a/modules/brother/cmd/brother/printlink_test.go b/modules/brother/cmd/brother/printlink_test.go index 56670d1f..d2ab095f 100644 --- a/modules/brother/cmd/brother/printlink_test.go +++ b/modules/brother/cmd/brother/printlink_test.go @@ -311,8 +311,13 @@ func TestASlowUploadAndPrintAnswersStartedNeverATimeout(t *testing.T) { } got, _ = r.call(t, "printer.print", map[string]any{"path": "/home/ops/.ssh/id_ed25519", "node": "g14"}) id2, _ := got.(map[string]any)["ask"].(string) - time.Sleep(300 * time.Millisecond) - if _, err := r.call(t, "printer.print", map[string]any{"ask": id2}); err == nil || !strings.Contains(err.Error(), "refused by name") { - t.Errorf("the failed upload's outcome: %v", err) + var outcome error + for end := time.Now().Add(30 * time.Second); time.Now().Before(end); time.Sleep(10 * time.Millisecond) { + if _, outcome = r.call(t, "printer.print", map[string]any{"ask": id2}); outcome != nil { + break + } + } + if outcome == nil || !strings.Contains(outcome.Error(), "refused by name") { + t.Errorf("the failed upload's outcome: %v", outcome) } } diff --git a/modules/claude-code/cmd/claude-code/agent_account_test.go b/modules/claude-code/cmd/claude-code/agent_account_test.go index 489d2d6b..60af230b 100644 --- a/modules/claude-code/cmd/claude-code/agent_account_test.go +++ b/modules/claude-code/cmd/claude-code/agent_account_test.go @@ -505,7 +505,7 @@ func TestTheHelperReadsOnlyARegularFile(t *testing.T) { if a.Err == "" || len(a.Data) != 0 { t.Fatalf("%s was read: %q", path, a.Data) } - case <-time.After(5 * time.Second): + case <-time.After(30 * time.Second): t.Fatalf("reading %s held the helper", path) } } @@ -567,7 +567,7 @@ func TestAHelperThatDoesNotAnswerFailsTheRequestInTime(t *testing.T) { if err == nil || !errors.Is(err, errHelperSlow) { t.Fatalf("a silent helper answered: %v", err) } - if time.Since(start) > 2*time.Second { + if time.Since(start) > 30*time.Second { t.Fatalf("the request waited %s", time.Since(start)) } } diff --git a/modules/claude-code/cmd/claude-code/judge_test.go b/modules/claude-code/cmd/claude-code/judge_test.go index 0ad535d0..0f714872 100644 --- a/modules/claude-code/cmd/claude-code/judge_test.go +++ b/modules/claude-code/cmd/claude-code/judge_test.go @@ -133,7 +133,7 @@ func TestAJudgementWaitsItsTurnWithinTheBound(t *testing.T) { if err == nil || !strings.Contains(err.Error(), "another judgement") { t.Fatalf("%v", err) } - if time.Since(start) > 2*time.Second { + if time.Since(start) > 30*time.Second { t.Fatal("waited past the bound") } } @@ -175,7 +175,7 @@ func TestALongJudgementIsCollectedByItsTicket(t *testing.T) { j := testJudge(true, true, func(ctx context.Context, _ []string, _ []byte) ([]byte, error) { deadline, _ = ctx.Deadline() select { - case <-time.After(400 * time.Millisecond): + case <-time.After(1500 * time.Millisecond): // well past Wait, however loaded the machine return []byte(`{"structured_output":{"verdict":"none"}}`), nil case <-ctx.Done(): return nil, ctx.Err() @@ -191,7 +191,7 @@ func TestALongJudgementIsCollectedByItsTicket(t *testing.T) { t.Fatalf("not a ticket: %+v", out) } var got *Judged - for i := 0; i < 100; i++ { + for i := 0; i < 600; i++ { got, err = j.Collect(out.Ticket) if err != nil { t.Fatal(err) @@ -223,12 +223,12 @@ func TestALongJudgementIsBoundedAndSaysWhyItFailed(t *testing.T) { t.Fatalf("a bound past the most taken: %v", err) } j.Wait = 20 * time.Millisecond - j.Bound = 30 * time.Millisecond // the test's stand-in for JudgeBound: within is past it, so a ticket - out, err := j.Judge(JudgeAsk{Question: "q", Schema: verdictSchema, Within: 200 * time.Millisecond}) + j.Bound = time.Second // the test's stand-in for JudgeBound: within is past it, so a ticket; far past Wait on a loaded machine + out, err := j.Judge(JudgeAsk{Question: "q", Schema: verdictSchema, Within: 2 * time.Second}) if err != nil || !out.Pending { t.Fatalf("%+v %v", out, err) } - for i := 0; i < 100; i++ { + for i := 0; i < 3000; i++ { got, err := j.Collect(out.Ticket) if err != nil { if !strings.Contains(err.Error(), "did not answer within") { diff --git a/modules/claude-code/cmd/claude-code/memory_test.go b/modules/claude-code/cmd/claude-code/memory_test.go index 892e8f95..99917163 100644 --- a/modules/claude-code/cmd/claude-code/memory_test.go +++ b/modules/claude-code/cmd/claude-code/memory_test.go @@ -950,11 +950,11 @@ func TestTheWatchHandlerReturnsAtOnceAndDrainAppliesWhatItNoted(t *testing.T) { if err != nil { t.Fatal(err) } - case <-time.After(2 * time.Second): + case <-time.After(30 * time.Second): t.Fatalf("the watch handler waited for the look or the state (%d of 400 returned)", i) } } - if took := time.Since(start); took > time.Second { + if took := time.Since(start); took > 30*time.Second { t.Fatalf("400 values took %s to hand over", took) } shanks.mu.Unlock() diff --git a/modules/claude-code/cmd/claude-code/proposals_test.go b/modules/claude-code/cmd/claude-code/proposals_test.go index 5d35e8ac..e1e199f1 100644 --- a/modules/claude-code/cmd/claude-code/proposals_test.go +++ b/modules/claude-code/cmd/claude-code/proposals_test.go @@ -670,7 +670,7 @@ func TestTheRoutersRefusalIsSaidAndDiscards(t *testing.T) { r.kinds = nil refusing := &refusingRouter{router: r, p: p, store: store} within, every := RouterAnswersWithin, RouterAnswersEvery - RouterAnswersWithin, RouterAnswersEvery = time.Second, 10*time.Millisecond + RouterAnswersWithin, RouterAnswersEvery = 30*time.Second, 10*time.Millisecond t.Cleanup(func() { RouterAnswersWithin, RouterAnswersEvery = within, every }) _, err := Propose(p, ProposeInput{Scope: ScopeMesh, Name: "x", Text: "Text.\n"}, store, refusing, t0) if err == nil || !strings.Contains(err.Error(), "no channel can carry any of its answers now") || diff --git a/modules/claude-code/cmd/claude-code/questions_test.go b/modules/claude-code/cmd/claude-code/questions_test.go index db3b249f..64d7dc34 100644 --- a/modules/claude-code/cmd/claude-code/questions_test.go +++ b/modules/claude-code/cmd/claude-code/questions_test.go @@ -223,7 +223,7 @@ func TestTheRoutersRefusalIsSaidAndKept(t *testing.T) { store := newMemQuestions() refusing := &questionRefusingRouter{router: newRouter(), store: store} within, every := RouterAnswersWithin, RouterAnswersEvery - RouterAnswersWithin, RouterAnswersEvery = time.Second, 10*time.Millisecond + RouterAnswersWithin, RouterAnswersEvery = 30*time.Second, 10*time.Millisecond t.Cleanup(func() { RouterAnswersWithin, RouterAnswersEvery = within, every }) _, err := AskQuestion(p, mergeTonight(), store, refusing, t0) if err == nil || !strings.Contains(err.Error(), "may not leave the mesh") { @@ -303,7 +303,7 @@ func TestAReadWaitsNoLongerThanItsBound(t *testing.T) { if err != nil || out["state"] != AnswerWaiting { t.Fatalf("%v %v", out, err) } - if took := time.Since(start); took > 2*time.Second { + if took := time.Since(start); took > 30*time.Second { t.Errorf("a read asked to wait an hour took %s", took) } } diff --git a/modules/clipmenu/cmd/clipmenu-tools/manifest_test.go b/modules/clipmenu/cmd/clipmenu-tools/manifest_test.go index fea70036..b00b6cde 100644 --- a/modules/clipmenu/cmd/clipmenu-tools/manifest_test.go +++ b/modules/clipmenu/cmd/clipmenu-tools/manifest_test.go @@ -123,25 +123,27 @@ func TestTheLauncherUsesTheManagersDisplayAndWaitsOtherwise(t *testing.T) { os.MkdirAll(fakeBin, 0o755) // the manager's environment: empty until the file appears os.WriteFile(fakeBin+"/systemctl", []byte("#!/bin/sh\n[ -f \""+dir+"/env\" ] && cat \""+dir+"/env\"\nexit 0\n"), 0o755) - run := func(env ...string) (string, bool) { - ctx, cancel := context.WithTimeout(context.Background(), 2500*time.Millisecond) + // wait is how long the launcher may run: a launcher that must answer gets a generous bound (the checker runs + // thousands of tests at once, issue 1814); one that must keep waiting is cut off after a short one + run := func(wait time.Duration, env ...string) (string, bool) { + ctx, cancel := context.WithTimeout(context.Background(), wait) defer cancel() cmd := exec.CommandContext(ctx, "sh", file) cmd.Env = append([]string{"PATH=" + fakeBin + ":" + os.Getenv("PATH"), "HOME=" + dir}, env...) out, _ := cmd.Output() return strings.TrimSpace(string(out)), ctx.Err() == nil } - if out, ok := run("DISPLAY=:7"); !ok || out != "DISPLAY=:7" { + if out, ok := run(30*time.Second, "DISPLAY=:7"); !ok || out != "DISPLAY=:7" { t.Fatalf("with DISPLAY: %q %v", out, ok) } - if _, ok := run(); ok { + if _, ok := run(2500 * time.Millisecond); ok { t.Fatal("it exited with no X server") } for _, n := range []string{"X0", "X1"} { l, _ := net.Listen("unix", dir+"/x11/"+n) defer l.Close() } - if _, ok := run(); ok { + if _, ok := run(2500 * time.Millisecond); ok { t.Fatal("it chose one of two servers") } // the session hands the manager its display while the launcher waits @@ -149,7 +151,7 @@ func TestTheLauncherUsesTheManagersDisplayAndWaitsOtherwise(t *testing.T) { time.Sleep(1200 * time.Millisecond) os.WriteFile(dir+"/env", []byte("DISPLAY=:1\nOTHER=x\n"), 0o644) }() - if out, ok := run(); !ok || out != "DISPLAY=:1" { + if out, ok := run(30 * time.Second); !ok || out != "DISPLAY=:1" { t.Fatalf("the display that arrived while waiting: %q %v", out, ok) } } diff --git a/modules/dbus/cmd/dbus-tools/watcher_test.go b/modules/dbus/cmd/dbus-tools/watcher_test.go index ad641ee4..a80edb71 100644 --- a/modules/dbus/cmd/dbus-tools/watcher_test.go +++ b/modules/dbus/cmd/dbus-tools/watcher_test.go @@ -422,11 +422,11 @@ func TestRunWithoutABusSaysItStalledAndReconnects(t *testing.T) { }, nil) w.state = filepath.Join(t.TempDir(), "bus") w.retry = 20 * time.Millisecond - ctx, cancel := context.WithTimeout(context.Background(), 6*time.Second) + ctx, cancel := context.WithTimeout(context.Background(), 40*time.Second) defer cancel() done := make(chan struct{}) go func() { w.Run(ctx); close(done) }() - deadline := time.Now().Add(6 * time.Second) + deadline := time.Now().Add(30 * time.Second) for time.Now().Before(deadline) && !w.Snapshot().Connected { time.Sleep(50 * time.Millisecond) } diff --git a/modules/disk-load/cmd/disk-load/data_test.go b/modules/disk-load/cmd/disk-load/data_test.go index c8a86f46..10cbfe95 100644 --- a/modules/disk-load/cmd/disk-load/data_test.go +++ b/modules/disk-load/cmd/disk-load/data_test.go @@ -181,10 +181,10 @@ func readingOf(s *memStore, key string) *health.Reading { func waitFor(t *testing.T, done func() bool) { t.Helper() - for end := time.Now().Add(5 * time.Second); time.Now().Before(end); time.Sleep(5 * time.Millisecond) { + for end := time.Now().Add(30 * time.Second); time.Now().Before(end); time.Sleep(5 * time.Millisecond) { if done() { return } } - t.Fatal("not done within 5 s") + t.Fatal("not done within 30 s") } diff --git a/modules/docker-compose/cmd/docker-compose-tools/jobs_test.go b/modules/docker-compose/cmd/docker-compose-tools/jobs_test.go index 46e1725c..ccf9042d 100644 --- a/modules/docker-compose/cmd/docker-compose-tools/jobs_test.go +++ b/modules/docker-compose/cmd/docker-compose-tools/jobs_test.go @@ -43,8 +43,12 @@ func TestJobsASlowActIsAnsweredRunningWithItsID(t *testing.T) { t.Fatalf("%+v", j) } close(release) - time.Sleep(50 * time.Millisecond) - got, _ := jobByID(j.ID) + var got Job + for end := time.Now().Add(30 * time.Second); time.Now().Before(end); time.Sleep(5 * time.Millisecond) { + if got, _ = jobByID(j.ID); !got.Running { + break + } + } if got.Running { t.Fatalf("finished afterwards: %+v", got) } diff --git a/modules/dunst/cmd/dunst-tools/actions_test.go b/modules/dunst/cmd/dunst-tools/actions_test.go index 70a472ce..029d58db 100644 --- a/modules/dunst/cmd/dunst-tools/actions_test.go +++ b/modules/dunst/cmd/dunst-tools/actions_test.go @@ -47,7 +47,7 @@ func TestANotificationsChosenAnswerIsSaidAsAnEvent(t *testing.T) { if !strings.Contains(string(asked), "[--expire-time=0][--wait][--action=a1b2=Release][--action=c3d4=Stop][--]") { t.Fatalf("notify-send was asked %s", asked) } - deadline := time.Now().Add(3 * time.Second) + deadline := time.Now().Add(30 * time.Second) for { mu.Lock() n := len(said) diff --git a/modules/flatpak/cmd/flatpak-tools/jobs_test.go b/modules/flatpak/cmd/flatpak-tools/jobs_test.go index 46e1725c..ccf9042d 100644 --- a/modules/flatpak/cmd/flatpak-tools/jobs_test.go +++ b/modules/flatpak/cmd/flatpak-tools/jobs_test.go @@ -43,8 +43,12 @@ func TestJobsASlowActIsAnsweredRunningWithItsID(t *testing.T) { t.Fatalf("%+v", j) } close(release) - time.Sleep(50 * time.Millisecond) - got, _ := jobByID(j.ID) + var got Job + for end := time.Now().Add(30 * time.Second); time.Now().Before(end); time.Sleep(5 * time.Millisecond) { + if got, _ = jobByID(j.ID); !got.Running { + break + } + } if got.Running { t.Fatalf("finished afterwards: %+v", got) } diff --git a/modules/gitea/cmd/forge-account-provider/service_test.go b/modules/gitea/cmd/forge-account-provider/service_test.go index 60242c91..f91aa2af 100644 --- a/modules/gitea/cmd/forge-account-provider/service_test.go +++ b/modules/gitea/cmd/forge-account-provider/service_test.go @@ -569,7 +569,7 @@ func TestKeepRunningStartsTheProviderAgainAfterARefusedWatch(t *testing.T) { }() select { case <-serving: - case <-time.After(5 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("the provider was not started again after its watch was refused") } stop() diff --git a/modules/i3/cmd/i3-tools/i3_test.go b/modules/i3/cmd/i3-tools/i3_test.go index add7c5ea..f745e824 100644 --- a/modules/i3/cmd/i3-tools/i3_test.go +++ b/modules/i3/cmd/i3-tools/i3_test.go @@ -310,7 +310,8 @@ func TestTheWatcherReloadsOnceAfterAChangeAndNeverIntoErrors(t *testing.T) { stop := make(chan struct{}) defer close(stop) go w.Run(stop) - time.Sleep(60 * time.Millisecond) + // the baseline is taken once Since is set; a change written before that would be part of it + waitFor(t, func() bool { return w.Status().Since != "" }) os.MkdirAll(filepath.Join(dir, "config.d"), 0o755) os.WriteFile(filepath.Join(dir, "config.d", "50-x.conf"), []byte("b"), 0o644) os.WriteFile(filepath.Join(dir, "config"), []byte("aa"), 0o644) @@ -342,15 +343,21 @@ func TestAtItsStartTheWatcherReloadsWhatTheRunningI3HasNotLoaded(t *testing.T) { {map[string]string{cfg: "new", filepath.Join(dir, "config.d", "gone.conf"): "x"}, 1}, } { var mu sync.Mutex - reloads := 0 + reloads, asked := 0, 0 w := &Watcher{Dir: dir, Every: 10 * time.Millisecond, Check: func() ([]ConfigError, error) { return nil, nil }, Reload: func() error { mu.Lock(); reloads++; mu.Unlock(); return nil }, - Loaded: func() (map[string]string, error) { return c.loaded, nil }, + Loaded: func() (map[string]string, error) { mu.Lock(); asked++; mu.Unlock(); return c.loaded, nil }, } stop := make(chan struct{}) go w.Run(stop) - time.Sleep(80 * time.Millisecond) + // positive evidence first: the watcher asked i3 what it has loaded, then reloads + // (want 1) or has had many rounds to do so (want 0) + waitFor(t, func() bool { mu.Lock(); defer mu.Unlock(); return asked > 0 }) + if c.want > 0 { + waitFor(t, func() bool { mu.Lock(); defer mu.Unlock(); return reloads >= c.want }) + } + time.Sleep(100 * time.Millisecond) close(stop) mu.Lock() if reloads != c.want { @@ -361,11 +368,12 @@ func TestAtItsStartTheWatcherReloadsWhatTheRunningI3HasNotLoaded(t *testing.T) { } func waitFor(t *testing.T, ok func() bool) { - for i := 0; i < 200; i++ { + t.Helper() + for i := 0; i < 3000; i++ { if ok() { return } time.Sleep(10 * time.Millisecond) } - t.Fatal("timed out") + t.Fatal("timed out after 30 s") } diff --git a/modules/keycloak/cmd/keycloak-provider/admin_test.go b/modules/keycloak/cmd/keycloak-provider/admin_test.go index 09ae9886..8f948061 100644 --- a/modules/keycloak/cmd/keycloak-provider/admin_test.go +++ b/modules/keycloak/cmd/keycloak-provider/admin_test.go @@ -252,7 +252,7 @@ func TestRunRepairsWhenNudged(t *testing.T) { c, cancel := context.WithCancel(ctx) defer cancel() go w.g.Run(c) - deadline := time.Now().Add(5 * time.Second) + deadline := time.Now().Add(30 * time.Second) for w.g.State() != AdminOK { if time.Now().After(deadline) { t.Fatal("no first check") diff --git a/modules/keycloak/cmd/keycloak-provider/grant_moved_test.go b/modules/keycloak/cmd/keycloak-provider/grant_moved_test.go index 80f02f9a..0749f4f6 100644 --- a/modules/keycloak/cmd/keycloak-provider/grant_moved_test.go +++ b/modules/keycloak/cmd/keycloak-provider/grant_moved_test.go @@ -108,7 +108,7 @@ func movedWorld(t *testing.T, h *harness.Harness) (f *fakeKeycloak, start func() Offers: map[string]provider.Offer{ProvisionName: {Credential: provider.PerConsumer, Serves: servedValues(testIssuer)}}, Make: run.Make, Gone: run.Gone, Every: h.Every, Logf: func(string, ...any) {}}) return f, func() { - runCtx, cancel := context.WithTimeout(ctx, 2*time.Second) + runCtx, cancel := context.WithTimeout(ctx, 60*time.Second) t.Cleanup(cancel) go func() { _ = run.Run(runCtx, p, bus) }() } diff --git a/modules/keycloak/cmd/keycloak-provider/moved_test.go b/modules/keycloak/cmd/keycloak-provider/moved_test.go index dd5371dd..2e47f786 100644 --- a/modules/keycloak/cmd/keycloak-provider/moved_test.go +++ b/modules/keycloak/cmd/keycloak-provider/moved_test.go @@ -69,7 +69,7 @@ func TestTheGrantPathLeavesWhenTheConsumersFileIsFilled(t *testing.T) { } select { case <-done: - case <-time.After(2 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("did not leave when the file was filled") } } diff --git a/modules/mesh-build-go/cmd/mesh-build-go/asks_test.go b/modules/mesh-build-go/cmd/mesh-build-go/asks_test.go index d9efe887..a7d94afc 100644 --- a/modules/mesh-build-go/cmd/mesh-build-go/asks_test.go +++ b/modules/mesh-build-go/cmd/mesh-build-go/asks_test.go @@ -59,7 +59,7 @@ func TestAPulledAskRunsTheBuildAndItsKeyNamesTheReference(t *testing.T) { go p.Pull(ctx) key, _ := delivery.AskStepKey("ace", a.ID) var step delivery.Step - for deadline := time.Now().Add(3 * time.Second); ; time.Sleep(5 * time.Millisecond) { + for deadline := time.Now().Add(30 * time.Second); ; time.Sleep(5 * time.Millisecond) { states.mu.Lock() v := states.steps[key] states.mu.Unlock() diff --git a/modules/mesh-build-go/cmd/mesh-build-go/fetch_test.go b/modules/mesh-build-go/cmd/mesh-build-go/fetch_test.go index 6c248513..e86e1559 100644 --- a/modules/mesh-build-go/cmd/mesh-build-go/fetch_test.go +++ b/modules/mesh-build-go/cmd/mesh-build-go/fetch_test.go @@ -246,7 +246,7 @@ func TestTheCallAnswersAStepIdBeforeTheFetchEnds(t *testing.T) { if key != "ace."+id { t.Errorf("ended %s", key) } - case <-time.After(3 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("the step never ended") } states.mu.Lock() diff --git a/modules/mesh-build-go/cmd/mesh-build-go/lint_test.go b/modules/mesh-build-go/cmd/mesh-build-go/lint_test.go index fef621b0..f5cef2eb 100644 --- a/modules/mesh-build-go/cmd/mesh-build-go/lint_test.go +++ b/modules/mesh-build-go/cmd/mesh-build-go/lint_test.go @@ -106,12 +106,23 @@ func TestTheLintOfManyDirectoriesRunsAtOnceUpToTheBound(t *testing.T) { tree := writeTree(t, files) var mu sync.Mutex running, most := 0, 0 + release := make(chan struct{}) // closed once two run at once: they overlap however slowly the machine starts them run := func(ctx context.Context, env []string, name string, args ...string) forgekey.Ran { mu.Lock() running++ most = max(most, running) + if running >= 2 { + select { + case <-release: + default: + close(release) + } + } mu.Unlock() - time.Sleep(30 * time.Millisecond) + select { + case <-release: + case <-time.After(30 * time.Second): + } mu.Lock() running-- mu.Unlock() diff --git a/modules/mesh-build-go/cmd/mesh-build-go/module_test.go b/modules/mesh-build-go/cmd/mesh-build-go/module_test.go index c61e959f..a780172f 100644 --- a/modules/mesh-build-go/cmd/mesh-build-go/module_test.go +++ b/modules/mesh-build-go/cmd/mesh-build-go/module_test.go @@ -65,7 +65,7 @@ func (s *keptStates) waitEnd(t *testing.T) delivery.Step { defer s.mu.Unlock() v := s.steps[key] return v[len(v)-1] - case <-time.After(3 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("the step never ended on its key") return delivery.Step{} } @@ -86,7 +86,7 @@ func TestStartWritesTheToolchainAndHealthIsHealthy(t *testing.T) { defer stop() go m.Start(ctx) var tc delivery.Toolchain - for deadline := time.Now().Add(3 * time.Second); time.Now().Before(deadline); time.Sleep(5 * time.Millisecond) { + for deadline := time.Now().Add(30 * time.Second); time.Now().Before(deadline); time.Sleep(5 * time.Millisecond) { if got, ok := states.toolchain("ace.go"); ok { tc = got break diff --git a/modules/mesh-build-go/cmd/mesh-build-go/selected_dirs_test.go b/modules/mesh-build-go/cmd/mesh-build-go/selected_dirs_test.go index fa86bb54..65d3a6aa 100644 --- a/modules/mesh-build-go/cmd/mesh-build-go/selected_dirs_test.go +++ b/modules/mesh-build-go/cmd/mesh-build-go/selected_dirs_test.go @@ -122,7 +122,7 @@ func TestSelectedDirectoriesRunAtOnceAndAnswerInDirectoryOrder(t *testing.T) { mu.Unlock() select { case <-release: - case <-time.After(10 * time.Second): + case <-time.After(30 * time.Second): } mu.Lock() running-- diff --git a/modules/mesh-build-go/cmd/mesh-build-go/test_real_integration_test.go b/modules/mesh-build-go/cmd/mesh-build-go/test_real_integration_test.go index 5603f45a..8ece1554 100644 --- a/modules/mesh-build-go/cmd/mesh-build-go/test_real_integration_test.go +++ b/modules/mesh-build-go/cmd/mesh-build-go/test_real_integration_test.go @@ -163,7 +163,7 @@ func TestIntegrationLevelRunsAgainstARealStoreAndBusAndLeavesNothing(t *testing. if len(entries) != 1 || entries[0].Name() != "tree" { t.Errorf("the workspace holds %v, want only its tree: the run directory is gone", entries) } - for deadline := time.Now().Add(5 * time.Second); len(processesNamed(work)) > 0 && time.Now().Before(deadline); time.Sleep(100 * time.Millisecond) { + for deadline := time.Now().Add(30 * time.Second); len(processesNamed(work)) > 0 && time.Now().Before(deadline); time.Sleep(100 * time.Millisecond) { } if left := processesNamed(work); len(left) > 0 { t.Errorf("processes of the run are left: %v", left) diff --git a/modules/mesh-build-go/cmd/mesh-build-go/verify_once_test.go b/modules/mesh-build-go/cmd/mesh-build-go/verify_once_test.go index 6d9776b4..3305e5cf 100644 --- a/modules/mesh-build-go/cmd/mesh-build-go/verify_once_test.go +++ b/modules/mesh-build-go/cmd/mesh-build-go/verify_once_test.go @@ -86,6 +86,7 @@ func TestAFailedVerifyLeavesNoMark(t *testing.T) { func TestDownloadsRunSideBySideUpToTheBound(t *testing.T) { var mu sync.Mutex running, most := 0, 0 + release := make(chan struct{}) // closed once two run at once: they overlap however slowly the machine starts them f := &fakeStep{gomods: "a/go.mod\nb/go.mod\nc/go.mod\nd/go.mod\n", files: map[string]string{ "a/go.mod": "a\n", "b/go.mod": "b\n", "c/go.mod": "c\n", "d/go.mod": "d\n"}} f.goRule = func(line string) forgekey.Ran { @@ -95,8 +96,18 @@ func TestDownloadsRunSideBySideUpToTheBound(t *testing.T) { if running > most { most = running } + if running == 2 && most == 2 { + select { + case <-release: + default: + close(release) + } + } mu.Unlock() - time.Sleep(40 * time.Millisecond) + select { + case <-release: + case <-time.After(30 * time.Second): + } mu.Lock() running-- mu.Unlock() diff --git a/modules/mesh-files/cmd/mesh-files/reads_test.go b/modules/mesh-files/cmd/mesh-files/reads_test.go index 60d8c8fa..162e5f72 100644 --- a/modules/mesh-files/cmd/mesh-files/reads_test.go +++ b/modules/mesh-files/cmd/mesh-files/reads_test.go @@ -198,7 +198,7 @@ func TestOnlyATextFileIsRead(t *testing.T) { if err == nil || !strings.Contains(err.Error(), "fifo") { t.Errorf("a fifo: %v", err) } - case <-time.After(5 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("a read of a fifo waits for a writer") } } diff --git a/modules/mesh-issues/cmd/mesh-issues/caller_test.go b/modules/mesh-issues/cmd/mesh-issues/caller_test.go index 3bcf32ad..6016f499 100644 --- a/modules/mesh-issues/cmd/mesh-issues/caller_test.go +++ b/modules/mesh-issues/cmd/mesh-issues/caller_test.go @@ -50,7 +50,7 @@ func (s *served) call(t *testing.T, verb, caller string, args map[string]any) (m var line []byte select { case line = <-done: - case <-time.After(5 * time.Second): + case <-time.After(30 * time.Second): t.Fatalf("%s was not answered", verb) } var m struct { diff --git a/modules/mesh-knowledge/cmd/mesh-knowledge/bus_test.go b/modules/mesh-knowledge/cmd/mesh-knowledge/bus_test.go index 06ba0ad6..03c87498 100644 --- a/modules/mesh-knowledge/cmd/mesh-knowledge/bus_test.go +++ b/modules/mesh-knowledge/cmd/mesh-knowledge/bus_test.go @@ -380,7 +380,7 @@ func TestTheKnowledgeBaseOverTheBus(t *testing.T) { t.Fatalf("history: %+v", h) } // Every change said on the bus, as the module, with who acted. - deadline := time.Now().Add(5 * time.Second) + deadline := time.Now().Add(30 * time.Second) for time.Now().Before(deadline) && len(w.of(EventProposed)) == 0 { time.Sleep(50 * time.Millisecond) } diff --git a/modules/mesh-knowledge/cmd/mesh-knowledge/caller_test.go b/modules/mesh-knowledge/cmd/mesh-knowledge/caller_test.go index 6c7daf3a..fda26020 100644 --- a/modules/mesh-knowledge/cmd/mesh-knowledge/caller_test.go +++ b/modules/mesh-knowledge/cmd/mesh-knowledge/caller_test.go @@ -46,7 +46,7 @@ func whoCalled(t *testing.T, params map[string]any) string { select { case who := <-got: return who - case <-time.After(3 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("the call was not answered") return "" } diff --git a/modules/mesh-mail-notifier/cmd/mesh-mail-notifier/run_test.go b/modules/mesh-mail-notifier/cmd/mesh-mail-notifier/run_test.go index 8a725595..4cbaa075 100644 --- a/modules/mesh-mail-notifier/cmd/mesh-mail-notifier/run_test.go +++ b/modules/mesh-mail-notifier/cmd/mesh-mail-notifier/run_test.go @@ -38,7 +38,7 @@ func TestRunStartsTheWatcherEvenWhenStdinIsAtEOF(t *testing.T) { select { case <-started: - case <-time.After(time.Second): + case <-time.After(30 * time.Second): t.Fatal("the watcher was not started before stdio.Serve returned") } @@ -47,7 +47,7 @@ func TestRunStartsTheWatcherEvenWhenStdinIsAtEOF(t *testing.T) { if err != nil { t.Fatalf("run over stdin at EOF: %v", err) } - case <-time.After(time.Second): + case <-time.After(30 * time.Second): t.Fatal("run did not return once stdin reached EOF, as systemd gives a process nobody talks to") } @@ -55,12 +55,12 @@ func TestRunStartsTheWatcherEvenWhenStdinIsAtEOF(t *testing.T) { // not yet torn down. A watcher that stopped when run returned would never take this ping. select { case ping <- struct{}{}: - case <-time.After(time.Second): + case <-time.After(30 * time.Second): t.Fatal("the watcher is no longer running once run returned: it must not stop just because stdio.Serve did") } select { case <-pong: - case <-time.After(time.Second): + case <-time.After(30 * time.Second): t.Fatal("the watcher did not answer once run returned") } close(ping) @@ -98,13 +98,13 @@ func TestWatchRetriesASubscribeRefusalWithBackoffAndNeverExits(t *testing.T) { if err != nil { t.Fatalf("run over stdin at EOF: %v", err) } - case <-time.After(time.Second): + case <-time.After(30 * time.Second): t.Fatal("run did not return once stdin reached EOF: a subscribe refusal must not hold up or kill the process") } select { case <-subscribed: - case <-time.After(time.Second): + case <-time.After(30 * time.Second): t.Fatal("the watcher never subscribed after its first two refusals") } diff --git a/modules/mesh-mail-reader/cmd/mesh-mail-reader/batch_test.go b/modules/mesh-mail-reader/cmd/mesh-mail-reader/batch_test.go index c882125b..31f17462 100644 --- a/modules/mesh-mail-reader/cmd/mesh-mail-reader/batch_test.go +++ b/modules/mesh-mail-reader/cmd/mesh-mail-reader/batch_test.go @@ -127,7 +127,7 @@ func TestThirtyWaitingMailsRunAsThreeBatchesAtLeast160sApart(t *testing.T) { }() select { case <-done: - case <-time.After(5 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("RunBatches did not stop after its own 3rd batch and this test's cancel") } diff --git a/modules/mesh-provisioner-client/cmd/mesh-provisioner-client/asks_test.go b/modules/mesh-provisioner-client/cmd/mesh-provisioner-client/asks_test.go index 844f58a6..3b48beb0 100644 --- a/modules/mesh-provisioner-client/cmd/mesh-provisioner-client/asks_test.go +++ b/modules/mesh-provisioner-client/cmd/mesh-provisioner-client/asks_test.go @@ -39,7 +39,7 @@ func aToolRunner(t *testing.T, b *aBus) *toolRunner { func (r *toolRunner) ask(body string) Answered { r.t.Helper() var a Answered - deadline := time.Now().Add(10 * time.Second) + deadline := time.Now().Add(30 * time.Second) for { msg, err := r.nc.Request(AskSubject(node), []byte(body), 2*time.Second) if err == nil { @@ -83,7 +83,7 @@ func (b *aBus) placed(t *testing.T, module string) { func until(t *testing.T, heard chan string, want string) { t.Helper() - deadline := time.After(10 * time.Second) + deadline := time.After(30 * time.Second) for { select { case got := <-heard: diff --git a/modules/mesh-provisioner-client/cmd/mesh-provisioner-client/client_test.go b/modules/mesh-provisioner-client/cmd/mesh-provisioner-client/client_test.go index 68ecc23f..72c25edd 100644 --- a/modules/mesh-provisioner-client/cmd/mesh-provisioner-client/client_test.go +++ b/modules/mesh-provisioner-client/cmd/mesh-provisioner-client/client_test.go @@ -404,10 +404,10 @@ func aClient(t *testing.T, b *aBus, e *engine, state string) (*Client, func()) { func eventually(t *testing.T, what string, ok func() bool) { t.Helper() - deadline := time.Now().Add(10 * time.Second) + deadline := time.Now().Add(30 * time.Second) for !ok() { if time.Now().After(deadline) { - t.Fatalf("not within 10s: %s", what) + t.Fatalf("not within 30s: %s", what) } time.Sleep(20 * time.Millisecond) } @@ -502,7 +502,8 @@ func TestNatsAChangeRefillsWritesOnceAndTheProgramTakesIt(t *testing.T) { // again (ADR 0349 clause 5), which answers unchanged, so the program is not reloaded for it. b.config(t, "dunst", "font-size", "15") b.config(t, "dunst", "geometry", `"300x5"`) - time.Sleep(300 * time.Millisecond) + eventually(t, "the node-engine is asked for the file again by each fill", func() bool { _, asked := e.counts(dunstrc); return asked >= 3 }) + time.Sleep(300 * time.Millisecond) // any stray extra write would come now if moved, asked := e.counts(dunstrc); moved != 2 || asked != 3 { t.Errorf("two values wrote dunstrc %d times (asked %d); want 2 and 3: the program is reloaded once a change, "+ "the file asked again each fill", moved, asked) diff --git a/modules/mesh-provisioner-client/cmd/mesh-provisioner-client/socket_integration_test.go b/modules/mesh-provisioner-client/cmd/mesh-provisioner-client/socket_integration_test.go index 2bd3860c..0617310d 100644 --- a/modules/mesh-provisioner-client/cmd/mesh-provisioner-client/socket_integration_test.go +++ b/modules/mesh-provisioner-client/cmd/mesh-provisioner-client/socket_integration_test.go @@ -83,7 +83,7 @@ func TestWatchSocketWakesWhenTheSocketIsMadeAndWhenItsDirectoryReturns(t *testin t.Helper() select { case <-up: - case <-time.After(5 * time.Second): + case <-time.After(30 * time.Second): t.Fatalf("no wake for %s", what) } } diff --git a/modules/mesh-reads/cmd/mesh-reads/reads_test.go b/modules/mesh-reads/cmd/mesh-reads/reads_test.go index 461892e8..045d8489 100644 --- a/modules/mesh-reads/cmd/mesh-reads/reads_test.go +++ b/modules/mesh-reads/cmd/mesh-reads/reads_test.go @@ -214,7 +214,7 @@ func TestOnlyATextFileIsRead(t *testing.T) { if err == nil || !strings.Contains(err.Error(), "fifo") { t.Errorf("a fifo: %v", err) } - case <-time.After(5 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("a read of a fifo waits for a writer") } } diff --git a/modules/mesh-vault/cmd/mesh-vault/core_test.go b/modules/mesh-vault/cmd/mesh-vault/core_test.go index a22f7d5f..bbc6826e 100644 --- a/modules/mesh-vault/cmd/mesh-vault/core_test.go +++ b/modules/mesh-vault/cmd/mesh-vault/core_test.go @@ -175,7 +175,7 @@ authorization { controller := connectAs(t, url, "controller") ask = func(name, key string) (Answer, error) { raw, _ := json.Marshal(map[string]string{"name": name, "public_key": key}) - msg, err := controller.Request("mesh.seat.mesh-vault.call.get.controller", raw, 3*time.Second) + msg, err := controller.Request("mesh.seat.mesh-vault.call.get.controller", raw, 30*time.Second) if err != nil { return Answer{}, err } diff --git a/modules/mesh-vault/cmd/mesh-vault/nodekey_test.go b/modules/mesh-vault/cmd/mesh-vault/nodekey_test.go index 3e5681bb..cc721a48 100644 --- a/modules/mesh-vault/cmd/mesh-vault/nodekey_test.go +++ b/modules/mesh-vault/cmd/mesh-vault/nodekey_test.go @@ -170,7 +170,7 @@ func TestOnARealBusANodeEngineStatesOnlyItsOwnKey(t *testing.T) { call := func(user, subject string, args any) (json.RawMessage, error) { raw, _ := json.Marshal(args) - msg, err := connectAs(t, s.ClientURL(), user).Request(subject, raw, 3*time.Second) + msg, err := connectAs(t, s.ClientURL(), user).Request(subject, raw, 30*time.Second) if err != nil { return nil, err } diff --git a/modules/messenger/cmd/messenger/answers_test.go b/modules/messenger/cmd/messenger/answers_test.go index c1ff0d0f..28595124 100644 --- a/modules/messenger/cmd/messenger/answers_test.go +++ b/modules/messenger/cmd/messenger/answers_test.go @@ -882,7 +882,7 @@ func TestBreakGlassIsAFileRootMadeAndTheMinuteGoesOn(t *testing.T) { go func() { h.Tick(); close(done) }() select { case <-done: - case <-time.After(5 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("the router's minute hung on a break-glass file") } } diff --git a/modules/messenger/cmd/messenger/review_test.go b/modules/messenger/cmd/messenger/review_test.go index 0ecb1b39..d60ff535 100644 --- a/modules/messenger/cmd/messenger/review_test.go +++ b/modules/messenger/cmd/messenger/review_test.go @@ -552,7 +552,7 @@ func TestTheRootFreeWordIsNotAskedWhileTheWorkIsHeld(t *testing.T) { }() select { case <-linked: - case <-time.After(2 * time.Second): + case <-time.After(30 * time.Second): close(slow) t.Fatal("a link waited for the controller's root-free word: the work was held while it was asked") } diff --git a/modules/mounts/cmd/mounts/failed_test.go b/modules/mounts/cmd/mounts/failed_test.go index 38431990..07b8d35d 100644 --- a/modules/mounts/cmd/mounts/failed_test.go +++ b/modules/mounts/cmd/mounts/failed_test.go @@ -126,12 +126,12 @@ func TestTheActingProcessClearsBetweenItsLooks(t *testing.T) { go func() { RunApply(ctx, a); close(done) }() defer func() { cancel(); <-done }() - if !waitFor(t, 2*time.Second, func() bool { return f.called("systemctl enable --now srv-library.automount") }) { + if !waitFor(t, 30*time.Second, func() bool { return f.called("systemctl enable --now srv-library.automount") }) { t.Fatal("the first look did not arm the pair") } // The server is away and someone opened the mount point: the mount failed after the look. f.setUnit("srv-library.mount", map[string]string{"ActiveState": "failed", "Result": "timeout"}) - if !waitFor(t, 2*time.Second, func() bool { return f.called("systemctl reset-failed srv-library.mount") }) { + if !waitFor(t, 30*time.Second, func() bool { return f.called("systemctl reset-failed srv-library.mount") }) { t.Fatal("a mount that failed between looks, its server away, is cleared before the next look") } } diff --git a/modules/nats/cmd/mesh-nats-snapshot/live_test.go b/modules/nats/cmd/mesh-nats-snapshot/live_test.go index a9918d6c..cd64c0fc 100644 --- a/modules/nats/cmd/mesh-nats-snapshot/live_test.go +++ b/modules/nats/cmd/mesh-nats-snapshot/live_test.go @@ -576,7 +576,7 @@ func TestTheSnapshotUserCannotChangeTheBus(t *testing.T) { if !strings.Contains(strings.ToLower(e.Error()), "permissions violation") { t.Errorf("%s: %v", subject, e) } - case <-time.After(2 * time.Second): + case <-time.After(30 * time.Second): t.Errorf("the server did not refuse %s", subject) } } @@ -590,7 +590,7 @@ func TestTheSnapshotUserCannotChangeTheBus(t *testing.T) { if !strings.Contains(strings.ToLower(e.Error()), "permissions violation") { t.Errorf("subscribing %s: %v", subject, e) } - case <-time.After(2 * time.Second): + case <-time.After(30 * time.Second): t.Errorf("the server let the snapshot user subscribe %s", subject) } } diff --git a/modules/postgres/cmd/postgres-provider/moved_test.go b/modules/postgres/cmd/postgres-provider/moved_test.go index 4070507c..a730302e 100644 --- a/modules/postgres/cmd/postgres-provider/moved_test.go +++ b/modules/postgres/cmd/postgres-provider/moved_test.go @@ -48,7 +48,7 @@ func TestTheGrantPathLeavesWhenTheConsumersFileIsFilled(t *testing.T) { } select { case <-done: - case <-time.After(2 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("did not leave when the file was filled") } } diff --git a/modules/restic/cmd/restic-backups/data_test.go b/modules/restic/cmd/restic-backups/data_test.go index 9e41411d..51ce5d46 100644 --- a/modules/restic/cmd/restic-backups/data_test.go +++ b/modules/restic/cmd/restic-backups/data_test.go @@ -140,7 +140,7 @@ func TestARetiredItemIsDeletedOnlyAfterALastRestorePoint(t *testing.T) { wait := func(path string) Deletion { t.Helper() - for i := 0; i < 200; i++ { + for i := 0; i < 6000; i++ { if d, err := b.DeletedOutcome(path); err == nil && d.Done { return d } diff --git a/modules/restic/cmd/restic-backups/health_test.go b/modules/restic/cmd/restic-backups/health_test.go index 76ce1550..4db6c7ef 100644 --- a/modules/restic/cmd/restic-backups/health_test.go +++ b/modules/restic/cmd/restic-backups/health_test.go @@ -229,7 +229,7 @@ func TestANightWaitsForAnotherProcesssNight(t *testing.T) { release() select { case <-done: - case <-time.After(5 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("the night did not run once the other let go") } } diff --git a/modules/screen-lock/cmd/screen-lock-tools/lock_test.go b/modules/screen-lock/cmd/screen-lock-tools/lock_test.go index 7925c9b6..98279308 100644 --- a/modules/screen-lock/cmd/screen-lock-tools/lock_test.go +++ b/modules/screen-lock/cmd/screen-lock-tools/lock_test.go @@ -170,7 +170,12 @@ func TestAnInhibitionTurnsIdleOffAndRestoresWhatWasThereWhenItEndsOrIsStopped(t if err := cmd.Start(); err != nil { t.Fatal(err) } - time.Sleep(300 * time.Millisecond) + // stop it only once it has turned idle off: the trap is set before that, and a slow start must not be signalled early + for end := time.Now().Add(30 * time.Second); time.Now().Before(end); time.Sleep(10 * time.Millisecond) { + if b, _ := os.ReadFile(filepath.Join(dir, "log")); strings.Contains(string(b), "s off -dpms") { + break + } + } _ = cmd.Process.Signal(os.Interrupt) _ = cmd.Wait() got, _ := os.ReadFile(filepath.Join(dir, "log")) diff --git a/modules/sensors/cmd/sensors/second_review_test.go b/modules/sensors/cmd/sensors/second_review_test.go index 21ff3386..7cac4c04 100644 --- a/modules/sensors/cmd/sensors/second_review_test.go +++ b/modules/sensors/cmd/sensors/second_review_test.go @@ -31,10 +31,10 @@ func TestAStuckReadIsUnhealthyAndDoesNotStopTheOtherDrives(t *testing.T) { if err != nil { t.Fatal(err) } - case <-time.After(5 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("a look waited on a stuck drive") } - deadline := time.Now().Add(5 * time.Second) + deadline := time.Now().Add(30 * time.Second) for { _ = w.write() r, _ := m.ReadReadings(DrivesPath) diff --git a/modules/ssh-client/cmd/ssh-client-tools/sweep_test.go b/modules/ssh-client/cmd/ssh-client-tools/sweep_test.go index cf60a604..a001c806 100644 --- a/modules/ssh-client/cmd/ssh-client-tools/sweep_test.go +++ b/modules/ssh-client/cmd/ssh-client-tools/sweep_test.go @@ -267,7 +267,7 @@ func TestSweepDoesNotOpenAPipe(t *testing.T) { if err != nil { t.Fatal(err) } - case <-time.After(2 * time.Second): + case <-time.After(30 * time.Second): t.Fatal("the sweep blocked on a pipe") } } diff --git a/modules/systemd-resolved/cmd/resolver-tools/guard_test.go b/modules/systemd-resolved/cmd/resolver-tools/guard_test.go index 535ba357..2306730b 100644 --- a/modules/systemd-resolved/cmd/resolver-tools/guard_test.go +++ b/modules/systemd-resolved/cmd/resolver-tools/guard_test.go @@ -185,7 +185,7 @@ func TestTheVerbsOnTheMachine(t *testing.T) { defer cancel() sock := filepath.Join(g.Dir, "verbs.sock") go func() { _ = g.Serve(ctx, sock) }() - for i := 0; i < 100; i++ { + for i := 0; i < 3000; i++ { if _, err := os.Stat(sock); err == nil { break } @@ -233,7 +233,7 @@ func TestTheVerbsOnTheMachine(t *testing.T) { select { case <-g.wake: g.Tick() - case <-time.After(time.Second): + case <-time.After(30 * time.Second): t.Fatal("taking the write did not wake the guard") } if contentOf(t, g.Path) != meshFile { diff --git a/modules/zfs/cmd/zfs-tools/review_test.go b/modules/zfs/cmd/zfs-tools/review_test.go index 6fb40191..0eda82f4 100644 --- a/modules/zfs/cmd/zfs-tools/review_test.go +++ b/modules/zfs/cmd/zfs-tools/review_test.go @@ -26,11 +26,11 @@ func TestATimedOutCommandIsEndedWithItsChildren(t *testing.T) { KillGrace = 300 * time.Millisecond defer func() { KillGrace = old }() pidFile := filepath.Join(t.TempDir(), "child") - ctx, cancel := context.WithTimeout(context.Background(), 300*time.Millisecond) + ctx, cancel := context.WithTimeout(context.Background(), 3*time.Second) // long enough for a loaded machine to start the shell and write the pid defer cancel() start := time.Now() r := ExecRunner(ctx, "sh", "-c", "sleep 30 & echo $! > "+pidFile+"; wait") - if took := time.Since(start); took > 5*time.Second { + if took := time.Since(start); took > 30*time.Second { t.Fatalf("the call waited %s for a child holding its output", took) } if !r.TimedOut { @@ -41,7 +41,9 @@ func TestATimedOutCommandIsEndedWithItsChildren(t *testing.T) { t.Fatal(err) } pid, _ := strconv.Atoi(strings.TrimSpace(string(b))) - time.Sleep(100 * time.Millisecond) + // the kill is sent before the answer; give the system up to 30 s to take the child away + for end := time.Now().Add(30 * time.Second); time.Now().Before(end) && syscall.Kill(pid, 0) == nil; time.Sleep(10 * time.Millisecond) { + } if err := syscall.Kill(pid, 0); err == nil { syscall.Kill(pid, syscall.SIGKILL) t.Errorf("the child %d outlived the timeout", pid) From 5ccce4967a98e2e368f9e24558574f829999eaa9 Mon Sep 17 00:00:00 2001 From: jochen Date: Sun, 1 Nov 2026 17:26:58 +0100 Subject: [PATCH 7/7] Keep three timeout tests' upper bounds well under the production timeouts, so a timeout that falls back to production still fails (issue 1814, review round 3) Claude-Session: https://claude.ai/code/session_01NcbgfJ9Gum47zkFKWRaovL --- modules/claude-code/cmd/claude-code/agent_account_test.go | 2 +- modules/claude-code/cmd/claude-code/judge_test.go | 2 +- modules/zfs/cmd/zfs-tools/review_test.go | 4 ++-- 3 files changed, 4 insertions(+), 4 deletions(-) diff --git a/modules/claude-code/cmd/claude-code/agent_account_test.go b/modules/claude-code/cmd/claude-code/agent_account_test.go index 60af230b..ec597b7b 100644 --- a/modules/claude-code/cmd/claude-code/agent_account_test.go +++ b/modules/claude-code/cmd/claude-code/agent_account_test.go @@ -567,7 +567,7 @@ func TestAHelperThatDoesNotAnswerFailsTheRequestInTime(t *testing.T) { if err == nil || !errors.Is(err, errHelperSlow) { t.Fatalf("a silent helper answered: %v", err) } - if time.Since(start) > 30*time.Second { + if time.Since(start) > 10*time.Second { t.Fatalf("the request waited %s", time.Since(start)) } } diff --git a/modules/claude-code/cmd/claude-code/judge_test.go b/modules/claude-code/cmd/claude-code/judge_test.go index 0f714872..4fd3da1f 100644 --- a/modules/claude-code/cmd/claude-code/judge_test.go +++ b/modules/claude-code/cmd/claude-code/judge_test.go @@ -133,7 +133,7 @@ func TestAJudgementWaitsItsTurnWithinTheBound(t *testing.T) { if err == nil || !strings.Contains(err.Error(), "another judgement") { t.Fatalf("%v", err) } - if time.Since(start) > 30*time.Second { + if time.Since(start) > 10*time.Second { t.Fatal("waited past the bound") } } diff --git a/modules/zfs/cmd/zfs-tools/review_test.go b/modules/zfs/cmd/zfs-tools/review_test.go index 0eda82f4..8d8408b1 100644 --- a/modules/zfs/cmd/zfs-tools/review_test.go +++ b/modules/zfs/cmd/zfs-tools/review_test.go @@ -29,8 +29,8 @@ func TestATimedOutCommandIsEndedWithItsChildren(t *testing.T) { ctx, cancel := context.WithTimeout(context.Background(), 3*time.Second) // long enough for a loaded machine to start the shell and write the pid defer cancel() start := time.Now() - r := ExecRunner(ctx, "sh", "-c", "sleep 30 & echo $! > "+pidFile+"; wait") - if took := time.Since(start); took > 30*time.Second { + r := ExecRunner(ctx, "sh", "-c", "sleep 300 & echo $! > "+pidFile+"; wait") + if took := time.Since(start); took > 10*time.Second { t.Fatalf("the call waited %s for a child holding its output", took) } if !r.TimedOut {