laantungir/fips
1
0
Fork 0
mirror of https://github.com/jmcorgan/fips.git synced 2026-07-30 11:36:15 +00:00
Code Issues Packages Projects Releases Wiki Activity

Harvest chaos results only from a mesh that actually started

Browse Source 
Teardown runs from a finally, so it also runs after a failed setup, and it was guarded only on the topology and the compose file, both of which are set well before any container exists. A scenario that died bringing its containers up therefore ran the whole harvest anyway: final snapshots, docker logs, the analysis, the assertions and the metadata, all addressing containers by names that are global to the host. What it left behind was not an empty directory an investigator would notice but a full and plausible one, in the recorded case ten node logs and an analysis reporting two promotions and two parent switches, every byte of it from a different scenario's mesh. Gate the harvest on whether the containers ever started, and leave the compose down outside that gate so a partly successful start still gets cleaned up.

Record the outcome in a status file in every result directory, naming the run as completed, interrupted, aborted, setup-failed or teardown-failed, alongside the scenario, the seed and the container names it used. With the harvest gated, the presence of an analysis file is now itself proof that the scenario's own mesh existed, and the status file says which of the several ways a run can end applies. A run cut short by a signal keeps the existing exit codes rather than gaining one of its own: what it collected before stopping is real and still worth reporting, the status file records that it was truncated, and every wrapper already reports a Ctrl-C of its own.

