fix: harden log export transactions

This commit is contained in:
Kurt Himebauch committed 2026-11-05 14:42:22 -05:00
1 parent 718712eb01
commit 4765644451
3 files changed
+176 -29

No files matched your search

@@ -215,7 +215,8 @@ class AgentBridgeProvider : ContentProvider() {
throw error
}
?: return error("NO_SESSION_LOGS", "The session artifact directory is empty")
return JSONObject().put("ok", true).put("command", "logs").put("sessionId", dir.name).put("zip", zip.absolutePath)
return JSONObject().put("ok", true).put("command", "logs").put("sessionId", dir.name)
.put("zip", zip.absolutePath).put("cleanupDir", output.absolutePath)
}
private fun state(context: Context): JSONObject {
+84 -23
View File
@@ -18,7 +18,7 @@ import time
import uuid
import zipfile
import zlib
from pathlib import Path
from pathlib import Path, PurePosixPath
sys.path.insert(0, str(Path(__file__).resolve().parent))
from adb_device import DeviceResolutionError, resolve_serial
@@ -434,40 +434,84 @@ def unpack_logs(archive: Path, destination: Path, session_id: str) -> None:
except (OSError, ValueError):
previous = []
previous = set(previous)
previous.discard(manifest.name)
extracted = set()
def managed_target(name: str) -> Path | None:
relative = Path(name)
if relative.is_absolute() or not relative.parts or any(part in {".", ".."} for part in relative.parts):
return None
target = destination
for part in relative.parts:
target = target / part
if target.is_symlink():
return None
return target if target.resolve().is_relative_to(destination) else None
try:
with tempfile.TemporaryDirectory(prefix="droiddeckctl-logs-") as temp, zipfile.ZipFile(archive) as z:
with tempfile.TemporaryDirectory(prefix=".droiddeckctl-logs-", dir=destination) as temp, zipfile.ZipFile(archive) as z:
staged = Path(temp)
staged_files = staged / "new"
backups = staged / "old"
staged_files.mkdir()
for entry in z.infolist():
name = entry.filename
if name.startswith(session_id + "/"):
name = name[len(session_id) + 1:]
target = (destination / name).resolve()
if entry.is_dir() or not name or not target.is_relative_to(destination):
target = managed_target(name)
if entry.is_dir() or target is None or target == manifest:
continue
relative = target.relative_to(destination).as_posix()
if relative == manifest.name:
continue
staged_file = staged / relative
staged_file = staged_files / relative
staged_file.parent.mkdir(parents=True, exist_ok=True)
with z.open(entry) as source, staged_file.open("wb") as copy:
shutil.copyfileobj(source, copy)
extracted.add(relative)
for name in extracted - previous:
target = destination / name
if target.exists() or target.is_symlink():
target = managed_target(name)
if target is None or target.exists():
raise ControlError(f"Refusing to overwrite an unrelated file: {target}", "LOG_PULL_FAILED")
for name in previous - extracted:
target = (destination / name).resolve()
if target.is_relative_to(destination) and target.is_file() and not target.is_symlink():
target.unlink()
for name in extracted:
target = destination / name
target.parent.mkdir(parents=True, exist_ok=True)
os.replace(staged / name, target)
temp_manifest = manifest.with_name(manifest.name + ".tmp")
temp_manifest.write_text(json.dumps(sorted(extracted), indent=2) + "\n", encoding="utf-8")
os.replace(temp_manifest, manifest)
if manifest.is_symlink() or (manifest.exists() and not manifest.is_file()):
raise ControlError("The managed log list is not a regular file", "LOG_PULL_FAILED")
backed_up = {}
installed = set()
manifest_backup = backups / manifest.name
try:
for name in sorted(previous):
target = managed_target(name)
if target is not None and target.is_file():
backup = backups / name
backup.parent.mkdir(parents=True, exist_ok=True)
os.replace(target, backup)
backed_up[name] = backup
if manifest.is_file():
manifest_backup.parent.mkdir(parents=True, exist_ok=True)
os.replace(manifest, manifest_backup)
for name in sorted(extracted):
target = managed_target(name)
if target is None:
raise ControlError(f"A log destination became unsafe: {name}", "LOG_PULL_FAILED")
target.parent.mkdir(parents=True, exist_ok=True)
os.replace(staged_files / name, target)
installed.add(name)
temp_manifest = staged / "managed-logs.json"
temp_manifest.write_text(json.dumps(sorted(extracted), indent=2) + "\n", encoding="utf-8")
os.replace(temp_manifest, manifest)
except Exception:
for name in installed:
target = managed_target(name)
if target is not None and target.is_file():
target.unlink()
if manifest.exists() and not manifest.is_symlink():
manifest.unlink()
for name, backup in backed_up.items():
target = managed_target(name)
if target is not None:
target.parent.mkdir(parents=True, exist_ok=True)
os.replace(backup, target)
if manifest_backup.is_file():
os.replace(manifest_backup, manifest)
raise
except (OSError, zipfile.BadZipFile) as exc:
raise ControlError(f"Could not unpack the session logs: {exc}", "LOG_PULL_FAILED") from exc
@@ -798,7 +842,17 @@ def execute(args: argparse.Namespace, adb: str, serial: str) -> dict:
result = run_adb(adb, serial, "pull", remote_dir, str(destination), timeout=120)
else:
zip_path = checked(exported, "LOG_PULL_FAILED")["zip"]
cleanup_dir = str(Path(zip_path).parent)
remote_zip = PurePosixPath(zip_path)
if (not remote_zip.is_absolute() or ".." in remote_zip.parts or
not re.fullmatch(r"/[A-Za-z0-9_./-]+", zip_path)):
raise ControlError("The exported logs path is invalid", "LOG_PULL_FAILED")
requested_dir = exported.get("cleanupDir")
request_dir = PurePosixPath(requested_dir) if isinstance(requested_dir, str) else None
cleanup = ["shell", "rm", "-f", zip_path]
if (request_dir and request_dir.is_absolute() and ".." not in request_dir.parts and
request_dir == remote_zip.parent and request_dir.parent.name == "agent-logs" and
re.fullmatch(r"[0-9a-fA-F-]{36}", request_dir.name)):
cleanup = ["shell", "rm", "-rf", str(request_dir)]
try:
if exported.get("sessionId", session["id"]) != session["id"]:
raise ControlError("A new session started while the logs were exported; run logs again",
@@ -810,7 +864,14 @@ def execute(args: argparse.Namespace, adb: str, serial: str) -> dict:
unpack_logs(local_zip, destination, session["id"])
finally:
# The copy sits in shared storage, so it does not outlive the pull.
run_adb(adb, serial, "shell", "rm", "-rf", cleanup_dir, timeout=30)
cleaned = run_adb(adb, serial, *cleanup, timeout=30)
if cleaned.returncode != 0:
detail = (cleaned.stderr or cleaned.stdout).decode(errors="replace").strip()
raise ControlError(
"Could not remove the exported log archive; it may remain in shared storage" +
(f": {detail}" if detail else ""),
"LOG_CLEANUP_FAILED",
)
if result.returncode != 0:
detail = (result.stderr or result.stdout).decode(errors="replace").strip()
raise ControlError(detail or "adb pull failed", "LOG_PULL_FAILED")
@@ -1044,7 +1105,7 @@ EXIT_SESSION = {
"NO_STEAM_SESSION", "SESSION_NOT_READY", "AGENT_UNAVAILABLE", "LAUNCH_REJECTED", "NO_PAD", "NO_FRAMES",
}
EXIT_TIMEOUT = {"TIMEOUT", "ARTIFACT_TIMEOUT"}
EXIT_FILE = {"NO_SESSION_LOGS", "LOG_PULL_FAILED", "SCREENSHOT_FAILED", "FILE_IO", "RECORD_FAILED", "PUSH_FAILED",
EXIT_FILE = {"NO_SESSION_LOGS", "LOG_PULL_FAILED", "LOG_CLEANUP_FAILED", "SCREENSHOT_FAILED", "FILE_IO", "RECORD_FAILED", "PUSH_FAILED",
"PACING_FAILED", "XR_CAPTURE_FAILED"}
EXIT_DENIED = {"AGENT_COMMANDS_DISABLED", "PROTECTED_PREFS", "PROTECTED_CONTROL"}
+90 -5
View File
@@ -76,6 +76,9 @@ FAKE_ADB = textwrap.dedent('''\
elif args[:1] == ["pull"]:
entry["denied"] = True
print(f"adb: error: failed to stat remote object '{args[1]}': Permission denied", file=sys.stderr)
elif args[:2] == ["shell", "rm"] and config.get("fail_cleanup"):
entry["denied"] = True
print("adb: error: cleanup denied", file=sys.stderr)
with open(config["log"], "a") as log:
log.write(json.dumps(entry) + "\\n")
sys.exit(1 if entry.get("denied") else 0)
@@ -138,7 +141,9 @@ CPUFREQ = textwrap.dedent('''\
def battery(tenths):
return f"Current Battery Service state:\n level: 80\n temperature: {tenths}\n technology: Li-poly"
PRIVATE_LOG_DIR = "/data/user/0/com.droiddeck.launcher/files/logs/sessions/s1"
EXPORTED_ZIP = "/storage/emulated/0/Android/data/com.droiddeck.launcher/files/agent-logs/request-1/DroidDeck-s1.zip"
AGENT_LOGS_DIR = "/storage/emulated/0/Android/data/com.droiddeck.launcher/files/agent-logs"
EXPORTED_DIR = AGENT_LOGS_DIR + "/123e4567-e89b-12d3-a456-426614174000"
EXPORTED_ZIP = EXPORTED_DIR + "/DroidDeck-s1.zip"
def share_zip(entries):
@@ -531,7 +536,8 @@ class DroiddeckctlTest(FakeAdbTest):
code, out = self.run_ctl("wait", "cool", "--below", "38")
self.assertEqual("THERMAL_FAILED", out["error"]["code"])
def test_logs_pull_the_exported_zip_instead_of_the_private_folder(self):
self.configure({"state": ended_state(), "logs": {"ok": True, "sessionId": "s1", "zip": EXPORTED_ZIP}},
self.configure({"state": ended_state(), "logs": {"ok": True, "sessionId": "s1", "zip": EXPORTED_ZIP,
"cleanupDir": EXPORTED_DIR}},
files={EXPORTED_ZIP: share_zip({"s1/session.log": "booted", "s1/steam/console.log": "c",
"stores/epic.log": "e", "../outside": "x"})})
destination = self.dir / "artifacts"
@@ -542,16 +548,38 @@ class DroiddeckctlTest(FakeAdbTest):
self.assertEqual("e", (destination / "stores" / "epic.log").read_text())
self.assertFalse((self.dir / "outside").exists())
self.assertEqual([["pull", EXPORTED_ZIP]], [c["args"][:2] for c in self.calls() if c["args"][:1] == ["pull"]])
self.assertIn(["shell", "rm", "-rf", str(Path(EXPORTED_ZIP).parent)], [c["args"] for c in self.calls()])
self.assertIn(["shell", "rm", "-rf", EXPORTED_DIR], [c["args"] for c in self.calls()])
def test_logs_of_a_session_that_started_meanwhile_are_refused(self):
self.configure({"state": ended_state(), "logs": {"ok": True, "sessionId": "s2", "zip": EXPORTED_ZIP}},
self.configure({"state": ended_state(), "logs": {"ok": True, "sessionId": "s2", "zip": EXPORTED_ZIP,
"cleanupDir": EXPORTED_DIR}},
files={EXPORTED_ZIP: share_zip({"s2/session.log": "other"})})
code, out = self.run_ctl("logs", "latest", str(self.dir / "artifacts"))
self.assertEqual(6, code)
self.assertEqual("LOG_PULL_FAILED", out["error"]["code"])
self.assertFalse((self.dir / "artifacts").exists())
self.assertIn(["shell", "rm", "-rf", str(Path(EXPORTED_ZIP).parent)], [c["args"] for c in self.calls()])
self.assertIn(["shell", "rm", "-rf", EXPORTED_DIR], [c["args"] for c in self.calls()])
def test_logs_from_a_legacy_provider_remove_only_the_export_zip(self):
legacy_zip = AGENT_LOGS_DIR + "/DroidDeck-s1.zip"
self.configure({"state": ended_state(),
"logs": {"ok": True, "sessionId": "s1", "zip": legacy_zip}},
files={legacy_zip: share_zip({"s1/session.log": "booted"})})
code, out = self.run_ctl("logs", "latest", str(self.dir / "artifacts"))
self.assertEqual(0, code, out)
commands = [c["args"] for c in self.calls()]
self.assertIn(["shell", "rm", "-f", legacy_zip], commands)
self.assertNotIn(["shell", "rm", "-rf", AGENT_LOGS_DIR], commands)
def test_logs_report_when_remote_export_cleanup_fails(self):
self.configure({"state": ended_state(),
"logs": {"ok": True, "sessionId": "s1", "zip": EXPORTED_ZIP,
"cleanupDir": EXPORTED_DIR}},
fail_cleanup=True, files={EXPORTED_ZIP: share_zip({"s1/session.log": "booted"})})
code, out = self.run_ctl("logs", "latest", str(self.dir / "artifacts"))
self.assertEqual(6, code, out)
self.assertEqual("LOG_CLEANUP_FAILED", out["error"]["code"])
self.assertIn("may remain in shared storage", out["error"]["message"])
def test_logs_replace_the_previous_snapshot_and_preserve_unrelated_files(self):
destination = self.dir / "artifacts"
@@ -572,6 +600,63 @@ class DroiddeckctlTest(FakeAdbTest):
self.assertFalse((destination / "steam/console.log").exists())
self.assertEqual("keep me", (destination / "notes.txt").read_text())
def test_logs_do_not_follow_a_stale_managed_symlink(self):
if os.name == "nt":
self.skipTest("symlink creation is unavailable on this Windows host")
destination = self.dir / "artifacts"
destination.mkdir()
victim = destination / "notes.txt"
victim.write_text("keep me")
(destination / ".droiddeckctl-managed-logs.json").write_text(json.dumps(["old.log"]))
(destination / "old.log").symlink_to(victim)
archive = self.dir / "logs.zip"
with zipfile.ZipFile(archive, "w") as z:
z.writestr("s1/session.log", "current")
ctl.unpack_logs(archive, destination, "s1")
self.assertEqual("keep me", victim.read_text())
self.assertTrue((destination / "old.log").is_symlink())
self.assertEqual("current", (destination / "session.log").read_text())
def test_logs_roll_back_a_failed_manifest_commit_and_can_retry(self):
destination = self.dir / "artifacts"
destination.mkdir()
(destination / "notes.txt").write_text("keep me")
first = self.dir / "first.zip"
with zipfile.ZipFile(first, "w") as z:
z.writestr("s1/session.log", "first")
z.writestr("s1/steam/console.log", "old")
ctl.unpack_logs(first, destination, "s1")
old_manifest = (destination / ".droiddeckctl-managed-logs.json").read_bytes()
second = self.dir / "second.zip"
with zipfile.ZipFile(second, "w") as z:
z.writestr("s1/session.log", "second")
z.writestr("s1/new.log", "new")
real_replace = ctl.os.replace
failed = False
def fail_manifest_once(source, target):
nonlocal failed
if Path(target) == destination / ".droiddeckctl-managed-logs.json" and not failed:
failed = True
raise OSError("injected manifest failure")
return real_replace(source, target)
with unittest.mock.patch.object(ctl.os, "replace", side_effect=fail_manifest_once):
with self.assertRaises(ctl.ControlError):
ctl.unpack_logs(second, destination, "s1")
self.assertEqual("first", (destination / "session.log").read_text())
self.assertEqual("old", (destination / "steam/console.log").read_text())
self.assertFalse((destination / "new.log").exists())
self.assertEqual(old_manifest, (destination / ".droiddeckctl-managed-logs.json").read_bytes())
ctl.unpack_logs(second, destination, "s1")
self.assertEqual("second", (destination / "session.log").read_text())
self.assertEqual("new", (destination / "new.log").read_text())
self.assertFalse((destination / "steam/console.log").exists())
self.assertEqual("keep me", (destination / "notes.txt").read_text())
def test_logs_from_an_older_build_fall_back_to_the_private_folder(self):
self.configure({"state": ended_state()})
code, out = self.run_ctl("logs", "latest", str(self.dir / "artifacts"))