ci(e2e): boot diagnostics + verbose/debug logging on the API 37 preview job

The API 37 preview E2E boot has flaked twice (#285, #333) with only
"did not boot within 300s" and no root-cause signal. Add rich boot
diagnostics by default, kept in parity between CI and the local
hand-provisioning script (api37_e2e.py):

- Launch the emulator with `-verbose -debug init,avd_config,kernel`
  (diagnostics only; no boot-affecting flag changed), still redirecting
  to $EMU_LOG.
- Stream `adb logcat -v time` to a file from the moment the device
  registers (via `adb wait-for-device logcat`, backgrounded).
- On a boot timeout, dump accel-check, /dev/kvm presence, GPU mode,
  free mem/disk, the AVD config.ini and the emulator.log tail; CI writes
  these to a boot-diagnostics file, the local script prints them.
- CI uploads emulator.log + logcat.txt + boot-diagnostics.txt as an
  artifact with `if: always()` so they survive a timeout/cancel, and
  prints a concise summary (accel/KVM status + last 50 lines of
  emulator.log) to the step log.

The existing 2-attempt boot retry + boot-completed wait loop are
unchanged; the diagnostics are additive.

Closes #334

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>

.claude/skills/preflight/api37_e2e.py

@@ -38,6 +38,7 @@ from __future__ import annotations
 import argparse
 import os
 import platform
+import shutil
 import subprocess
 import sys
 import tempfile
@@ -52,6 +53,11 @@ BUILD_TOOLS = "build-tools;37.0.0"
 AVD_NAME = "api37"
 DEVICE_PROFILE = "pixel_2"
 BOOT_TIMEOUT = 300
+# GPU mode: the ONE deliberate divergence from CI's e2e-preview (which uses `swiftshader_indirect`
+# for headless determinism). Locally we render on the host GPU -- faster, and the mode that boots
+# cleanly on a dev machine. See start_emulator. Kept as a constant so start_emulator and the
+# boot-failure diagnostics dump report the same value.
+GPU_MODE = "auto-no-window"
 
 IS_WINDOWS = os.name == "nt"
 BAT = ".bat" if IS_WINDOWS else ""
@@ -120,15 +126,17 @@ def create_avd(avdmanager: str, emulator: str) -> None:
 def start_emulator(emulator: str, emu_log: Path, attempt: int) -> subprocess.Popen:
     print(f"Starting API 37 emulator (attempt {attempt})...")
     # Flags mirror .github/workflows/ci.yml e2e-preview (cold headless boot, hardware accel
-    # required, no cameras), with ONE deliberate LOCAL exception -- the GPU mode. CI uses
-    # `-gpu swiftshader_indirect` (software rendering, deterministic on a headless CI runner);
-    # locally we use `-gpu auto-no-window`, which renders on the host GPU: faster, and the mode
-    # that boots cleanly on a dev machine. Keep everything except the GPU mode in lockstep with
-    # that job.
+    # required, no cameras), with ONE deliberate LOCAL exception -- the GPU mode (GPU_MODE above:
+    # CI uses `-gpu swiftshader_indirect`, deterministic on a headless CI runner; locally we render
+    # on the host GPU -- faster, and the mode that boots cleanly on a dev machine). `-verbose -debug
+    # init,avd_config,kernel` turns emulator boot logging on by default (mirrors CI) so a boot flake
+    # is diagnosable from $EMU_LOG; it is DIAGNOSTICS ONLY and does not change any boot-affecting
+    # flag. Keep everything except the GPU mode in lockstep with that job.
     flags = [
         "-avd", AVD_NAME,
         "-no-window", "-no-audio", "-no-boot-anim", "-no-snapshot", "-accel", "on",
-        "-gpu", "auto-no-window", "-camera-back", "none", "-camera-front", "none",
+        "-gpu", GPU_MODE, "-camera-back", "none", "-camera-front", "none",
+        "-verbose", "-debug", "init,avd_config,kernel",
     ]
     log = open(emu_log, "wb")  # noqa: SIM115 - handed to the child; closed in the parent below
     try:
@@ -189,6 +197,102 @@ def tail(path: Path, lines: int = 80) -> None:
         pass
 
 
+def _accel_check(emulator: str) -> str:
+    """`emulator -accel-check` output -- the accelerator status (WHPX / KVM / HVF availability)."""
+    try:
+        out = subprocess.run(cmd(emulator, "-accel-check"), capture_output=True, text=True,
+                             check=False)
+        return (out.stdout + out.stderr).strip() or f"(no output; exit {out.returncode})"
+    except OSError as exc:
+        return f"(accel-check failed: {exc})"
+
+
+def _kvm_status() -> str:
+    """/dev/kvm presence (Linux). Off-Linux the accelerator is WHPX/HVF -- see -accel-check."""
+    if os.path.exists("/dev/kvm"):
+        return "/dev/kvm present"
+    return f"/dev/kvm absent (expected off-Linux; platform={platform.system()})"
+
+
+def _mem_info() -> str:
+    """Free/total memory. Reads /proc/meminfo on Linux (where CI runs); best-effort elsewhere."""
+    try:
+        meminfo = Path("/proc/meminfo")
+        if meminfo.exists():
+            wanted = {"MemTotal", "MemFree", "MemAvailable"}
+            lines = [line.strip() for line in meminfo.read_text().splitlines()
+                     if line.split(":", 1)[0] in wanted]
+            if lines:
+                return "; ".join(lines)
+    except OSError:
+        pass
+    return f"(memory stats unavailable on {platform.system()})"
+
+
+def _disk_info(path: Path) -> str:
+    """Free/total disk for the filesystem holding `path` (cross-platform via shutil.disk_usage)."""
+    try:
+        usage = shutil.disk_usage(path)
+        gib = 1024 ** 3
+        return f"total={usage.total / gib:.1f}GiB free={usage.free / gib:.1f}GiB ({path})"
+    except OSError as exc:
+        return f"(disk stats unavailable: {exc})"
+
+
+def start_logcat(adb: str, logcat_log: Path, attempt: int) -> subprocess.Popen | None:
+    """Background `adb wait-for-device logcat -v time` to a file. wait-for-device blocks until the
+    device registers, so streaming starts the moment the emulator appears and captures the whole
+    boot. Mirrors CI's e2e-preview logcat capture; appended (with a header) per boot attempt."""
+    try:
+        with open(logcat_log, "a") as marker:
+            marker.write(f"===== logcat (attempt {attempt}) =====\n")
+        log = open(logcat_log, "ab")  # noqa: SIM115 - child inherits fd; parent copy closed below
+        try:
+            return subprocess.Popen(cmd(adb, "wait-for-device", "logcat", "-v", "time"),
+                                    stdout=log, stderr=subprocess.STDOUT)
+        finally:
+            log.close()  # the child has inherited its own fd; the parent's copy is no longer needed
+    except OSError as exc:
+        print(f"WARNING: could not start logcat capture: {exc}", file=sys.stderr)
+        return None
+
+
+def stop_logcat(proc: subprocess.Popen | None) -> None:
+    if proc and proc.poll() is None:
+        proc.terminate()
+        try:
+            proc.wait(timeout=5)
+        except subprocess.TimeoutExpired:
+            proc.kill()
+
+
+def dump_diagnostics(adb: str, emulator: str, emu_log: Path, avd_home: Path, attempt: int) -> None:
+    """Print boot diagnostics + a concise failure summary to the console -- the local mirror of CI's
+    e2e-preview boot-timeout dump (accel/KVM/GPU/mem/disk/AVD config + emulator.log tail). Local
+    runs PRINT these; CI uploads the same set as an artifact and prints only the concise summary."""
+    accel = _accel_check(emulator)
+    kvm = _kvm_status()
+    config_ini = avd_home / f"{AVD_NAME}.avd" / "config.ini"
+    print(f"===== API 37 boot diagnostics (attempt {attempt}) =====")
+    print("--- adb devices ---")
+    subprocess.run(cmd(adb, "devices"), check=False)
+    print(f"--- emulator -accel-check ---\n{accel}")
+    print(f"--- KVM/hypervisor ---\n{kvm}")
+    print(f"--- GPU mode ---\n{GPU_MODE}")
+    print(f"--- free memory ---\n{_mem_info()}")
+    print(f"--- free disk ---\n{_disk_info(Path(tempfile.gettempdir()))}")
+    print("--- AVD config.ini ---")
+    try:
+        print(config_ini.read_text(errors="replace"))
+    except OSError as exc:
+        print(f"(could not read {config_ini}: {exc})")
+    # Concise failure summary (mirrors CI): accel/KVM status + the last 50 lines of emulator.log.
+    print(f"----- BOOT FAILURE SUMMARY (attempt {attempt}) -----")
+    print(f"accel-check: {accel}")
+    print(f"kvm: {kvm}")
+    tail(emu_log, 50)
+
+
 def main() -> int:
     parser = argparse.ArgumentParser(
         description="Hand-provision + run the API 37 preview E2E suite.")
@@ -216,8 +320,14 @@ def main() -> int:
     os.environ["ANDROID_AVD_HOME"] = str(avd_home)
 
     emu_log = Path(tempfile.gettempdir()) / "libremail-api37-emulator.log"
+    logcat_log = Path(tempfile.gettempdir()) / "libremail-api37-logcat.txt"
+    try:
+        logcat_log.unlink()  # start fresh; start_logcat appends (with a header) per attempt
+    except OSError:
+        pass
     adb: str | None = None
     proc: subprocess.Popen | None = None
+    logcat_proc: subprocess.Popen | None = None
     test_exit = 1
 
     try:
@@ -234,16 +344,21 @@ def main() -> int:
         # 2. Create the AVD, mirroring CI.
         create_avd(avdmanager, emulator)
 
-        # 3. Cold-boot headless, retrying once (mirrors CI's two-attempt boot loop).
+        # 3. Cold-boot headless, retrying once (mirrors CI's two-attempt boot loop). Diagnostics
+        # (logcat capture + a boot-timeout dump) are ADDITIVE -- the retry/boot-wait is unchanged.
         booted = False
         for attempt in (1, 2):
             proc = start_emulator(emulator, emu_log, attempt)
+            # Capture logcat from device registration onward (mirrors CI); killed on failure.
+            logcat_proc = start_logcat(adb, logcat_log, attempt)
             if wait_for_boot(adb, proc, args.boot_timeout):
                 booted = True
                 break
             print(f"API 37 emulator did not boot within {args.boot_timeout}s (attempt {attempt}).",
                   file=sys.stderr)
-            tail(emu_log)
+            dump_diagnostics(adb, emulator, emu_log, avd_home, attempt)
+            stop_logcat(logcat_proc)
+            logcat_proc = None
             stop_emulator(adb, proc)
             proc = None
             time.sleep(5)
@@ -266,9 +381,12 @@ def main() -> int:
     finally:
         # 5. Always tear the emulator down and delete the AVD, even on failure.
         print("Tearing down API 37 emulator and AVD...")
+        stop_logcat(logcat_proc)
         stop_emulator(adb, proc)
         subprocess.run(cmd(avdmanager, "delete", "avd", "-n", AVD_NAME), check=False,
                        stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL)
+        print(f"(emulator boot log: {emu_log})")
+        print(f"(logcat: {logcat_log})")
 
     if test_exit != 0:
         print(f"api37 connectedDebugAndroidTest failed (exit {test_exit}).", file=sys.stderr)

.github/workflows/ci.yml

@@ -577,13 +577,50 @@ jobs:
         run: |
           set -euo pipefail
           EMU_LOG="${RUNNER_TEMP:-/tmp}/emulator.log"
+          LOGCAT_LOG="${RUNNER_TEMP:-/tmp}/logcat.txt"
+          DIAG_LOG="${RUNNER_TEMP:-/tmp}/boot-diagnostics.txt"
+          GPU_MODE="swiftshader_indirect"
+
+          # On a boot timeout, capture the full system state (accel/KVM/GPU/mem/disk/AVD config +
+          # emulator.log tail) into $DIAG_LOG for the artifact upload, then print a CONCISE summary
+          # (accel/KVM status + last 50 lines of emulator.log) to the step log so the cause is
+          # visible in the run output without downloading artifacts. Every probe is guarded (|| true)
+          # so a missing tool can't abort the retry under `set -e`.
+          dump_diagnostics() {
+            local attempt="$1" accel kvm
+            accel=$("$ANDROID_SDK_ROOT/emulator/emulator" -accel-check 2>&1) || true
+            kvm=$(ls -l /dev/kvm 2>&1) || true
+            {
+              echo "===== API 37 boot diagnostics (attempt $attempt) ====="
+              echo "--- adb devices ---";             adb devices 2>&1 || true
+              echo "--- emulator -accel-check ---";    echo "$accel"
+              echo "--- /dev/kvm ---";                echo "$kvm"
+              echo "--- GPU mode ---";                echo "$GPU_MODE"
+              echo "--- free memory ---";             free -h 2>&1 || true
+              echo "--- free disk ---";               df -h 2>&1 || true
+              echo "--- AVD config.ini ---";          cat "${ANDROID_AVD_HOME:-$HOME/.android/avd}/api37.avd/config.ini" 2>&1 || true
+              echo "--- emulator.log (tail 200) ---";  tail -200 "$EMU_LOG" 2>&1 || true
+            } >> "$DIAG_LOG" 2>&1 || true
+            echo "----- BOOT FAILURE SUMMARY (attempt $attempt) -----"
+            echo "accel-check: $accel"
+            echo "/dev/kvm:    $kvm"
+            echo "--- emulator.log (tail 50) ---"; tail -50 "$EMU_LOG" 2>&1 || true
+          }
 
           boot_emulator() {
             echo "::group::Start API 37 emulator (attempt $1)"
             # Capture the emulator's own output — without this a boot failure is invisible.
+            # -verbose -debug init,avd_config,kernel turns boot logging on by default so a boot flake
+            # is diagnosable from $EMU_LOG; DIAGNOSTICS ONLY — no boot-affecting flag is changed.
             "$ANDROID_SDK_ROOT/emulator/emulator" -avd api37 \
               -no-window -no-audio -no-boot-anim -no-snapshot -accel on \
-              -gpu swiftshader_indirect -camera-back none -camera-front none > "$EMU_LOG" 2>&1 &
+              -gpu "$GPU_MODE" -camera-back none -camera-front none \
+              -verbose -debug init,avd_config,kernel > "$EMU_LOG" 2>&1 &
+            # Stream logcat from the moment the device registers (wait-for-device blocks until then)
+            # into a file that survives to the artifact upload. Appended (with a header) per attempt.
+            echo "===== logcat (attempt $1) =====" >> "$LOGCAT_LOG"
+            adb wait-for-device logcat -v time >> "$LOGCAT_LOG" 2>&1 &
+            logcat_pid=$!
             # ONE bounded wait covering both device registration and full boot, so a stuck emulator
             # fails fast instead of hanging the whole job until the 35-min cap (the original bug).
             if timeout 300 adb wait-for-device shell \
@@ -592,8 +629,8 @@ jobs:
             fi
             echo "::endgroup::"
             echo "::warning::API 37 emulator did not boot within 300s (attempt $1)"
-            adb devices || true
-            echo "--- emulator.log (tail) ---"; tail -120 "$EMU_LOG" || true
+            dump_diagnostics "$1"
+            kill "$logcat_pid" 2>/dev/null || true
             adb emu kill 2>/dev/null || true
             sleep 5
             return 1
@@ -612,6 +649,19 @@ jobs:
           echo "--- emulator.log ---"; tail -200 "${RUNNER_TEMP:-/tmp}/emulator.log" 2>/dev/null || echo "(none)"
           echo "--- logcat ---"; adb logcat -d 2>/dev/null | tail -120 || echo "(device unavailable)"
 
+      # Always upload the emulator log + captured logcat + boot-diagnostics dump so a boot flake
+      # (which can time out or be cancelled) is diagnosable from artifacts without a re-run.
+      - name: Upload emulator boot diagnostics
+        if: always()
+        uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1
+        with:
+          name: e2e-api37-boot-diagnostics
+          path: |
+            ${{ runner.temp }}/emulator.log
+            ${{ runner.temp }}/logcat.txt
+            ${{ runner.temp }}/boot-diagnostics.txt
+          if-no-files-found: warn
+
       - name: Shut down emulator
         if: always()
         run: adb emu kill || true