| 1 | """Environment-fault family: disk full, read-only directories, fsync load.
|
| 2 |
|
| 3 | - disk_full the trial (client + server data) lives on a small RAM disk
|
| 4 | (macOS: ``hdiutil attach -nomount ram://`` + ``newfs_hfs`` mounted
|
| 5 | inside the work dir; no sudo) filled to leave ``free_kib`` free.
|
| 6 | The operation must fail with an actionable error or succeed with
|
| 7 | the exact outcome; the store must open; pre-op commits survive;
|
| 8 | after the filler is removed the next operation must converge.
|
| 9 | - readonly the store directory (``.oak`` / ``.git``) or one worktree subdir is
|
| 10 | made read-only for the operation, then restored.
|
| 11 | - fsync_load (see runner) the same_branch concurrency scenario under a
|
| 12 | background fsync storm (4 writers x 256 KiB + F_FULLFSYNC).
|
| 13 | """
|
| 14 |
|
| 15 | from __future__ import annotations
|
| 16 |
|
| 17 | import errno
|
| 18 | import os
|
| 19 | import platform
|
| 20 | import re
|
| 21 | import shutil
|
| 22 | import stat
|
| 23 | import subprocess
|
| 24 | import time
|
| 25 | from pathlib import Path
|
| 26 | from typing import Optional
|
| 27 |
|
| 28 | from . import FAULT_NOT_FIRED, HARNESS_ERROR
|
| 29 | from .crash import evaluate
|
| 30 | from .engine import Calibration, Trial, actionable, classify, converge_check
|
| 31 |
|
| 32 | FREE_KIB = (0, 256, 4096)
|
| 33 | # An environment fault is actionable when the error names the OS cause the user must fix.
|
| 34 | CAUSE_RE = re.compile(r"no space left|os error 28|ENOSPC|permission denied|os error 13|read-?only|disk I/O error|"
|
| 35 | r"disk (is )?full|out of disk ?space|quota", re.I)
|
| 36 |
|
| 37 |
|
| 38 | def env_actionable(res) -> bool:
|
| 39 | return actionable(res) or (res.returncode not in (None, 0) and res.returncode > 0
|
| 40 | and "panicked at" not in res.text() and bool(CAUSE_RE.search(res.text())))
|
| 41 |
|
| 42 |
|
| 43 | class RamDisk:
|
| 44 | def __init__(self, mountpoint: Path, mib: int = 96):
|
| 45 | self.mountpoint = mountpoint
|
| 46 | self.mib = mib
|
| 47 | self.device: Optional[str] = None
|
| 48 |
|
| 49 | def __enter__(self) -> "RamDisk":
|
| 50 | if platform.system() != "Darwin":
|
| 51 | raise NotImplementedError("disk-full fixture implemented with macOS hdiutil RAM disks (Linux: small tmpfs pending)")
|
| 52 | sectors = self.mib * 2048
|
| 53 | out = subprocess.run(["hdiutil", "attach", "-nomount", f"ram://{sectors}"], capture_output=True, text=True,
|
| 54 | timeout=60)
|
| 55 | if out.returncode != 0:
|
| 56 | raise NotImplementedError("hdiutil ram disk unavailable: " + out.stderr[-200:])
|
| 57 | self.device = out.stdout.split()[0]
|
| 58 | subprocess.run(["newfs_hfs", "-v", "p4full", self.device], capture_output=True, check=True, timeout=60)
|
| 59 | self.mountpoint.mkdir(parents=True, exist_ok=True)
|
| 60 | subprocess.run(["diskutil", "mount", "-mountPoint", str(self.mountpoint), self.device], capture_output=True,
|
| 61 | check=True, timeout=60)
|
| 62 | return self
|
| 63 |
|
| 64 | def __exit__(self, *exc) -> None:
|
| 65 | if self.device:
|
| 66 | subprocess.run(["diskutil", "unmount", "force", str(self.mountpoint)], capture_output=True, timeout=60)
|
| 67 | subprocess.run(["hdiutil", "detach", self.device, "-force"], capture_output=True, timeout=60)
|
| 68 | self.device = None
|
| 69 |
|
| 70 |
|
| 71 | FILL_CHUNKS = (1 << 20, 64 << 10, 4 << 10, 512, 1)
|
| 72 |
|
| 73 |
|
| 74 | def free_bytes(directory: Path) -> int:
|
| 75 | """Bytes an unprivileged writer can still allocate on directory's filesystem."""
|
| 76 | st = os.statvfs(directory)
|
| 77 | return st.f_bavail * st.f_frsize
|
| 78 |
|
| 79 |
|
| 80 | def fill(directory: Path, leave_kib: int) -> tuple[Path, int]:
|
| 81 | """Fill the filesystem until writes fail at 1-byte granularity, then free ``leave_kib``.
|
| 82 |
|
| 83 | Writes shrink from 1 MiB to 64 KiB, 4 KiB, 512 B and 1 B, each until ENOSPC,
|
| 84 | with an fsync between rounds so delayed allocation cannot hide free space.
|
| 85 | Returns (filler, measured free bytes after the optional release).
|
| 86 | """
|
| 87 | filler = directory / "p4-filler.bin"
|
| 88 | fd = os.open(filler, os.O_WRONLY | os.O_CREAT | os.O_TRUNC, 0o644)
|
| 89 | try:
|
| 90 | for _round in range(3):
|
| 91 | for size in FILL_CHUNKS:
|
| 92 | buf = b"\0" * size
|
| 93 | while True:
|
| 94 | try:
|
| 95 | written = os.write(fd, buf)
|
| 96 | except OSError as exc:
|
| 97 | if exc.errno in (errno.ENOSPC, errno.EDQUOT):
|
| 98 | break
|
| 99 | raise
|
| 100 | if written < size:
|
| 101 | break
|
| 102 | try:
|
| 103 | os.fsync(fd)
|
| 104 | except OSError:
|
| 105 | pass
|
| 106 | if free_bytes(directory) == 0:
|
| 107 | break
|
| 108 | if leave_kib:
|
| 109 | size = os.fstat(fd).st_size
|
| 110 | os.ftruncate(fd, max(0, size - leave_kib * 1024))
|
| 111 | os.fsync(fd)
|
| 112 | finally:
|
| 113 | os.close(fd)
|
| 114 | return filler, free_bytes(directory)
|
| 115 |
|
| 116 |
|
| 117 | def allocated_bytes(root: Path) -> int:
|
| 118 | total = 0
|
| 119 | for path in [root, *root.rglob("*")]:
|
| 120 | try:
|
| 121 | total += path.lstat().st_blocks * 512
|
| 122 | except OSError:
|
| 123 | pass
|
| 124 | return total
|
| 125 |
|
| 126 |
|
| 127 | def op_need_bytes(fixture, subject_bin: str, work: Path) -> int:
|
| 128 | """Net bytes the clean op allocates (client + server data) on an ordinary disk."""
|
| 129 | trial = Trial(fixture, subject_bin, work, "need")
|
| 130 | try:
|
| 131 | trial.start_server()
|
| 132 | trial.pre()
|
| 133 | before = allocated_bytes(trial.dir)
|
| 134 | res = trial.adapter.run(trial.op_argv(), trial.op_cwd())
|
| 135 | trial.settle()
|
| 136 | if res.returncode != 0:
|
| 137 | return 0
|
| 138 | return max(0, allocated_bytes(trial.dir) - before)
|
| 139 | finally:
|
| 140 | trial.cleanup()
|
| 141 |
|
| 142 |
|
| 143 | ENOSPC_RE = re.compile(r"no space left|os error 28|ENOSPC|disk (is )?full|database or disk is full|SQLITE_FULL",
|
| 144 | re.I)
|
| 145 | # Evidence that a write under a read-only path was refused.
|
| 146 | EACCES_RE = re.compile(r"permission denied|os error 13|os error 30|EACCES|EROFS|EPERM|read-?only (?:file ?system|"
|
| 147 | r"database)|attempt to write a readonly database|SQLITE_READONLY|Operation not permitted", re.I)
|
| 148 |
|
| 149 |
|
| 150 | def disk_full_fired(free: int, need_bytes: int, op_res) -> tuple[bool, str]:
|
| 151 | """Did the disk-full fault take effect for this op? (fired, evidence).
|
| 152 |
|
| 153 | Requires evidence, never a bare non-zero exit: the op reported ENOSPC /
|
| 154 | "No space left" / SQLITE_FULL, or the measured free space before the op was
|
| 155 | below what a clean run of the op allocates."""
|
| 156 | if op_res is not None and ENOSPC_RE.search(op_res.text()):
|
| 157 | return True, "op reported ENOSPC"
|
| 158 | if free < need_bytes:
|
| 159 | return True, f"measured free {free} B < op need {need_bytes} B"
|
| 160 | return False, f"measured free {free} B >= op need {need_bytes} B and no ENOSPC reported"
|
| 161 |
|
| 162 |
|
| 163 | def _judge_env(trial: Trial, calib: Calibration, op_res, restore) -> tuple[dict, dict]:
|
| 164 | """Common judgement: op either converged or failed actionably; then restore and re-run."""
|
| 165 | inv: dict = {"op_no_hang": not op_res.timed_out}
|
| 166 | obs: dict = {"op": op_res.brief(300)}
|
| 167 | if op_res.returncode == 0:
|
| 168 | ok, detail = converge_check(trial, calib, trial.target_repo())
|
| 169 | inv["op_success_is_true"] = ok
|
| 170 | obs["op_converge"] = detail
|
| 171 | else:
|
| 172 | inv["op_failure_actionable"] = env_actionable(op_res)
|
| 173 | restore()
|
| 174 | more_inv, more_obs = evaluate(trial, calib, op_res, True)
|
| 175 | more_inv.pop("op_no_hang", None)
|
| 176 | inv.update(more_inv)
|
| 177 | obs.update({k: v for k, v in more_obs.items() if k != "op"})
|
| 178 | return inv, obs
|
| 179 |
|
| 180 |
|
| 181 | def disk_full_trial(fixture, subject_bin: str, work: Path, name: str, calib: Calibration, leave_kib: int,
|
| 182 | need_bytes: int = 0) -> dict:
|
| 183 | """Run the op with the trial's filesystem filled to ``leave_kib`` free (measured).
|
| 184 |
|
| 185 | The fault fired only if the measured free space was below the op's need
|
| 186 | (net allocation of a clean run), or the op failed / reported ENOSPC.
|
| 187 | Otherwise the row is ``fault_not_fired``: the disk was not actually full
|
| 188 | for this op, so a success proves nothing.
|
| 189 | """
|
| 190 | started = time.perf_counter()
|
| 191 | mount = work / f"{name}-mnt"
|
| 192 | op_res = None
|
| 193 | fired = None
|
| 194 | try:
|
| 195 | with RamDisk(mount):
|
| 196 | trial = Trial(fixture, subject_bin, mount, "t")
|
| 197 | try:
|
| 198 | trial.start_server()
|
| 199 | trial.pre()
|
| 200 | trial.adapter.env() # create the subject HOME before the disk is full (harness setup)
|
| 201 | filler, free = fill(mount, leave_kib)
|
| 202 | op_res = trial.adapter.run(trial.op_argv(), trial.op_cwd())
|
| 203 | enospc = bool(ENOSPC_RE.search(op_res.text()))
|
| 204 | fired, fired_evidence = disk_full_fired(free, need_bytes, op_res)
|
| 205 | inv, obs = _judge_env(trial, calib, op_res, lambda: filler.unlink(missing_ok=True))
|
| 206 | obs.update(free_bytes_measured_before_op=free, op_need_bytes=need_bytes, enospc_reported=enospc,
|
| 207 | fault_fired_evidence=fired_evidence,
|
| 208 | fill_granularity_bytes=FILL_CHUNKS[-1], requested_free_kib=leave_kib)
|
| 209 | classification = classify(inv, fault_fired=fired, reader_errors=obs.get("reader_errors"))
|
| 210 | error = None
|
| 211 | finally:
|
| 212 | trial.stop_server()
|
| 213 | except NotImplementedError as exc:
|
| 214 | return {"unsupported": str(exc)}
|
| 215 | except Exception as exc: # noqa: BLE001
|
| 216 | inv, obs, classification, error = {}, {}, HARNESS_ERROR, f"{type(exc).__name__}: {exc}"
|
| 217 | finally:
|
| 218 | shutil.rmtree(mount, ignore_errors=True)
|
| 219 | row = _row(f"free={leave_kib}KiB", inv, obs, classification, error, op_res, started)
|
| 220 | row["fault_fired"] = fired
|
| 221 | if "free_bytes_measured_before_op" in obs:
|
| 222 | row["free_bytes_measured"] = obs["free_bytes_measured_before_op"]
|
| 223 | if classification == FAULT_NOT_FIRED:
|
| 224 | row["skip_reason"] = (f"disk not full for this op: {obs.get('free_bytes_measured_before_op')} B free >= "
|
| 225 | f"{need_bytes} B needed and no ENOSPC reported")
|
| 226 | if op_res is not None and op_res.returncode not in (0, None):
|
| 227 | # The op failed although the disk demonstrably had room: the failure is
|
| 228 | # not attributable to the fault. Keep it visible instead of calling it held.
|
| 229 | row["unattributed_failure"] = True
|
| 230 | row["skip_reason"] += f"; UNATTRIBUTED FAILURE rc={op_res.returncode} (see observations.op)"
|
| 231 | return row
|
| 232 |
|
| 233 |
|
| 234 | def readonly_base(repo: Path, kind: str, target: str) -> Path:
|
| 235 | return repo / (".oak" if kind == "oak" else ".git") if target == "store" else repo / "d3"
|
| 236 |
|
| 237 |
|
| 238 | def write_snapshot(base: Path, target: str) -> Optional[dict]:
|
| 239 | """What a write under ``base`` would change, as lock_down restricts it.
|
| 240 |
|
| 241 | store: every path below is read-only -> {relpath: (inode, size, mtime_ns)} of
|
| 242 | the whole tree. subdir: only the directory itself is read-only -> its entry
|
| 243 | set {name: inode} plus the directory's own mtime (entry create/rename/delete)."""
|
| 244 | if not base.exists():
|
| 245 | return None
|
| 246 | if target == "store":
|
| 247 | out = {}
|
| 248 | for path in [base, *base.rglob("*")]:
|
| 249 | try:
|
| 250 | st = path.lstat()
|
| 251 | except OSError:
|
| 252 | continue
|
| 253 | is_dir = stat.S_ISDIR(st.st_mode)
|
| 254 | out[str(path.relative_to(base))] = (st.st_ino, 0 if is_dir else st.st_size,
|
| 255 | 0 if is_dir else st.st_mtime_ns)
|
| 256 | return out
|
| 257 | out = {"<dir-mtime>": base.stat().st_mtime_ns}
|
| 258 | for child in base.iterdir():
|
| 259 | out[child.name] = child.lstat().st_ino
|
| 260 | return out
|
| 261 |
|
| 262 |
|
| 263 | def readonly_exercised(fixture, subject_bin: str, work: Path, name: str, target: str) -> tuple[Optional[bool], dict]:
|
| 264 | """Does a clean run of the op write under the path readonly_trial locks down?"""
|
| 265 | trial = Trial(fixture, subject_bin, work, name)
|
| 266 | try:
|
| 267 | trial.start_server()
|
| 268 | trial.pre()
|
| 269 | base = readonly_base(trial.client, trial.kind, target)
|
| 270 | before = write_snapshot(base, target)
|
| 271 | res = trial.adapter.run(trial.op_argv(), trial.op_cwd())
|
| 272 | trial.settle()
|
| 273 | after = write_snapshot(base, target)
|
| 274 | if res.returncode != 0 or before is None:
|
| 275 | return None, {"clean_rc": res.returncode, "detail": "clean run failed or path missing"}
|
| 276 | changed = sorted(k for k in set(before) | set(after or {}) if before.get(k) != (after or {}).get(k))
|
| 277 | return bool(changed), {"clean_run_changed": len(changed), "sample": changed[:5]}
|
| 278 | finally:
|
| 279 | trial.stop_server()
|
| 280 | trial.cleanup()
|
| 281 |
|
| 282 |
|
| 283 | def readonly_fired(writable_after_lockdown: bool, exercised: Optional[bool], op_res) -> tuple[Optional[bool], str]:
|
| 284 | """Did the read-only fault take effect? (fired, evidence).
|
| 285 |
|
| 286 | Fired only if the path really was unwritable (not the case as root) and the
|
| 287 | op attempted a write there: it reported a permission/read-only error, or a
|
| 288 | clean run of the same op writes under that path. Otherwise 'not exercised'."""
|
| 289 | if writable_after_lockdown:
|
| 290 | return False, "not exercised: path still writable after chmod (running as root?)"
|
| 291 | if op_res is not None and EACCES_RE.search(op_res.text()):
|
| 292 | return True, "op reported a permission/read-only error"
|
| 293 | if exercised:
|
| 294 | return True, "a clean run of the op writes under the read-only path"
|
| 295 | if exercised is None:
|
| 296 | return None, "exercise probe failed; fired unknown"
|
| 297 | return False, "not exercised: a clean run of the op writes nothing under the read-only path"
|
| 298 |
|
| 299 |
|
| 300 | def readonly_trial(fixture, subject_bin: str, work: Path, name: str, calib: Calibration, target: str,
|
| 301 | exercised: Optional[bool] = None, exercise_detail: Optional[dict] = None) -> dict:
|
| 302 | """target: 'store' (.oak/.git) or 'subdir' (worktree d3/).
|
| 303 |
|
| 304 | exercised: whether a clean run of the op writes under the locked path
|
| 305 | (readonly_exercised); decides fault_fired together with the op's output."""
|
| 306 | started = time.perf_counter()
|
| 307 | trial = Trial(fixture, subject_bin, work, name)
|
| 308 | op_res = None
|
| 309 | changed: list[tuple[Path, int]] = []
|
| 310 | fired, fired_evidence = None, "not run"
|
| 311 |
|
| 312 | def lock_down() -> None:
|
| 313 | repo = trial.client
|
| 314 | base = readonly_base(repo, trial.kind, target)
|
| 315 | for path in [base, *base.rglob("*")] if target == "store" else [base]:
|
| 316 | mode = path.stat().st_mode
|
| 317 | changed.append((path, mode))
|
| 318 | os.chmod(path, mode & ~(stat.S_IWUSR | stat.S_IWGRP | stat.S_IWOTH))
|
| 319 |
|
| 320 | def restore() -> None:
|
| 321 | for path, mode in reversed(changed):
|
| 322 | try:
|
| 323 | os.chmod(path, mode)
|
| 324 | except OSError:
|
| 325 | pass
|
| 326 | changed.clear()
|
| 327 |
|
| 328 | try:
|
| 329 | trial.start_server()
|
| 330 | trial.pre()
|
| 331 | lock_down()
|
| 332 | writable = os.access(readonly_base(trial.client, trial.kind, target), os.W_OK)
|
| 333 | op_res = trial.adapter.run(trial.op_argv(), trial.op_cwd())
|
| 334 | fired, fired_evidence = readonly_fired(writable, exercised, op_res)
|
| 335 | inv, obs = _judge_env(trial, calib, op_res, restore)
|
| 336 | obs.update(fault_fired_evidence=fired_evidence, readonly_exercise=exercise_detail)
|
| 337 | classification, error = classify(inv, fault_fired=fired, reader_errors=obs.get("reader_errors")), None
|
| 338 | except Exception as exc: # noqa: BLE001
|
| 339 | restore()
|
| 340 | inv, obs, classification, error = {}, {}, HARNESS_ERROR, f"{type(exc).__name__}: {exc}"
|
| 341 | finally:
|
| 342 | restore()
|
| 343 | trial.cleanup()
|
| 344 | row = _row(f"readonly={target}", inv, obs, classification, error, op_res, started)
|
| 345 | row["fault_fired"] = fired
|
| 346 | if classification == FAULT_NOT_FIRED:
|
| 347 | row["skip_reason"] = fired_evidence
|
| 348 | return row
|
| 349 |
|
| 350 |
|
| 351 | def _row(point, inv, obs, classification, error, op_res, started) -> dict:
|
| 352 | row = {"fault_point": point, "invariants": inv, "violations": sorted(k for k, v in inv.items() if v is False),
|
| 353 | "observations": obs, "classification": classification,
|
| 354 | "elapsed_ms": round(op_res.elapsed_ms if op_res else (time.perf_counter() - started) * 1000.0, 3),
|
| 355 | "command": op_res.argv if op_res else []}
|
| 356 | if error:
|
| 357 | row["harness_error"] = error
|
| 358 | elif classification == HARNESS_ERROR and obs.get("reader_errors"):
|
| 359 | row["harness_error"] = "independent reader failed: " + "; ".join(obs["reader_errors"][:2])
|
| 360 | return row
|
| 361 |
|
| 362 |
|
| 363 | class FsyncLoad:
|
| 364 | """Background fsync storm (idea from the L8 fsyncload.py harness)."""
|
| 365 |
|
| 366 | SCRIPT = r"""
|
| 367 | import os, sys, fcntl, time
|
| 368 | d, stop = sys.argv[1], sys.argv[2]
|
| 369 | buf = os.urandom(256 * 1024)
|
| 370 | p = os.path.join(d, f"load-{os.getpid()}")
|
| 371 | while not os.path.exists(stop):
|
| 372 | with open(p, "wb") as f:
|
| 373 | f.write(buf); f.flush()
|
| 374 | try: fcntl.fcntl(f.fileno(), 51)
|
| 375 | except OSError: os.fsync(f.fileno())
|
| 376 | os.unlink(p)
|
| 377 | """
|
| 378 |
|
| 379 | def __init__(self, directory: Path, workers: int = 4):
|
| 380 | self.dir = directory
|
| 381 | self.workers = workers
|
| 382 | self.procs: list[subprocess.Popen] = []
|
| 383 |
|
| 384 | def __enter__(self) -> "FsyncLoad":
|
| 385 | self.dir.mkdir(parents=True, exist_ok=True)
|
| 386 | self.stop_file = self.dir / "stop"
|
| 387 | self.stop_file.unlink(missing_ok=True)
|
| 388 | script = self.dir / "fsyncload.py"
|
| 389 | script.write_text(self.SCRIPT)
|
| 390 | for _ in range(self.workers):
|
| 391 | self.procs.append(subprocess.Popen(["python3", str(script), str(self.dir), str(self.stop_file)]))
|
| 392 | return self
|
| 393 |
|
| 394 | def __exit__(self, *exc) -> None:
|
| 395 | self.stop_file.write_text("stop")
|
| 396 | for proc in self.procs:
|
| 397 | try:
|
| 398 | proc.wait(timeout=20)
|
| 399 | except subprocess.TimeoutExpired:
|
| 400 | proc.kill()
|