diff --git a/testing/chaos/scenarios/ethernet-churn.yaml b/testing/chaos/scenarios/ethernet-churn.yaml index ca9b3cde..89149afe 100644 --- a/testing/chaos/scenarios/ethernet-churn.yaml +++ b/testing/chaos/scenarios/ethernet-churn.yaml @@ -79,35 +79,34 @@ node_churn: protect_connectivity: true assertions: - # The mesh re-forms after each interface comes back. + # The mesh re-forms after each interface comes back, fully. # - # Calibrated 2026-09-02 against four runs, all at this file's fixed seed 42 - # and therefore an identical churn schedule, so the spread is container - # timing rather than differing scenarios: + # Calibrated 2026-09-10 against sixteen runs, eight on master-line code and + # eight on next-line code, on a harness that fails a veth restore it cannot + # complete and waits for the tree to settle before the final snapshot. Twelve + # ran beside the other five CI chaos scenarios and four CPU busy loops; seeds + # 42 (twelve runs), 7 and 1234: # - # nodes answering 4 in all four runs - # distinct roots 2 in all four runs - # nodes parented 2 in all four runs - # traffic 3-5 sessions, 206-388 MB + # nodes answering 4 in all sixteen + # distinct roots 1 in all sixteen + # nodes parented 3 in all sixteen + # settle 11-22 s + # traffic 4-11 sessions per run, 3.8-11.7 GB # - # `max_roots: 1` was wrong and failed every run: the harness restores - # stopped nodes immediately before the final snapshot, so a node that has - # just restarted has not re-parented yet and is briefly its own root. That - # is the scenario working, not failing. + # So the thresholds are full convergence: every node answers, one root, three + # parented. A red here is a mesh that did not re-form. # - # The ceiling is 3, one step beyond the observed maximum of 2, with the - # parented floor at its complement. A mesh that genuinely collapsed — every - # node islanded — still fails, which is all this assertion is for. Do not - # read a pass as convergence. - # - # READ BEFORE RETUNING: four runs is a thin sample. `churn-mixed` documents - # what happens when a threshold is set one step outside a small one — it - # ends up inside the real distribution and reddens runs whatever the daemon - # does. Widen on evidence; tighten only against a much larger sample. + # READ BEFORE RETUNING: the 2026-09-02 calibration recorded 2 roots and 2 + # parented in all four of its runs, and that was not the daemon. The veth + # restore then failed silently whenever a stopped node's namespace outlived + # the stop, and in every later run that was inspected, the node islanded at + # the snapshot was one whose links the harness had left down. Before widening these, read the red run's runner.log for a + # harness fault; a failed restore now aborts the run rather than reaching + # this assertion. baseline: - min_nodes_reporting: 3 - max_roots: 3 - min_nodes_parented: 2 + min_nodes_reporting: 4 + max_roots: 1 + min_nodes_parented: 3 # The point of the scenario. Traffic must actually have crossed Ethernet # links while interfaces were being taken away underneath it — a green tree diff --git a/testing/chaos/sim/netem.py b/testing/chaos/sim/netem.py index 3ac8d0e2..e95d8548 100644 --- a/testing/chaos/sim/netem.py +++ b/testing/chaos/sim/netem.py @@ -370,22 +370,42 @@ class NetemManager: # Re-apply Ethernet veth netem veth_states = self.veth_states.get(container) if veth_states: - for iface, state in veth_states.items(): - cmd = ( - f"tc qdisc del dev {iface} root 2>/dev/null || true && " - f"tc qdisc add dev {iface} root netem {state.params.to_tc_args()}" - ) - result = docker_exec_quiet(container, cmd, timeout=10) - if result is not None: - log.debug("Re-applied veth netem on %s:%s", container, iface) - else: - log.warning("Failed to re-apply veth netem on %s:%s", container, iface) + for state in veth_states.values(): + self._apply_veth(state) log.info( "Re-applied veth netem on %s (%d Ethernet peers)", container, len(veth_states), ) + # And on each running neighbour's end of those links. The restore + # recreates the whole pair, so the survivor's end is a new interface + # with no qdisc, and without this that direction of every restored + # link ran unshaped for the rest of the run. + for peer_id in sorted(self.topology.nodes[node_id].peers): + if peer_id in self.down_nodes: + continue + if self.topology.transport_for_edge(node_id, peer_id) != "ethernet": + continue + peer_container = self.topology.container_name(peer_id) + state = self.veth_states.get(peer_container, {}).get( + veth_interface_name(peer_id, node_id) + ) + if state is not None: + self._apply_veth(state) + + def _apply_veth(self, state: VethNetemState): + """Install a veth end's current netem parameters as its root qdisc.""" + cmd = ( + f"tc qdisc del dev {state.iface} root 2>/dev/null || true && " + f"tc qdisc add dev {state.iface} root netem {state.params.to_tc_args()}" + ) + result = docker_exec_quiet(state.container, cmd, timeout=10) + if result is not None: + log.debug("Re-applied veth netem on %s:%s", state.container, state.iface) + else: + log.warning("Failed to re-apply veth netem on %s:%s", state.container, state.iface) + def mutate(self): """Randomly mutate netem params on a fraction of links.""" if not self.config.mutation.policies: diff --git a/testing/chaos/sim/nodes.py b/testing/chaos/sim/nodes.py index 2a69f7c3..75565d6b 100644 --- a/testing/chaos/sim/nodes.py +++ b/testing/chaos/sim/nodes.py @@ -50,7 +50,10 @@ class NodeManager: self.rng = rng self.netem_mgr = netem_mgr self.veth_mgr = veth_mgr - self.down_nodes = down_nodes or set() + # `is not None`, not `or`: the runner passes its shared set while it + # is still empty, and an empty set is falsy, so `or` replaced it with + # a private one and no other manager ever saw a node go down. + self.down_nodes = down_nodes if down_nodes is not None else set() self.on_node_restart = on_node_restart self.node_states: dict[str, NodeState] = { nid: NodeState(node_id=nid) for nid in topology.nodes @@ -173,7 +176,11 @@ class NodeManager: # Re-create veth pairs (container restart destroys netns) if self.veth_mgr: time.sleep(1) - self.veth_mgr.setup_node(node_id) + # Churn's own record, not the shared set: netem's safety net also + # adds to that set, on a docker hiccup or a crash churn did not + # cause, and a pair deferred on that basis would never be rebuilt. + stopped = {nid for nid, ns in self.node_states.items() if ns.is_down} + self.veth_mgr.setup_node(node_id, stopped) # Re-apply netem after a brief delay for the container to initialize if self.netem_mgr: diff --git a/testing/chaos/sim/runner.py b/testing/chaos/sim/runner.py index 502febe6..1d9df9de 100644 --- a/testing/chaos/sim/runner.py +++ b/testing/chaos/sim/runner.py @@ -42,11 +42,21 @@ from .veth import VethManager log = logging.getLogger(__name__) +# The final snapshot waits for this many identical consecutive tree reads, +# taken this far apart, so the tree must hold still for two intervals. +SETTLE_READS = 3 +SETTLE_INTERVAL_SECS = 5 +SETTLE_TIMEOUT_SECS = 90 + class SimRunner: def __init__(self, scenario: Scenario): self.scenario = scenario + # Setup draws only: the topology and the ephemeral node choice, made + # once and in a fixed order. Everything drawn while the simulation + # runs comes from `_stream` instead. self.rng = random.Random(scenario.seed) + self._streams: dict[str, random.Random] = {} self.topology: SimTopology | None = None self.compose_file: str | None = None # Claimed in _setup; the compose file refers to it as external, so @@ -317,14 +327,16 @@ class SimRunner: if s.netem.enabled: bw = s.bandwidth if s.bandwidth.enabled else None ig = s.ingress if s.ingress.enabled else None - self.netem_mgr = NetemManager(self.topology, s.netem, self.rng, bandwidth=bw, ingress=ig) + self.netem_mgr = NetemManager( + self.topology, s.netem, self._stream("netem"), bandwidth=bw, ingress=ig + ) self.netem_mgr.down_nodes = self._down_nodes log.info("Applying initial per-link netem...") self.netem_mgr.setup_initial() if s.link_flaps.enabled: self.link_mgr = LinkManager( - self.topology, s.link_flaps, self.rng, netem_mgr=self.netem_mgr + self.topology, s.link_flaps, self._stream("flaps"), netem_mgr=self.netem_mgr ) if s.link_swap.enabled: @@ -333,7 +345,7 @@ class SimRunner: "link_swap requires netem.enabled (depends on per-link tc state)" ) self.link_swap_mgr = LinkSwapManager( - self.topology, s.link_swap, self.netem_mgr, self.rng, + self.topology, s.link_swap, self.netem_mgr, self._stream("swap"), ) if s.assertions.bloom_send_rate is not None: @@ -343,12 +355,12 @@ class SimRunner: if s.traffic.enabled: self.traffic_mgr = TrafficManager( - self.topology, s.traffic, self.rng, down_nodes=self._down_nodes + self.topology, s.traffic, self._stream("traffic"), down_nodes=self._down_nodes ) if s.node_churn.enabled: self.node_mgr = NodeManager( - self.topology, s.node_churn, self.rng, + self.topology, s.node_churn, self._stream("churn"), netem_mgr=self.netem_mgr, down_nodes=self._down_nodes, veth_mgr=self.veth_mgr, on_node_restart=self._handle_node_restart, @@ -356,7 +368,7 @@ class SimRunner: if s.peer_churn.enabled: self.peer_churn_mgr = PeerChurnManager( - self.topology, s.peer_churn, self.rng, + self.topology, s.peer_churn, self._stream("peer-churn"), down_nodes=self._down_nodes, ephemeral_nodes=self._ephemeral_nodes, ) @@ -411,11 +423,11 @@ class SimRunner: log.info("Simulation running for %ds...", duration) # Schedule first events - next_netem = self._schedule_next(start, s.netem.mutation.interval_secs) if self.netem_mgr else float("inf") - next_flap = self._schedule_next(start, s.link_flaps.interval_secs) if self.link_mgr else float("inf") - next_traffic = self._schedule_next(start, s.traffic.interval_secs) if self.traffic_mgr else float("inf") - next_churn = self._schedule_next(start, s.node_churn.interval_secs) if self.node_mgr else float("inf") - next_peer_churn = self._schedule_next(start, s.peer_churn.interval_secs) if self.peer_churn_mgr else float("inf") + next_netem = self._schedule_next(start, s.netem.mutation.interval_secs, "netem") if self.netem_mgr else float("inf") + next_flap = self._schedule_next(start, s.link_flaps.interval_secs, "flaps") if self.link_mgr else float("inf") + next_traffic = self._schedule_next(start, s.traffic.interval_secs, "traffic") if self.traffic_mgr else float("inf") + next_churn = self._schedule_next(start, s.node_churn.interval_secs, "churn") if self.node_mgr else float("inf") + next_peer_churn = self._schedule_next(start, s.peer_churn.interval_secs, "peer-churn") if self.peer_churn_mgr else float("inf") # Bloom-send-rate assertion: sample at window_secs before end. bloom_window_start_at = float("inf") @@ -452,34 +464,34 @@ class SimRunner: # Netem mutation if self.netem_mgr and now >= next_netem: self.netem_mgr.mutate() - next_netem = self._schedule_next(now, s.netem.mutation.interval_secs) + next_netem = self._schedule_next(now, s.netem.mutation.interval_secs, "netem") # Link flaps if self.link_mgr: if now >= next_flap: self.link_mgr.maybe_flap() - next_flap = self._schedule_next(now, s.link_flaps.interval_secs) + next_flap = self._schedule_next(now, s.link_flaps.interval_secs, "flaps") self.link_mgr.restore_expired() # Traffic generation if self.traffic_mgr: if now >= next_traffic: self.traffic_mgr.maybe_spawn() - next_traffic = self._schedule_next(now, s.traffic.interval_secs) + next_traffic = self._schedule_next(now, s.traffic.interval_secs, "traffic") self.traffic_mgr.cleanup_expired() # Node churn if self.node_mgr: if now >= next_churn: self.node_mgr.maybe_kill() - next_churn = self._schedule_next(now, s.node_churn.interval_secs) + next_churn = self._schedule_next(now, s.node_churn.interval_secs, "churn") self.node_mgr.restore_expired() # Peer churn (topology mutation) if self.peer_churn_mgr: if now >= next_peer_churn: self.peer_churn_mgr.maybe_churn() - next_peer_churn = self._schedule_next(now, s.peer_churn.interval_secs) + next_peer_churn = self._schedule_next(now, s.peer_churn.interval_secs, "peer-churn") # Status line down_links = self.link_mgr.down_count if self.link_mgr else 0 @@ -709,7 +721,11 @@ class SimRunner: json.dump(iperf_results, f, indent=2) log.info("Saved %d iperf3 results to %s", len(iperf_results), iperf_path) - # Take final tree snapshot while nodes are still running + # Take final tree snapshot while nodes are still running, once the + # tree has stopped moving. A node restored a moment ago is its own + # root until it re-parents, so a snapshot taken straight after the + # restore reads a mesh still converging. + self._settle_tree() self._take_snapshot("final") # Collect logs before stopping containers @@ -847,6 +863,46 @@ class SimRunner: return result + def _settle_tree(self): + """Wait until consecutive tree reads agree, or the settle time runs out. + + Compares each answering node's root and parent. A fixed delay would + either waste time on a mesh that settled at once or cut off one that + had not. Running out is logged and is not a failure in itself: the + final snapshot is taken anyway, and the assertions judge what it + shows. + + A read that no node answered never counts toward agreement. It does + not catch a node that stays its own root for longer than the reads + span, which is a tree that is stable and wrong, and is left to the + assertions. + """ + started = time.time() + previous = None + agreeing = 0 + while not self._interrupted: + trees = snapshot_all_trees(self.topology) + shape = { + nid: (data.get("root"), data.get("parent")) + for nid, data in trees.items() + } + if not shape: + agreeing = 0 + else: + agreeing = agreeing + 1 if shape == previous else 1 + previous = shape + waited = time.time() - started + if agreeing >= SETTLE_READS: + log.info("Tree settled after %.0fs", waited) + return + if waited >= SETTLE_TIMEOUT_SECS: + log.warning( + "Tree still changing after %.0fs; taking the final snapshot anyway", + waited, + ) + return + self._sleep(SETTLE_INTERVAL_SECS) + def _take_snapshot(self, label: str): """Query all nodes via control socket and save tree/MMP/congestion snapshots.""" if not self.topology: @@ -883,9 +939,24 @@ class SimRunner: len(self.topology.nodes), ) - def _schedule_next(self, now: float, interval) -> float: - """Schedule the next event using a Range interval.""" - return now + self.rng.uniform(interval.min, interval.max) + def _schedule_next(self, now: float, interval, kind: str) -> float: + """Schedule the next event of one kind using a Range interval.""" + return now + self._stream(f"{kind}-schedule").uniform(interval.min, interval.max) + + def _stream(self, name: str) -> random.Random: + """Return the random stream for one consumer, derived from the seed. + + One stream shared by every manager was drawn in wall-clock order, and + a manager that returns early draws nothing, so host load changed + which node the churn stopped next. Under heavy host load that walked + the stops around the ring. A stream per consumer means one manager's + draws no longer shift another's. It does not make a schedule a + function of the seed alone: a manager's own draws can still depend on + mesh state at the tick, such as which nodes are down. + """ + if name not in self._streams: + self._streams[name] = random.Random(f"{self.scenario.seed}:{name}") + return self._streams[name] def _sleep(self, seconds: float): """Sleep in small increments so SIGINT can break out.""" diff --git a/testing/chaos/sim/scenario.py b/testing/chaos/sim/scenario.py index 19e59954..de6e5dee 100644 --- a/testing/chaos/sim/scenario.py +++ b/testing/chaos/sim/scenario.py @@ -880,14 +880,21 @@ def load_scenario(path: str) -> Scenario: + ", ".join(sorted(_ASSERTION_KEYS["baseline"])) + "; a block with none asserts nothing" ) - if vals.get("min_nodes_parented", 0) > 0 or vals.get("max_roots"): + if vals.get("min_nodes_parented", 0) > 0: + # Every root is its own parent, so a mesh with R roots has at most + # n - R nodes parented. Checked against the roots ceiling rather + # than against one root: a floor above n - max_roots reds a run + # that sits exactly at the ceiling the file itself allows, so the + # two thresholds contradict each other there. n = s.topology.num_nodes - if vals.get("min_nodes_parented", 0) > n - 1: + roots = vals.get("max_roots", 1) + floor = vals["min_nodes_parented"] + if floor > n - roots: raise ValueError( - f"assertions.baseline.min_nodes_parented: " - f"{vals['min_nodes_parented']} exceeds {n - 1}, the most a " - f"{n}-node mesh can reach — the root is its own parent, so " - f"this could never pass" + f"assertions.baseline.min_nodes_parented: {floor} exceeds " + f"{n - roots}, the most a {n}-node mesh with {roots} " + f"root(s) can reach — each root is its own parent, so a " + f"run at the max_roots ceiling could never pass" ) s.assertions.baseline = BaselineAssertion(**vals) diff --git a/testing/chaos/sim/traffic.py b/testing/chaos/sim/traffic.py index 8d9d1e56..28acabe0 100644 --- a/testing/chaos/sim/traffic.py +++ b/testing/chaos/sim/traffic.py @@ -44,7 +44,10 @@ class TrafficManager: self.topology = topology self.config = config self.rng = rng - self.down_nodes = down_nodes or set() + # `is not None`, not `or`: the runner passes its shared set while it + # is still empty, and an empty set is falsy, so `or` replaced it with + # a private one and no other manager ever saw a node go down. + self.down_nodes = down_nodes if down_nodes is not None else set() self.npub_cache = npub_cache or {} self.active_sessions: list[TrafficSession] = [] self.completed_results: list[dict] = [] diff --git a/testing/chaos/sim/veth.py b/testing/chaos/sim/veth.py index a60a25fe..cb1a2228 100644 --- a/testing/chaos/sim/veth.py +++ b/testing/chaos/sim/veth.py @@ -34,12 +34,36 @@ from __future__ import annotations import logging import subprocess +import time -from .docker_exec import docker_exec_quiet +from .docker_exec import DockerExecError, docker_exec, docker_exec_quiet from .topology import SimTopology, veth_interface_name log = logging.getLogger(__name__) +# How long a freshly raised veth end may take to report operstate up. The +# kernel publishes the carrier change through linkwatch, which is deferred, so +# a read straight after `ip link set up` can still see the old state. Long +# enough for at least two reads under host load, since one slow `docker exec` +# must not abort a run whose link is up. +OPERSTATE_WAIT_SECS = 15 + +# Timeout for each `docker exec` a restore makes. The run blocks on these, and +# a timeout aborts it, so this errs long: a loaded host is the normal case. +EXEC_TIMEOUT_SECS = 30 + + +class VethSetupError(RuntimeError): + """A veth pair could not be created, placed, renamed or raised. + + Raised rather than logged. A pair that fails part way leaves a ring link + down while the run carries on, and what reaches the verdict is then a tree + that did not converge: a daemon failure in every respect a reader can see. + Letting this propagate aborts the run, so the fault is reported as the + harness's own. + """ + + class VethManager: """Manages veth pairs for Ethernet-transport edges.""" @@ -102,12 +126,13 @@ class VethManager: len(self._host_pairs), ) - def setup_node(self, node_id: str): + def setup_node(self, node_id: str, down_nodes: set[str] | None = None): """Re-create veth endpoints for a single node after container restart. When a container restarts (node churn), its network namespace is destroyed. We re-create the veth pairs for all Ethernet edges - involving this node. + involving this node. ``down_nodes`` names the neighbours churn has + stopped, whose pairs are left for their own restart. """ image = self._get_image() for a, b in self.topology.ethernet_edges(): @@ -117,7 +142,7 @@ class VethManager: host_a = self.topology.veth_host_name(a, b, "a") _run_host(["ip", "link", "delete", host_a], image, check=False) # Re-create - self._create_veth_pair(a, b, image) + self._create_veth_pair(a, b, image, down_nodes or set()) def teardown_all(self): """Clean up all veth pairs.""" @@ -126,18 +151,40 @@ class VethManager: _run_host(["ip", "link", "delete", host_a], image, check=False) self._host_pairs.clear() - def _create_veth_pair(self, node_a: str, node_b: str, image: str): - """Create a single veth pair between two containers.""" + def _create_veth_pair( + self, node_a: str, node_b: str, image: str, down_nodes: set[str] | None = None + ): + """Create a single veth pair between two containers. + + ``down_nodes`` is None at first setup, when every container must be + running. On a restore it names the nodes churn has stopped. + """ container_a = self.topology.container_name(node_a) container_b = self.topology.container_name(node_b) - # Get container PIDs - pid_a = _get_container_pid(container_a) - pid_b = _get_container_pid(container_b) + pid_a = _container_pid(container_a) + pid_b = _container_pid(container_b) if pid_a is None or pid_b is None: - log.warning( - "Cannot create veth %s--%s: container PID not found", node_a, node_b - ) + stopped = [n for n, pid in ((node_a, pid_a), (node_b, pid_b)) if pid is None] + names = ", ".join(stopped) + if down_nodes is None: + raise VethSetupError( + f"veth {node_a}--{node_b}: {names} not running at setup" + ) + if all(n in down_nodes for n in stopped): + # Stopped by churn: it has no namespace to join, and its own + # restart recreates this pair. + log.info("Veth %s--%s deferred: %s down", node_a, node_b, names) + else: + # Not raised: a container that exited on its own is a daemon + # failure, and aborting here would report it as the harness's. + # Nothing recreates this pair, so say so loudly. + log.warning( + "Veth %s--%s not recreated: %s not running, and churn did " + "not stop all of them; the link stays absent for the rest " + "of the run", + node_a, node_b, names, + ) return # Generate names @@ -146,68 +193,146 @@ class VethManager: final_a = veth_interface_name(node_a, node_b) final_b = veth_interface_name(node_b, node_a) + # Clear both final names and both temporary names out of the + # containers first. A stopped node's network namespace can outlive + # the stop by minutes, and while it does the survivor still holds its + # old `ve-X-Y`, whose peer sits in that namespace; the rename below + # then fails with "File exists". Deleting the survivor's end removes + # its peer too. A temporary name is left behind only by a restore + # that failed after the move, and it blocks the next move the same + # way. + _purge_links(container_a, [final_a, host_a]) + _purge_links(container_b, [final_b, host_b]) + # Clean up a stale pair left by this scenario. The token makes the # name unique to this run, so a pair orphaned by an earlier run is # no longer reclaimed here — `ci-cleanup.sh` reaps those instead. _run_host(["ip", "link", "delete", host_a], image, check=False) - # Create veth pair on host - ok = _run_host([ - "ip", "link", "add", host_a, "type", "veth", "peer", "name", host_b, - ], image) - if not ok: - log.warning("Failed to create veth pair %s/%s", host_a, host_b) - return - - # Move into container namespaces - _run_host(["ip", "link", "set", host_a, "netns", str(pid_a)], image) - _run_host(["ip", "link", "set", host_b, "netns", str(pid_b)], image) - - # Rename and bring up inside containers - docker_exec_quiet( - container_a, - f"ip link set {host_a} name {final_a} && ip link set {final_a} up", - timeout=10, - ) - docker_exec_quiet( - container_b, - f"ip link set {host_b} name {final_b} && ip link set {final_b} up", - timeout=10, + _require_host( + ["ip", "link", "add", host_a, "type", "veth", "peer", "name", host_b], + image, ) + _require_host(["ip", "link", "set", host_a, "netns", str(pid_a)], image) + _require_host(["ip", "link", "set", host_b, "netns", str(pid_b)], image) - # Query MAC addresses + _raise_link(container_a, host_a, final_a) + _raise_link(container_b, host_b, final_b) + _await_up(container_a, final_a) + _await_up(container_b, final_b) + + # Read only after both ends are proven renamed and up. Before, a + # failed rename left the old interface under the final name, and this + # read its MAC and reported the restore as a success. mac_a = _get_mac_in_container(container_a, final_a) mac_b = _get_mac_in_container(container_b, final_b) - - if mac_a: - self.topology.nodes[node_a].ethernet_macs[node_b] = mac_a - if mac_b: - self.topology.nodes[node_b].ethernet_macs[node_a] = mac_b + if not mac_a or not mac_b: + raise VethSetupError( + f"veth {node_a}--{node_b} is up but its MAC could not be read " + f"({final_a}: {mac_a or '?'}, {final_b}: {mac_b or '?'})" + ) + self.topology.nodes[node_a].ethernet_macs[node_b] = mac_a + self.topology.nodes[node_b].ethernet_macs[node_a] = mac_b self._host_pairs.append((node_a, node_b, host_a, host_b)) log.info( "Veth %s(%s) -- %s(%s) MAC: %s / %s", - node_a, final_a, node_b, final_b, - mac_a or "?", mac_b or "?", + node_a, final_a, node_b, final_b, mac_a, mac_b, ) -def _get_container_pid(container: str) -> int | None: - """Get the PID of a running Docker container.""" +def _in_container(container: str, cmd: str, what: str, timeout: int = EXEC_TIMEOUT_SECS) -> str: + """Run a command inside a container, raising `VethSetupError` on failure.""" + try: + return docker_exec(container, cmd, timeout=timeout) + except (DockerExecError, subprocess.TimeoutExpired) as e: + raise VethSetupError(f"{what} in {container} failed: {e}") from e + + +def _purge_links(container: str, names: list[str]): + """Delete each named interface in a container if it exists, in one exec. + + An absent name is the ordinary case and is skipped. A delete that fails + raises, since the rename that follows would then fail on the name too, + unless the name is gone by then: a lingering namespace can be reaped + between the check and the delete, taking the survivor's end with it. + """ + script = "; ".join( + f"if ip link show {name} >/dev/null 2>&1; then " + f"ip link delete {name} || ! ip link show {name} >/dev/null 2>&1 || exit 1; fi" + for name in names + ) + _in_container(container, script, f"deleting stale {', '.join(names)}") + + +def _require_host(cmd: list[str], image: str): + """Run a host-namespace ``ip`` command, raising `VethSetupError` on failure.""" + if not _run_host(cmd, image): + raise VethSetupError(f"host command failed: {' '.join(cmd)}") + + +def _raise_link(container: str, temp: str, final: str): + """Rename a moved veth end to its final name and set it up.""" + _in_container( + container, + f"ip link set {temp} name {final} && ip link set {final} up", + f"renaming {temp} to {final}", + ) + + +def _await_up(container: str, iface: str): + """Wait for an interface's operstate to read ``up``, else raise. + + A veth end reports up only once both ends are up, so this proves the + pair is joined as well as that this end was raised. + """ + deadline = time.monotonic() + OPERSTATE_WAIT_SECS + state = None + reads = 0 + while True: + state = docker_exec_quiet( + container, f"cat /sys/class/net/{iface}/operstate", timeout=EXEC_TIMEOUT_SECS + ) + state = state.strip() if state is not None else None + reads += 1 + if state == "up": + return + if reads >= 2 and time.monotonic() >= deadline: + raise VethSetupError( + f"{iface} in {container} reads operstate {state or '?'}, " + f"not up, {OPERSTATE_WAIT_SECS}s after it was raised" + ) + time.sleep(0.2) + + +def _container_pid(container: str) -> int | None: + """Return a container's PID, or None when docker reports it not running. + + Raises `VethSetupError` when docker cannot be asked. A timed-out or failed + inspect of a running container used to read as "not running", so under + host load a live link was skipped and never recreated. + """ try: result = subprocess.run( ["docker", "inspect", "-f", "{{.State.Pid}}", container], capture_output=True, text=True, - timeout=10, + timeout=EXEC_TIMEOUT_SECS, ) - if result.returncode == 0: - pid = int(result.stdout.strip()) - return pid if pid > 0 else None - except (subprocess.TimeoutExpired, ValueError): - pass - return None + except subprocess.TimeoutExpired as e: + raise VethSetupError(f"docker inspect {container} timed out") from e + if result.returncode != 0: + raise VethSetupError( + f"docker inspect {container} failed: {result.stderr.strip()}" + ) + try: + pid = int(result.stdout.strip()) + except ValueError as e: + raise VethSetupError( + f"docker inspect {container} returned no PID: {result.stdout.strip()!r}" + ) from e + return pid if pid > 0 else None def _get_mac_in_container(container: str, iface: str) -> str | None: @@ -215,7 +340,7 @@ def _get_mac_in_container(container: str, iface: str) -> str | None: result = docker_exec_quiet( container, f"cat /sys/class/net/{iface}/address", - timeout=5, + timeout=EXEC_TIMEOUT_SECS, ) if result is not None: return result.strip() diff --git a/testing/ci-cleanup.sh b/testing/ci-cleanup.sh index 010394d4..92dcf79d 100755 --- a/testing/ci-cleanup.sh +++ b/testing/ci-cleanup.sh @@ -204,13 +204,19 @@ VETH_NODE_ID='(0[0-9]|[1-9][0-9]+)' # from the simulation itself rather than repeated here, so widening it cannot # leave this matching the old width. Empty output means "reap nothing". # -# Two producers, two shapes. The chaos simulation makes vh{token}{NN}{MM}{a,b}; -# the NAT lab (nat/scripts/setup-topology.sh) makes vn{a,b}{token}{0,1}, using -# the RUN-wide suffix rather than any chaos scenario's. Widening this regex is +# Three producers, three shapes. The chaos simulation makes +# vh{token}{NN}{MM}{a,b}; the NAT lab (nat/scripts/setup-topology.sh) makes +# vn{a,b}{token}{0,1}; the interface-binding suite +# (iface-binding/test.sh) makes vhifb{token}{a,b,c,d}. The last two use the +# RUN-wide suffix rather than any chaos scenario's. Widening this regex is # only half the fix: the token set is derived separately below, so a suffix -# list carrying no NAT suffix leaves the NAT half matching nothing while +# list carrying no run-wide suffix leaves those halves matching nothing while # looking correct. ci-local.sh's ci_teardown therefore appends the run-wide # suffix to --veth-suffixes. +# +# vhifb is listed before the bare vh shape in each alternation only for +# readability; the shapes are anchored and cannot overlap, because a node id +# is digits and `ifb` is not. veth_pattern() { # vh{token}{NN}{MM}{a,b}: the token is 4 hex or wholly absent — never a # part of one — and the two node ids follow. Anchored and shaped this @@ -219,7 +225,7 @@ veth_pattern() { # single run, no missing or empty suffix list may widen this back out to # every run. if [[ -z "$RUN_ID" && -z "$VETH_SUFFIXES" ]]; then - printf '^vh([0-9a-f]{4})?%s%s[ab]$|^vn[ab]([0-9a-f]{4})?[01]$' \ + printf '^vhifb([0-9a-f]{4})?[a-d]$|^vh([0-9a-f]{4})?%s%s[ab]$|^vn[ab]([0-9a-f]{4})?[01]$' \ "$VETH_NODE_ID" "$VETH_NODE_ID" return 0 fi @@ -253,8 +259,8 @@ veth_pattern() { veth_warn "no interface tokens derived from: ${sfx[*]}" return 0 fi - printf '^vh(%s)%s%s[ab]$|^vn[ab](%s)[01]$' \ - "$alt" "$VETH_NODE_ID" "$VETH_NODE_ID" "$alt" + printf '^vhifb(%s)[a-d]$|^vh(%s)%s%s[ab]$|^vn[ab](%s)[01]$' \ + "$alt" "$alt" "$VETH_NODE_ID" "$VETH_NODE_ID" "$alt" } # ip(8) in a privileged --net=host container, matching how the simulation diff --git a/testing/ci-local.sh b/testing/ci-local.sh index 8c3759f1..14939572 100755 --- a/testing/ci-local.sh +++ b/testing/ci-local.sh @@ -661,6 +661,47 @@ run_static() { record "static-$topology" $rc } +# Lines kept from each node's log when a red scenario's results are printed. +CHAOS_DUMP_LINES=300 + +# Print a red chaos scenario's results into the run log. +# +# A CI worker that runs each job in a worktree it deletes afterwards, under a +# private /tmp, loses the results directory when the run ends, and the log is +# the only record that survives. Without this such a red cannot be traced node +# by node. The runner's own log is not repeated here: it already reached the run +# log as the scenario's output. Each node log is capped, so the total grows with +# node count; the largest CI scenario has ten nodes. +chaos_dump() { + local name="$1" base="$2" dir f + dir="$(find "$base" -mindepth 1 -maxdepth 1 -type d 2>/dev/null | sort | tail -n 1)" + if [[ -z "$dir" ]]; then + echo "[chaos/$name] no results directory under $base" + return 0 + fi + echo "===== chaos-$name results from $dir =====" + for f in status.txt assertions.txt; do + [[ -f "$dir/$f" ]] || continue + echo "----- $f -----" + cat "$dir/$f" + done + if [[ -f "$dir/tree-snapshot-final.json" ]]; then + echo "----- final tree: node, root, parent -----" + python3 -c ' +import json, sys +for node, tree in sorted(json.load(open(sys.argv[1])).items()): + print(node, tree.get("root"), tree.get("parent")) +' "$dir/tree-snapshot-final.json" || true + fi + for f in "$dir"/fips-node-*.log; do + [[ -f "$f" ]] || continue + echo "----- $(basename "$f"), last $CHAOS_DUMP_LINES lines -----" + tail -n "$CHAOS_DUMP_LINES" "$f" + done + echo "===== end of chaos-$name results =====" + return 0 +} + # Run a chaos scenario run_chaos() { local name="$1" @@ -678,11 +719,17 @@ run_chaos() { suffix="$(ci_chaos_suffix "$name")" local -x FIPS_CI_NAME_SUFFIX="$suffix" + # The same scoping for the results, so a red can find the directory this + # run wrote rather than guess among earlier runs' timestamps. + local results="$SCRIPT_DIR/chaos/sim-results/ci$suffix" + local -x FIPS_SIM_OUTPUT="$results" + info "[chaos/$name] Running simulation" if bash testing/chaos/scripts/chaos.sh "$@" 2>&1; then rc=0 else rc=1 + chaos_dump "$name" "$results" fi record "chaos-$name" $rc @@ -1345,9 +1392,12 @@ run_integration() { record "chaos-$scenario" 0 else record "chaos-$scenario" 1 - # Show tail of failure log - echo "--- chaos-$scenario output (last 20 lines) ---" - tail -20 "$logfile" 2>/dev/null || true + # The whole log, not its tail: the child printed the results + # directory into it, and this is the only place that reaches + # the run log. The sed keeps the last frame of each line the + # progress display redraws with carriage returns. + echo "--- chaos-$scenario output ---" + sed 's/.*\r//' "$logfile" 2>/dev/null || true echo "---" fi rm -f "$logfile" diff --git a/testing/iface-binding/test.sh b/testing/iface-binding/test.sh index eccf4cce..aca65341 100755 --- a/testing/iface-binding/test.sh +++ b/testing/iface-binding/test.sh @@ -46,10 +46,30 @@ BOOT_IFACE="ve-boot0" # Host-side veth names, scoped per run: these live in the host (or Docker VM) # namespace for the moment between creation and the move into the containers, # where two concurrent runs would otherwise collide on one name. -HOST_VETH_A="vhifb${FIPS_CI_NAME_SUFFIX:-0}a" -HOST_VETH_B="vhifb${FIPS_CI_NAME_SUFFIX:-0}b" -HOST_VETH_C="vhifb${FIPS_CI_NAME_SUFFIX:-0}c" -HOST_VETH_D="vhifb${FIPS_CI_NAME_SUFFIX:-0}d" +# +# The scope comes from a four-hex hash of the run suffix, not from the suffix +# itself. An interface name gets 15 characters and the suffix alone can spend +# 24 of them (`-20260910t025205-2802512`), so interpolating it produced +# `vhifb-20260910t025205-2802512b` and ip(8) refused the name outright. The +# chaos simulation had already met this and answers it in `sim.naming`, which +# the NAT topology script also calls; this uses the same token so the reaper +# in `ci-cleanup.sh` can match these interfaces by the same rule. +# +# Empty for an empty suffix, so a bare run keeps short unscoped names. +veth_token() { + local suffix="${FIPS_CI_NAME_SUFFIX:-}" + if [ -z "$suffix" ]; then + echo "" + return 0 + fi + PYTHONPATH="$TESTING_DIR/chaos" python3 -m sim.naming "$suffix" +} + +VETH_TOKEN="$(veth_token)" +HOST_VETH_A="vhifb${VETH_TOKEN}a" +HOST_VETH_B="vhifb${VETH_TOKEN}b" +HOST_VETH_C="vhifb${VETH_TOKEN}c" +HOST_VETH_D="vhifb${VETH_TOKEN}d" SKIP_BUILD=false KEEP_UP=false