diff --git a/ext4_symlink.py b/ext4_symlink.py index ff8ad73..afe8952 100644 --- a/ext4_symlink.py +++ b/ext4_symlink.py @@ -29,6 +29,7 @@ import logging import os +import re import struct import subprocess import sys @@ -203,22 +204,182 @@ def _fsck_ok(device: str, env: dict) -> bool: return _run([_e2fsck(), "-fn", device], env=env).returncode == 0 +_UUID_RE = re.compile(r"^Filesystem UUID:\s*(\S+)", re.MULTILINE) + + +def _fs_uuid(device: str, env: dict) -> str | None: + """The ext4 superblock UUID, or None if this isn't a readable ext4 device. + + Read with ``debugfs`` rather than a check pass: it is a superblock read, so + it costs milliseconds where ``e2fsck -f`` walks the whole (multi-GB) image, + and a UUID is an actual identity where matching sizes are not. + """ + r = _run([_debugfs(), "-R", "show_super_stats -h", device], env=env) + m = _UUID_RE.search(r.stdout or "") + return m.group(1) if m else None + + +def _partition_device(device: str, env: dict) -> str | None: + """Find the ``/dev/sdX`` node backing an ``/dev/sdX?offset=`` device. + + Repairs have to run on this rather than the offset form (see + :func:`_fsck_repair`). That means briefly relying on Cygwin's partition + nodes, which :func:`_cyg_device` deliberately avoids for the *working* + device, so this is best-effort by design: when no node matches, the caller + skips the repair instead of failing. Candidates are matched on superblock + UUID, so a repair can never be pointed at a different filesystem. + """ + base = device.split("?")[0] + if base == device: # already a plain device + return device + want = _fs_uuid(device, env) + if not want: + return None + for n in range(1, 5): + cand = "%s%d" % (base, n) + if _fs_uuid(cand, env) == want: + return cand + return None + + +def _fsck_repair(device: str, env: dict) -> str | None: + """Replay a dirty journal so the image is consistent before we write to it. + + BlueStacks instances are rarely shut down cleanly: the player is terminated + rather than asked to close (its own clean exit needs a human to click through + a confirmation dialog), so the guest never unmounts and ``/data`` routinely + comes to rest with an unreplayed journal. Booting replays it, which is why + this is invisible in normal use. + + Offline it matters twice over. ``e2fsck -fn`` cannot replay a journal, so it + reports such an image as damaged and every caller here turned that into + "e2fsck reported errors" -- an operation refused because of the previous + shutdown, not because anything was wrong. Worse, writing with ``debugfs`` + into a filesystem whose journal still holds pending metadata risks having + that replay overwrite the very changes just made. + + Note what ``-fn`` actually reports on such an image:: + + Warning: skipping journal recovery because doing a read-only filesystem check + Inode 3410023 was part of the orphaned inode list. IGNORED. + Block bitmap differences: ... + + Those "errors" are phantoms: they are the journal's pending metadata, and + they evaporate once it is replayed. Refusing to work on that image was + refusing over nothing. + + The repair has to run on the **partition device**, not on the + ``?offset=`` one everything else here uses. After replaying a journal + e2fsck reopens the filesystem to restart its check, and the reopen drops the + ``?offset=`` qualifier, so it lands on the raw disk and dies with ``Bad magic + number in super-block`` (exit 12) *before committing anything*. The replay + then never persists: run it twice and it announces "recovering journal" both + times, with the image byte-for-byte unchanged. Pointed at ``/dev/sdX1`` + there is no qualifier to lose, and the same preen completes normally (exit 1, + "recovering journal" plus the orphaned inodes cleared) and sticks. + + **Best-effort, and never raises.** It would be wrong to turn "could not + replay" into a hard failure: an unreplayed journal is the *normal* resting + state of a BlueStacks image, so raising would blanket-block every offline + write on any host where the partition node cannot be found, and it would + also block the uninstall and restore paths, which deliberately tolerate a + dirty filesystem (``remove_su_symlink`` runs ``_fsck_ok`` and discards the + result precisely so a removal always completes). Refusing to let someone + undo a change because their last shutdown was untidy is a worse bug than the + one this fixes. When the replay cannot happen we are simply no worse off + than before, and the callers' own post-write checks still apply. + + Returns a note when a repair happened, otherwise ``None``. + """ + if _fsck_ok(device, env): + return None + + part = _partition_device(device, env) + if part is None: + logger.warning( + "%s: journal looks unreplayed but no matching partition node was " + "found, so it is left as-is", device) + return None + + # -fp (preen): the automatic, safe-repairs-only mode a Linux boot uses. Its + # exit code is informative only (12 even on success here, see above), so the + # verdict comes from re-checking; log it either way or a failed repair would + # look like filesystem damage. + result = _run([_e2fsck(), "-fp", part], env=env) + logger.info("e2fsck -fp %s -> exit %s: %s", part, result.returncode, + ((result.stdout or "") + (result.stderr or "")).strip()[:500]) + + if _fsck_ok(device, env): + return ("Replayed the filesystem journal left by the last shutdown " + "before writing.") + logger.warning( + "%s: still reports errors after replaying its journal; continuing, but " + "the caller's own verification may fail", device) + return None + + class _Attached: """Context manager: attach the VHD, resolve its Cygwin device, detach on exit.""" - def __init__(self, vhd_path: str): + def __init__(self, vhd_path: str, repair: bool = True, progress=None): self.vhd = vhd_path self.offset = _partition_offset(vhd_path) self.device: str | None = None + # Every offline writer funnels through here, so this is the one place a + # dirty journal can be dealt with once for all of them. + self.repair = repair + # A replay runs before the caller's first progress message and can take a + # while on a large image, so callers pass their reporter in to say so + # rather than looking frozen on "Attaching...". + self.progress = progress + self.repaired: str | None = None + + def _resolve_device(self) -> str: + num = _disk_number(self.vhd) + if num is None: + raise RuntimeError("could not locate the attached Root.vhd disk") + return _cyg_device(num, self.offset) def __enter__(self) -> _Attached: _attach(self.vhd) time.sleep(1.5) # let Windows enumerate the disk - num = _disk_number(self.vhd) - if num is None: - _detach(self.vhd) - raise RuntimeError("could not locate the attached Root.vhd disk") - self.device = _cyg_device(num, self.offset) + try: + self.device = self._resolve_device() + if self.repair: + self.repaired = _fsck_repair(self.device, _tool_env()) + if self.repaired: + logger.info("%s: %s", self.vhd, self.repaired) + if self.progress: + self.progress(self.repaired) + # The preen wrote through the *partition* node, while every + # other write here goes through the *disk* node. On Windows + # those are separate device objects with separate caches, so + # a late write-back of stale partition-cached sectors could + # land on top of what debugfs writes next. Reattaching drops + # both caches and removes the aliasing entirely. + if _detach(self.vhd): + _attach(self.vhd) + time.sleep(1.5) + self.device = self._resolve_device() + else: + # Re-attaching something still attached would only make + # this worse, so keep the working device and say why the + # cache was not dropped. + logger.warning( + "%s: could not detach to refresh the device cache " + "after the journal replay; continuing on the " + "existing attachment", self.vhd) + except Exception: + # Leaving the VHD attached keeps the image locked and the instance + # unbootable, so detach before the error propagates -- and say so if + # that detach fails, or the user gets an unrelated error while a raw + # disk is still mounted. + if not _detach(self.vhd): + logger.error( + "failed to detach %s -- it may still be mounted as a raw " + "disk; detach it via Disk Management before relaunching the " + "instance", self.vhd) + raise return self def __exit__(self, *exc) -> None: @@ -261,7 +422,7 @@ def _p(msg: str) -> None: env = _tool_env() results: list[str] = [] _p("Attaching Root.vhd (app-root symlink)...") - with _Attached(vhd) as att: + with _Attached(vhd, progress=_p) as att: dev = att.device xbin = _find_xbin(dev, env) if not xbin: @@ -296,7 +457,7 @@ def _p(msg: str) -> None: env = _tool_env() results: list[str] = [] _p("Attaching Root.vhd (remove app-root symlink)...") - with _Attached(vhd) as att: + with _Attached(vhd, progress=_p) as att: dev = att.device xbin = _find_xbin(dev, env) if not xbin or "Type: symlink" not in _stat_su(dev, xbin, env): diff --git a/magisk_system.py b/magisk_system.py index 3e3ee4e..ffbddd5 100644 --- a/magisk_system.py +++ b/magisk_system.py @@ -429,7 +429,7 @@ def _p(msg: str) -> None: grant_script = _grant_script_tempfile() # service.d ADB auto-grant; removed below _p("Attaching Data.vhdx (staging Magisk binaries)...") try: - with _es._Attached(vhdx) as att: + with _es._Attached(vhdx, progress=_p) as att: dev = att.device _p("Writing %d DATABIN files into %s..." % (total, _DATABIN)) svc_exists = "Inode:" in _es._stat_path(dev, _SERVICE_D, env) @@ -480,7 +480,7 @@ def _p(msg: str) -> None: return ["e2fsprogs/Data.vhdx unavailable -- nothing to remove"] env = _es._tool_env() _p("Attaching Data.vhdx (removing Magisk binaries)...") - with _es._Attached(vhdx) as att: + with _es._Attached(vhdx, progress=_p) as att: dev = att.device _es._run_script(dev, _clean_dir_commands(dev, _DATABIN, env) + ["rm %s/%s" % (_SERVICE_D, _ADB_GRANT_SCRIPT)], env) # DATABIN + auto-grant @@ -590,7 +590,7 @@ def _p(msg: str) -> None: env = _es._tool_env() _p("Attaching Root.vhd (installing Magisk to /system)...") - with _es._Attached(root_vhd) as att: + with _es._Attached(root_vhd, progress=_p) as att: dev = att.device sysroot = _find_system_root(dev, env) magiskdir = "%s/etc/init/magisk" % sysroot @@ -644,7 +644,7 @@ def _p(msg: str) -> None: env = _es._tool_env() _p("Attaching Root.vhd (removing Magisk system files)...") try: - with _es._Attached(root_vhd) as att: + with _es._Attached(root_vhd, progress=_p) as att: dev = att.device sysroot = _find_system_root(dev, env) initdir = "%s/etc/init" % sysroot diff --git a/telemetry_block.py b/telemetry_block.py index 4becec0..41b583d 100644 --- a/telemetry_block.py +++ b/telemetry_block.py @@ -283,7 +283,7 @@ def _p(msg: str) -> None: env = _es._tool_env() _p("Attaching Root.vhd (blocking ad/telemetry hosts)...") - with _es._Attached(root_vhd) as att: + with _es._Attached(root_vhd, progress=_p) as att: dev = att.device sysroot = _ms._find_system_root(dev, env) current = _dump_hosts(dev, sysroot, env) @@ -326,7 +326,7 @@ def _p(msg: str) -> None: env = _es._tool_env() _p("Attaching Root.vhd (restoring guest hosts)...") - with _es._Attached(root_vhd) as att: + with _es._Attached(root_vhd, progress=_p) as att: dev = att.device sysroot = _ms._find_system_root(dev, env) if os.path.isfile(backup): diff --git a/tests/test_fsck_repair.py b/tests/test_fsck_repair.py new file mode 100644 index 0000000..6be6956 --- /dev/null +++ b/tests/test_fsck_repair.py @@ -0,0 +1,219 @@ +"""Tests for the pre-write journal replay in ext4_symlink. + +BlueStacks instances are almost never shut down cleanly, so /data routinely +carries an unreplayed journal. `e2fsck -fn` cannot replay one and then reports +phantom errors (orphaned inodes, bitmap differences) that are really the +journal's pending metadata, which used to surface as "e2fsck reported errors" +and refuse an operation over nothing. + +Two properties matter most here and both are easy to regress: + +* the repair runs on the *partition* device, because via `?offset=` the bundled + Cygwin e2fsck dies reopening the filesystem after a replay and never commits; +* it is *best-effort and never raises*, because an unreplayed journal is the + normal resting state of these images, and raising would block the uninstall + and restore paths that deliberately tolerate a dirty filesystem. +""" +import pytest + +import ext4_symlink as es + +OFFSET_DEV = "/dev/sdc?offset=1048576" +PART_DEV = "/dev/sdc1" +UUID = "3f2b1a4c-9d8e-4f7a-b6c5-0123456789ab" +OTHER_UUID = "00000000-1111-2222-3333-444444444444" + + +class _Result: + def __init__(self, returncode, stdout=""): + self.returncode = returncode + self.stdout = stdout + self.stderr = "" + + +def _disk(uuids, dirty_until=1): + """Fake e2fsck/debugfs. `uuids` maps device -> superblock UUID.""" + state = {"preened": 0} + + def handler(cmd): + dev = cmd[-1] + if "show_super_stats -h" in cmd: + uid = uuids.get(dev) + return _Result(0, "Filesystem UUID: %s\n" % uid) if uid else _Result(1, "") + if "-fp" in cmd: + state["preened"] += 1 + return _Result(1, "recovering journal") + if "-fn" in cmd: + return _Result(4 if state["preened"] < dirty_until else 0) + raise AssertionError("unexpected command: %r" % (cmd,)) + + return handler, state + + +def _install(monkeypatch, handler): + calls = [] + + def run(cmd, env=None, **kw): + calls.append(cmd) + return handler(cmd) + + monkeypatch.setattr(es, "_run", run) + return calls + + +# --- _fsck_repair ----------------------------------------------------------- + +def test_clean_image_is_not_touched(monkeypatch): + calls = _install(monkeypatch, _disk({}, dirty_until=0)[0]) + assert es._fsck_repair(OFFSET_DEV, {}) is None + assert not any("-fp" in c for c in calls) + + +def test_repair_runs_on_the_partition_device_not_the_offset_one(monkeypatch): + """The whole point: via ?offset= the replay never persists.""" + handler, _ = _disk({OFFSET_DEV: UUID, PART_DEV: UUID}) + calls = _install(monkeypatch, handler) + note = es._fsck_repair(OFFSET_DEV, {}) + assert note and "journal" in note.lower() + preens = [c for c in calls if "-fp" in c] + assert len(preens) == 1 and preens[0][-1] == PART_DEV + + +def test_verdict_comes_from_rechecking_the_original_device(monkeypatch): + handler, _ = _disk({OFFSET_DEV: UUID, PART_DEV: UUID}) + calls = _install(monkeypatch, handler) + es._fsck_repair(OFFSET_DEV, {}) + assert calls[-1][-1] == OFFSET_DEV and "-fn" in calls[-1] + + +@pytest.mark.parametrize("preen_code", [0, 1, 2, 4, 8, 12]) +def test_preen_exit_code_does_not_decide_the_outcome(monkeypatch, preen_code): + """The real build exits 12 after a successful replay and 1 after a real + repair, so only the recheck may decide.""" + state = {"preened": 0} + + def handler(cmd): + if "show_super_stats -h" in cmd: + return _Result(0, "Filesystem UUID: %s\n" % UUID) + if "-fp" in cmd: + state["preened"] += 1 + return _Result(preen_code) + return _Result(4 if state["preened"] == 0 else 0) + + _install(monkeypatch, handler) + assert es._fsck_repair(OFFSET_DEV, {}) is not None + + +def test_partition_is_matched_by_uuid_not_by_size(monkeypatch): + """Identity guard: a same-size but different filesystem must never be + preened, and with no match the repair is skipped rather than misapplied.""" + handler, state = _disk({OFFSET_DEV: UUID, PART_DEV: OTHER_UUID}) + calls = _install(monkeypatch, handler) + assert es._fsck_repair(OFFSET_DEV, {}) is None + assert state["preened"] == 0 + assert not any("-fp" in c for c in calls) + + +def test_missing_partition_node_is_skipped_not_fatal(monkeypatch): + """Cygwin may not expose /dev/sdXN at all. That must not block the write: + an unreplayed journal is the normal state, so raising would break everything. + """ + handler, _ = _disk({OFFSET_DEV: UUID}) # no partition nodes + _install(monkeypatch, handler) + assert es._fsck_repair(OFFSET_DEV, {}) is None # no exception + + +def test_still_dirty_after_replay_is_reported_but_not_fatal(monkeypatch): + """Uninstall and restore paths tolerate a dirty filesystem on purpose, so a + failed replay must not stop them from running.""" + handler, _ = _disk({OFFSET_DEV: UUID, PART_DEV: UUID}, dirty_until=99) + _install(monkeypatch, handler) + assert es._fsck_repair(OFFSET_DEV, {}) is None # no exception + + +def test_plain_device_needs_no_partition_lookup(monkeypatch): + handler, _ = _disk({PART_DEV: UUID}) + calls = _install(monkeypatch, handler) + es._fsck_repair(PART_DEV, {}) + assert [c for c in calls if "-fp" in c][0][-1] == PART_DEV + + +# --- _Attached wiring ------------------------------------------------------- + +@pytest.fixture +def attach_stub(monkeypatch): + """Stub out diskpart so _Attached can be exercised without a real VHD.""" + events = [] + monkeypatch.setattr(es, "_partition_offset", lambda p: 1048576) + monkeypatch.setattr(es, "_attach", lambda p: events.append("attach")) + monkeypatch.setattr(es, "_detach", lambda p: (events.append("detach"), True)[1]) + monkeypatch.setattr(es, "_disk_number", lambda p: 2) + monkeypatch.setattr(es, "_tool_env", dict) + monkeypatch.setattr(es.time, "sleep", lambda *_: None) + return events + + +def test_clean_image_reports_no_repair(attach_stub, monkeypatch): + monkeypatch.setattr(es, "_fsck_repair", lambda dev, env: None) + with es._Attached("R.vhd") as att: + assert att.repaired is None + assert att.device == OFFSET_DEV + assert attach_stub == ["attach", "detach"] + + +def test_repair_false_skips_it_entirely(attach_stub, monkeypatch): + def boom(dev, env): + raise AssertionError("must not repair when repair=False") + + monkeypatch.setattr(es, "_fsck_repair", boom) + with es._Attached("R.vhd", repair=False) as att: + assert att.repaired is None + + +def test_a_repair_reattaches_to_drop_the_stale_partition_cache(attach_stub, monkeypatch): + """The preen writes through the partition node while debugfs writes through + the disk node; reattaching removes that cache aliasing.""" + monkeypatch.setattr(es, "_fsck_repair", lambda dev, env: "replayed") + with es._Attached("R.vhd") as att: + assert att.repaired == "replayed" + assert attach_stub == ["attach", "detach", "attach", "detach"] + + +def test_a_stuck_detach_does_not_trigger_a_double_attach(attach_stub, monkeypatch): + """If the refresh detach fails, re-attaching an already-attached disk would + only compound it, so we keep the working device instead.""" + monkeypatch.setattr(es, "_fsck_repair", lambda dev, env: "replayed") + monkeypatch.setattr(es, "_detach", + lambda p: (attach_stub.append("detach-failed"), False)[1]) + with es._Attached("R.vhd") as att: + assert att.device == OFFSET_DEV # still usable + assert attach_stub.count("attach") == 1 # never re-attached + + +def test_the_repair_note_is_reported_to_the_caller(attach_stub, monkeypatch): + monkeypatch.setattr(es, "_fsck_repair", lambda dev, env: "replayed the journal") + seen = [] + with es._Attached("R.vhd", progress=seen.append): + pass + assert seen == ["replayed the journal"] + + +def test_a_failure_inside_enter_detaches_before_propagating(attach_stub, monkeypatch): + """Otherwise the image stays mounted as a raw disk and the instance will not + boot until the user detaches it by hand.""" + def boom(dev, env): + raise RuntimeError("kaboom") + + monkeypatch.setattr(es, "_fsck_repair", boom) + with pytest.raises(RuntimeError, match="kaboom"): + with es._Attached("R.vhd"): + pass + assert attach_stub == ["attach", "detach"] + + +def test_an_unlocatable_disk_still_detaches(attach_stub, monkeypatch): + monkeypatch.setattr(es, "_disk_number", lambda p: None) + with pytest.raises(RuntimeError, match="could not locate"): + with es._Attached("R.vhd"): + pass + assert attach_stub == ["attach", "detach"]