Log collection never looked at the status of docker logs. It concatenated stdout and stderr unconditionally, so collecting from containers that were not there wrote the daemon's "No such container" reply into each node log and analysed the result as a mesh with no panics, no errors and no sessions, which reads exactly like a clean run and exits zero. Check the return code, and treat a harvest that cannot read every container, or that reads none, as a failed teardown. A teardown that raises now also reports on the same footing as a run that never started, instead of escaping past the exit codes as a bare traceback and being read as a malformed command line.
This commit is contained in:
Johnathan Corgan
2026-07-22 08:02:38 +00:00
parent 4f55a281ac
commit 226c6994d3
3 changed files with 137 additions and 19 deletions
Download Patch File Download Diff File Expand all files Collapse all files
testing/chaos/README.md
+29 -4
View File
@@ -257,27 +257,52 @@ since they use beacon discovery.
Results written to `sim-results/` (configurable via
`logging.output_dir`):
- `status.txt` -- How the run ended, plus the scenario, the seed and the
container names it used; one `key=value` per line
- `analysis.txt` -- Summary: panics, errors, sessions, metrics
- `metadata.txt` -- Seed, node count, edges, adjacency list
- `runner.log` -- Orchestration events (topology, netem, churn, traffic) with timestamps
- `fips-node-nXX.log` -- Per-node log output
The `status` field reads:
- `completed` -- ran for its configured duration
- `interrupted` -- a signal cut the run short, so the artifacts are real
but describe less time than the scenario asked for
- `aborted` -- the run raised part way through; same caveat, and
`runner.log` carries the traceback
- `setup-failed` -- the containers never started
- `teardown-failed` -- the mesh ran but its logs or analysis could not be
produced
A `setup-failed` directory holds `runner.log` and `status.txt` and nothing
else. Nothing is harvested, because container names are global to the host
and reading them after a failed setup describes whichever run holds them
now. So `analysis.txt` in a result directory is proof that this scenario's
own mesh existed. A directory with no `status.txt` was written before this
was the case and says nothing either way.
Exit codes:
- `0` -- Ran to completion, no panics, every assertion passed
- `1` -- The scenario file could not be loaded, teardown itself raised, or a
second interrupt arrived while the first was being handled
- `1` -- The scenario file could not be loaded, or a second interrupt
arrived while the first was being handled
- `2` -- Panics found in the collected node logs. Also what the argument
parser exits with when it rejects the command line, before any run starts
- `3` -- A post-run assertion failed
- `4` -- Setup, warmup or the simulation loop raised, so the run did not
complete; `runner.log` carries the traceback
- `4` -- Setup, warmup, the simulation loop or teardown raised, so the run
did not complete; `runner.log` carries the traceback
Codes 2 and 3 describe what a mesh that ran did. Code 4 says there is
nothing to describe, and takes precedence over both. Code 2 is dual-use:
a run that never started cannot have panicked, so read it together with
whether `runner.log` exists.
A run stopped by a signal exits on this same ladder rather than one of its
own: what it collected before stopping is still worth reporting, and
`status.txt` says it was cut short. `chaos.sh` reports 130 for a Ctrl-C of
its own accord.
## Creating Custom Scenarios
1. Copy an existing scenario from `scenarios/`.
testing/chaos/sim/logs.py
+38 -11
View File
@@ -29,9 +29,18 @@ __all__ = ["AnalysisResult", "analyze_logs", "collect_logs", "write_sim_metadata
def collect_logs(container_names: list[str], output_dir: str) -> dict[str, str]:
"""Collect all output (stdout + stderr) from all containers."""
"""Collect all output (stdout + stderr) from all containers.
Raises RuntimeError if any container's output could not be read, or if
there was nothing to read. `docker logs` writes its own failures to
stderr and exits non-zero, so without the returncode check the daemon's
"No such container" reply was stored as though it were the node's log
and analysed as a mesh with no panics, no errors and no sessions --
which reads exactly like a clean run.
"""
os.makedirs(output_dir, exist_ok=True)
logs = {}
failed = []
for name in container_names:
try:
@@ -41,17 +50,35 @@ def collect_logs(container_names: list[str], output_dir: str) -> dict[str, str]:
text=True,
timeout=30,
)
raw = result.stdout + result.stderr
log_text = strip_ansi(raw)
logs[name] = log_text
path = os.path.join(output_dir, f"{name}.log")
with open(path, "w") as f:
f.write(log_text)
except (subprocess.TimeoutExpired, Exception) as e:
except Exception as e:
log.warning("Failed to collect logs from %s: %s", name, e)
logs[name] = ""
failed.append(name)
continue
if result.returncode != 0:
log.warning(
"docker logs %s exited %d: %s",
name, result.returncode, result.stderr.strip(),
)
failed.append(name)
continue
# A container's own stderr comes back on our stderr, so both
# streams are log content on the success path.
log_text = strip_ansi(result.stdout + result.stderr)
logs[name] = log_text
path = os.path.join(output_dir, f"{name}.log")
with open(path, "w") as f:
f.write(log_text)
if failed:
raise RuntimeError(
f"could not collect logs from {len(failed)}/{len(container_names)} "
f"containers: {', '.join(failed)}"
)
if not logs:
raise RuntimeError("no container logs were collected")
return logs
testing/chaos/sim/runner.py
+70 -4
View File
@@ -20,6 +20,7 @@ from .docker_exec import docker_compose
from .link_swap import LinkSwapManager
from .links import LinkManager
from .logs import AnalysisResult, analyze_logs, collect_logs, write_sim_metadata
from .naming import name_suffix
from .netem import NetemManager
from .nodes import NodeManager
from .peer_churn import PeerChurnManager
@@ -45,6 +46,13 @@ class SimRunner:
# of run() carries the fact that the simulation did not complete.
self.aborted = False
# Whether this run ever owned containers. Teardown runs from a
# finally, so it runs after a failed setup too, and container names
# are global: without this it would harvest whatever currently
# answers to them. topology and compose_file are both set well
# before the containers start and so cannot stand in for it.
self._containers_started = False
# Shared set of currently-down node IDs (updated by NodeManager,
# read by NetemManager, LinkManager, TrafficManager)
self._down_nodes: set[str] = set()
@@ -190,6 +198,7 @@ class SimRunner:
# 5. Start containers
log.info("Starting %d containers...", len(self.topology.nodes))
docker_compose(self.compose_file, ["up", "-d"])
self._containers_started = True
# 6. Set up veth pairs for Ethernet edges (before netem)
#
@@ -427,11 +436,57 @@ class SimRunner:
def assertions_failed(self) -> bool:
return any(not o.passed for o in self.assertion_outcomes)
def _run_status(self) -> str:
"""Name for how the run itself ended, before teardown is considered."""
if self.aborted:
return "aborted"
if self._interrupted:
return "interrupted"
return "completed"
def _write_status(self, status: str) -> None:
"""Record how the run ended, for a reader who has only this directory.
One field per line so it can be grepped. The container names are
included because they are the handle on everything else the run
touched, and because a directory that names them cannot be mistaken
for a directory assembled from some other scenario's mesh.
Never raises. Both callers run this immediately before stopping the
containers, so letting a full disk or a vanished output directory
out of here would leak the mesh it was about to tear down.
"""
try:
os.makedirs(self.output_dir, exist_ok=True)
path = os.path.join(self.output_dir, "status.txt")
with open(path, "w") as f:
f.write(f"status={status}\n")
f.write(f"scenario={self.scenario.name}\n")
f.write(f"seed={self.scenario.seed}\n")
f.write(f"containers=fips-node-nNN{name_suffix()}\n")
except Exception:
log.exception("Could not write status file")
def _teardown(self) -> AnalysisResult | None:
"""Stop dynamic elements, collect logs, analyze, stop containers."""
result = None
if not self._containers_started:
# There is no mesh to harvest. Snapshots, logs, analysis and
# assertions all address containers by a name that is global to
# the host, so running them here would describe whoever holds
# those names now and leave a plausible report of a run that
# never happened. Leaving them out makes the presence of
# analysis.txt proof that this scenario's own mesh existed.
self._write_status("setup-failed")
if self.compose_file:
# `up -d` can fail part way through, so this run may own
# containers or a network even with no mesh to speak of.
log.info("Stopping containers...")
docker_compose(self.compose_file, ["down"], check=False)
return None
if self.topology and self.compose_file:
result = None
status = self._run_status()
try:
# Evaluate post-run assertions before doing any teardown so
# control sockets are still reachable.
self._evaluate_assertions()
@@ -516,8 +571,19 @@ class SimRunner:
if self.veth_mgr:
log.info("Cleaning up veth pairs...")
self.veth_mgr.teardown_all()
# Stop containers
except Exception:
# Same reasoning as run(): logging keeps the traceback in
# runner.log, where re-raising would send it to stderr instead
# and past the exit ladder, which would report a harvest that
# fell over as a bad command line.
log.exception("Teardown failed")
self.aborted = True
status = "teardown-failed"
result = None
finally:
# Status first: it is the one artifact that must exist whatever
# else happens, and stopping containers can still time out.
self._write_status(status)
log.info("Stopping containers...")
docker_compose(
self.compose_file,