Replay a dirty journal before writing to an instance image

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<n>`` 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):

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

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):