Viewing files at commit 5717cc9fc7edCommit detailsView latest

suites/robustness/robustness/envfaults.py 400 lines · 17.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) -> 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()