Viewing files at commit ada5e175e5bfCommit detailsView latest

suites/robustness/robustness/envfaults.py 418 lines · 18.1 KB · python
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) -> Optional[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 None  # calibration failed: the need is unmeasured, never zero
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 op_failed(op_res) -> bool:
151
    """The op errored, crashed or hung (returncode None = killed by the harness on timeout)."""
152
    return op_res is None or op_res.timed_out or op_res.returncode != 0
153
154
155
def disk_full_fired(free: int, need_bytes: int, op_res) -> tuple[bool, str]:
156
    """Did the disk-full fault take effect for this op? (fired, evidence).
157
158
    The disk was really filled before the op, so any op that fails, errors or
159
    hangs there is JUDGED (fired): an opaque error on a full disk (fb-548's
160
    "unable to open database file", a panic) must surface as a violation of
161
    op_failure_actionable, never as a skip. Only a SUCCESSFUL op that had room
162
    (measured free >= its calibrated need, no ENOSPC) is fault_not_fired."""
163
    if op_res is not None and ENOSPC_RE.search(op_res.text()):
164
        return True, "op reported ENOSPC"
165
    if free < need_bytes:
166
        return True, f"measured free {free} B < op need {need_bytes} B"
167
    if op_failed(op_res):
168
        rc = None if op_res is None else ("hang" if op_res.timed_out else op_res.returncode)
169
        return True, (f"op failed (rc={rc}) on the filled disk (free {free} B >= need {need_bytes} B, no ENOSPC "
170
                      "text): judged")
171
    return False, f"op succeeded with measured free {free} B >= op need {need_bytes} B"
172
173
174
def _judge_env(trial: Trial, calib: Calibration, op_res, restore) -> tuple[dict, dict]:
175
    """Common judgement: op either converged or failed actionably; then restore and re-run."""
176
    inv: dict = {"op_no_hang": not op_res.timed_out}
177
    obs: dict = {"op": op_res.brief(300)}
178
    if op_res.returncode == 0:
179
        ok, detail = converge_check(trial, calib, trial.target_repo())
180
        inv["op_success_is_true"] = ok
181
        obs["op_converge"] = detail
182
    else:
183
        inv["op_failure_actionable"] = env_actionable(op_res)
184
    restore()
185
    more_inv, more_obs = evaluate(trial, calib, op_res, True)
186
    more_inv.pop("op_no_hang", None)
187
    inv.update(more_inv)
188
    obs.update({k: v for k, v in more_obs.items() if k != "op"})
189
    return inv, obs
190
191
192
def disk_full_trial(fixture, subject_bin: str, work: Path, name: str, calib: Calibration, leave_kib: int,
193
                    need_bytes: Optional[int]) -> dict:
194
    """Run the op with the trial's filesystem filled to ``leave_kib`` free (measured).
195
196
    See disk_full_fired: a failing / hanging op is always judged; only a
197
    success with room to spare is ``fault_not_fired``. need_bytes None (the
198
    clean calibration run failed) makes the row a harness error.
199
    """
200
    started = time.perf_counter()
201
    if need_bytes is None:
202
        return {"fault_point": f"free={leave_kib}KiB", "classification": HARNESS_ERROR, "invariants": {},
203
                "observations": {}, "fault_fired": None,
204
                "harness_error": "op need unmeasured: the clean calibration run of the op failed"}
205
    mount = work / f"{name}-mnt"
206
    op_res = None
207
    fired = None
208
    try:
209
        with RamDisk(mount):
210
            trial = Trial(fixture, subject_bin, mount, "t")
211
            try:
212
                trial.start_server()
213
                trial.pre()
214
                trial.adapter.env()  # create the subject HOME before the disk is full (harness setup)
215
                filler, free = fill(mount, leave_kib)
216
                op_res = trial.adapter.run(trial.op_argv(), trial.op_cwd())
217
                enospc = bool(ENOSPC_RE.search(op_res.text()))
218
                fired, fired_evidence = disk_full_fired(free, need_bytes, op_res)
219
                inv, obs = _judge_env(trial, calib, op_res, lambda: filler.unlink(missing_ok=True))
220
                obs.update(free_bytes_measured_before_op=free, op_need_bytes=need_bytes, enospc_reported=enospc,
221
                           fault_fired_evidence=fired_evidence,
222
                           fill_granularity_bytes=FILL_CHUNKS[-1], requested_free_kib=leave_kib)
223
                classification = classify(inv, fault_fired=fired, reader_errors=obs.get("reader_errors"))
224
                error = None
225
            finally:
226
                trial.stop_server()
227
    except NotImplementedError as exc:
228
        return {"unsupported": str(exc)}
229
    except Exception as exc:  # noqa: BLE001
230
        inv, obs, classification, error = {}, {}, HARNESS_ERROR, f"{type(exc).__name__}: {exc}"
231
    finally:
232
        shutil.rmtree(mount, ignore_errors=True)
233
    row = _row(f"free={leave_kib}KiB", inv, obs, classification, error, op_res, started)
234
    row["fault_fired"] = fired
235
    if "free_bytes_measured_before_op" in obs:
236
        row["free_bytes_measured"] = obs["free_bytes_measured_before_op"]
237
    if classification == FAULT_NOT_FIRED:
238
        row["skip_reason"] = (f"disk not full for this op: it succeeded with "
239
                              f"{obs.get('free_bytes_measured_before_op')} B free >= {need_bytes} B needed")
240
    return row
241
242
243
def readonly_base(repo: Path, kind: str, target: str) -> Path:
244
    return repo / (".oak" if kind == "oak" else ".git") if target == "store" else repo / "d3"
245
246
247
def write_snapshot(base: Path, target: str) -> Optional[dict]:
248
    """What a write under ``base`` would change, as lock_down restricts it.
249
250
    store: every path below is read-only -> {relpath: (inode, size, mtime_ns)} of
251
    the whole tree. subdir: only the directory itself is read-only -> its entry
252
    set {name: inode} plus the directory's own mtime (entry create/rename/delete)."""
253
    if not base.exists():
254
        return None
255
    if target == "store":
256
        out = {}
257
        for path in [base, *base.rglob("*")]:
258
            try:
259
                st = path.lstat()
260
            except OSError:
261
                continue
262
            is_dir = stat.S_ISDIR(st.st_mode)
263
            out[str(path.relative_to(base))] = (st.st_ino, 0 if is_dir else st.st_size,
264
                                                0 if is_dir else st.st_mtime_ns)
265
        return out
266
    out = {"<dir-mtime>": base.stat().st_mtime_ns}
267
    for child in base.iterdir():
268
        out[child.name] = child.lstat().st_ino
269
    return out
270
271
272
def readonly_exercised(fixture, subject_bin: str, work: Path, name: str, target: str) -> tuple[Optional[bool], dict]:
273
    """Does a clean run of the op write under the path readonly_trial locks down?"""
274
    trial = Trial(fixture, subject_bin, work, name)
275
    try:
276
        trial.start_server()
277
        trial.pre()
278
        base = readonly_base(trial.client, trial.kind, target)
279
        before = write_snapshot(base, target)
280
        res = trial.adapter.run(trial.op_argv(), trial.op_cwd())
281
        trial.settle()
282
        after = write_snapshot(base, target)
283
        if res.returncode != 0 or before is None:
284
            return None, {"clean_rc": res.returncode, "detail": "clean run failed or path missing"}
285
        changed = sorted(k for k in set(before) | set(after or {}) if before.get(k) != (after or {}).get(k))
286
        return bool(changed), {"clean_run_changed": len(changed), "sample": changed[:5]}
287
    finally:
288
        trial.stop_server()
289
        trial.cleanup()
290
291
292
def readonly_fired(writable_after_lockdown: bool, exercised: Optional[bool], op_res) -> tuple[Optional[bool], str]:
293
    """Did the read-only fault take effect? (fired, evidence).
294
295
    A failing / hanging op is always judged (fired): its error must be
296
    actionable whatever caused it. A successful op counts as fired only if the
297
    path really was unwritable (not the case as root) and the op attempted a
298
    write there: it reported a permission/read-only error, or a clean run of
299
    the same op writes under that path. Otherwise 'not exercised'."""
300
    if op_failed(op_res):
301
        return True, "op failed with the path read-only: judged"
302
    if writable_after_lockdown:
303
        return False, "not exercised: path still writable after chmod (running as root?)"
304
    if op_res is not None and EACCES_RE.search(op_res.text()):
305
        return True, "op reported a permission/read-only error"
306
    if exercised:
307
        return True, "a clean run of the op writes under the read-only path"
308
    if exercised is None:
309
        return None, "exercise probe failed; whether the op wrote under the path is unmeasured"
310
    return False, "not exercised: a clean run of the op writes nothing under the read-only path"
311
312
313
def readonly_trial(fixture, subject_bin: str, work: Path, name: str, calib: Calibration, target: str,
314
                   exercised: Optional[bool] = None, exercise_detail: Optional[dict] = None) -> dict:
315
    """target: 'store' (.oak/.git) or 'subdir' (worktree d3/).
316
317
    exercised: whether a clean run of the op writes under the locked path
318
    (readonly_exercised); decides fault_fired together with the op's output."""
319
    started = time.perf_counter()
320
    trial = Trial(fixture, subject_bin, work, name)
321
    op_res = None
322
    changed: list[tuple[Path, int]] = []
323
    fired, fired_evidence = None, "not run"
324
325
    def lock_down() -> None:
326
        repo = trial.client
327
        base = readonly_base(repo, trial.kind, target)
328
        for path in [base, *base.rglob("*")] if target == "store" else [base]:
329
            mode = path.stat().st_mode
330
            changed.append((path, mode))
331
            os.chmod(path, mode & ~(stat.S_IWUSR | stat.S_IWGRP | stat.S_IWOTH))
332
333
    def restore() -> None:
334
        for path, mode in reversed(changed):
335
            try:
336
                os.chmod(path, mode)
337
            except OSError:
338
                pass
339
        changed.clear()
340
341
    try:
342
        trial.start_server()
343
        trial.pre()
344
        lock_down()
345
        writable = os.access(readonly_base(trial.client, trial.kind, target), os.W_OK)
346
        op_res = trial.adapter.run(trial.op_argv(), trial.op_cwd())
347
        fired, fired_evidence = readonly_fired(writable, exercised, op_res)
348
        inv, obs = _judge_env(trial, calib, op_res, restore)
349
        obs.update(fault_fired_evidence=fired_evidence, readonly_exercise=exercise_detail)
350
        if fired is None:
351
            # A successful op whose exposure to the fault is unmeasured is neither
352
            # held nor a skip: the instrument could not decide.
353
            classification, error = HARNESS_ERROR, "readonly: " + fired_evidence
354
        else:
355
            classification, error = classify(inv, fault_fired=fired, reader_errors=obs.get("reader_errors")), None
356
    except Exception as exc:  # noqa: BLE001
357
        restore()
358
        inv, obs, classification, error = {}, {}, HARNESS_ERROR, f"{type(exc).__name__}: {exc}"
359
    finally:
360
        restore()
361
        trial.cleanup()
362
    row = _row(f"readonly={target}", inv, obs, classification, error, op_res, started)
363
    row["fault_fired"] = fired
364
    if classification == FAULT_NOT_FIRED:
365
        row["skip_reason"] = fired_evidence
366
    return row
367
368
369
def _row(point, inv, obs, classification, error, op_res, started) -> dict:
370
    row = {"fault_point": point, "invariants": inv, "violations": sorted(k for k, v in inv.items() if v is False),
371
           "observations": obs, "classification": classification,
372
           "elapsed_ms": round(op_res.elapsed_ms if op_res else (time.perf_counter() - started) * 1000.0, 3),
373
           "command": op_res.argv if op_res else []}
374
    if error:
375
        row["harness_error"] = error
376
    elif classification == HARNESS_ERROR and obs.get("reader_errors"):
377
        row["harness_error"] = "independent reader failed: " + "; ".join(obs["reader_errors"][:2])
378
    return row
379
380
381
class FsyncLoad:
382
    """Background fsync storm (idea from the L8 fsyncload.py harness)."""
383
384
    SCRIPT = r"""
385
import os, sys, fcntl, time
386
d, stop = sys.argv[1], sys.argv[2]
387
buf = os.urandom(256 * 1024)
388
p = os.path.join(d, f"load-{os.getpid()}")
389
while not os.path.exists(stop):
390
    with open(p, "wb") as f:
391
        f.write(buf); f.flush()
392
        try: fcntl.fcntl(f.fileno(), 51)
393
        except OSError: os.fsync(f.fileno())
394
os.unlink(p)
395
"""
396
397
    def __init__(self, directory: Path, workers: int = 4):
398
        self.dir = directory
399
        self.workers = workers
400
        self.procs: list[subprocess.Popen] = []
401
402
    def __enter__(self) -> "FsyncLoad":
403
        self.dir.mkdir(parents=True, exist_ok=True)
404
        self.stop_file = self.dir / "stop"
405
        self.stop_file.unlink(missing_ok=True)
406
        script = self.dir / "fsyncload.py"
407
        script.write_text(self.SCRIPT)
408
        for _ in range(self.workers):
409
            self.procs.append(subprocess.Popen(["python3", str(script), str(self.dir), str(self.stop_file)]))
410
        return self
411
412
    def __exit__(self, *exc) -> None:
413
        self.stop_file.write_text("stop")
414
        for proc in self.procs:
415
            try:
416
                proc.wait(timeout=20)
417
            except subprocess.TimeoutExpired:
418
                proc.kill()