diff --git a/README.md b/README.md index dc51794..653046b 100644 --- a/README.md +++ b/README.md @@ -96,6 +96,13 @@ The image didn't match the dump, so nothing was uploaded. Use **Compress again**. If it keeps failing, copy the dump again; it may be incomplete or on a failing drive. +#### ShadowMountPlus couldn't register the game + +The image is on the PS5, but ShadowMountPlus couldn't add it to the home screen. If the +message mentions a lost system hook, that's a ShadowMountPlus 1.7beta4 (and older) bug +after rest mode: update to 1.7beta5 or newer, or restart ShadowMountPlus, then use +**Check again**. + #### Mount not confirmed The image made it to the PS5, but ShadowMountPlus hadn't mounted diff --git a/src-tauri/src/ftp.rs b/src-tauri/src/ftp.rs index e2bc8bc..308bae9 100644 --- a/src-tauri/src/ftp.rs +++ b/src-tauri/src/ftp.rs @@ -181,7 +181,15 @@ impl Ftp { /// Downloads a (small) file. `Ok(None)` when it doesn't exist. pub fn retr(&mut self, path: &str) -> Result>, String> { + self.retr_from(path, 0) + } + + /// Downloads a file starting at byte `offset` (used to read only the new end of a log). + pub fn retr_from(&mut self, path: &str, offset: u64) -> Result>, String> { let mut data = self.pasv()?; + if offset > 0 { + self.expect(&format!("REST {offset}"), &[350])?; + } let r = self.cmd(&format!("RETR {path}"))?; if r.code == 550 { return Ok(None); diff --git a/src-tauri/src/pipeline.rs b/src-tauri/src/pipeline.rs index e2f4f94..9378ba7 100644 --- a/src-tauri/src/pipeline.rs +++ b/src-tauri/src/pipeline.rs @@ -758,25 +758,35 @@ impl Queue { }; let started = Instant::now(); let mut last = Instant::now(); - let mounted = ps5::wait_for_mount(s, &title, &remote, Duration::from_secs(MOUNT_WAIT_SECS), cancel, &mut |secs| { + let outcome = ps5::wait_for_mount(s, &title, &remote, Duration::from_secs(MOUNT_WAIT_SECS), cancel, &mut |secs| { self.progress(id, &mut last, started, |j| { j.pct = (secs as f64 / MOUNT_WAIT_SECS as f64 * 100.0).min(99.0); j.stages[3].meta = format!("Waiting for ShadowMountPlus ยท {secs}s"); }); })?; + let mounted = outcome == ps5::MountOutcome::Registered; self.with(id, |j| { - if mounted { - j.warnings.retain(|w| !w.starts_with("ShadowMountPlus hasn't mounted")); - j.stages[3].meta = "Mounted by ShadowMountPlus".into(); - j.log("ok", "ShadowMountPlus mounted the image. It's ready to play."); - } else { - j.stages[3].state = StageState::Warn; - j.stages[3].meta = "Not confirmed within 5 minutes".into(); - j.warnings.push( - "ShadowMountPlus hasn't mounted the image yet. The game may still show up; use Check again, or restart ShadowMountPlus." - .into(), - ); - j.log("warn", "Mount not confirmed within 5 minutes"); + j.warnings.retain(|w| !w.starts_with("ShadowMountPlus")); + match &outcome { + ps5::MountOutcome::Registered => { + j.stages[3].meta = "Mounted by ShadowMountPlus".into(); + j.log("ok", "ShadowMountPlus registered the game. It's ready to play."); + } + ps5::MountOutcome::Failed(reason) => { + j.stages[3].state = StageState::Warn; + j.stages[3].meta = "ShadowMountPlus couldn't register it".into(); + j.warnings.push(reason.clone()); + j.log("warn", reason.clone()); + } + ps5::MountOutcome::Unconfirmed => { + j.stages[3].state = StageState::Warn; + j.stages[3].meta = "Not confirmed within 5 minutes".into(); + j.warnings.push( + "ShadowMountPlus hasn't registered the game yet. It may still appear; use Check again, or restart ShadowMountPlus." + .into(), + ); + j.log("warn", "Mount not confirmed within 5 minutes"); + } } }); if mounted && s.delete_local_after_upload { @@ -1030,5 +1040,21 @@ mod e2e { assert!(j5.log.iter().any(|l| l.text.starts_with("Resuming at")), "should resume"); assert_eq!(std::fs::read(&remote).unwrap(), good, "resumed upload must be byte-identical"); assert!(!part.exists()); + + // ShadowMountPlus with a lost ShellCore hook: it writes mount_img.lnk but can't register + // the game. That must end as a warning with the reason, never as "Ready to play". + q.remove(id5).unwrap(); + std::fs::write(ps5_root.join("data/shadowmount/.broken-hook"), b"").unwrap(); + let dump2 = tmp.path().join("PPSA00002-app"); + copy_dir(&dump, &dump2); + let param = dump2.join("sce_sys/param.json"); + let p = std::fs::read_to_string(¶m).unwrap().replace("PPSA00001", "PPSA00002"); + std::fs::write(¶m, p).unwrap(); + let id6 = q.add(crate::dump::inspect(&dump2).unwrap()).unwrap(); + let j6 = wait_until(&q, id6, 300); + assert_eq!(j6.status, JobStatus::Done, "error: {:?}", j6.error); + assert_eq!(j6.stages[3].state, StageState::Warn, "must not report a mount that failed"); + assert!(j6.warnings.iter().any(|w| w.contains("system hook was lost")), "{:?}", j6.warnings); + assert!(ps5_root.join("user/app/PPSA00002/mount_img.lnk").is_file(), "the stale link exists, as on a real PS5"); } } diff --git a/src-tauri/src/ps5.rs b/src-tauri/src/ps5.rs index 68ced5d..a6bd5df 100644 --- a/src-tauri/src/ps5.rs +++ b/src-tauri/src/ps5.rs @@ -276,7 +276,78 @@ pub fn request_scan(ftp: &mut Ftp, title_id: &str, image: &str, backup_dir: Opti Ok(changed) } -/// Polls `/user/app//mount_img.lnk` until ShadowMountPlus records the image. +/// How a mount attempt ended. +#[derive(Debug, Clone, PartialEq)] +pub enum MountOutcome { + /// ShadowMountPlus mounted and registered the game. + Registered, + /// ShadowMountPlus tried and gave up; the reason is ready to show the user. + Failed(String), + /// Nothing conclusive before the timeout. + Unconfirmed, +} + +const SMP_LOG: &str = "/data/shadowmount/debug.log"; + +/// True when manual.status says ShadowMountPlus installed this image. It writes that line +/// only after the game is mounted *and* registered; the link files in /user/app are written +/// before registration and stay behind when it fails, so they can't be trusted on their own. +pub fn manual_status_installed(text: &str, title_id: &str, image: &str) -> bool { + text.lines().any(|l| { + let f: Vec<&str> = l.split('\t').collect(); + f.len() >= 3 && f[0] == "installed" && f[1].eq_ignore_ascii_case(title_id) && f[2] == image + }) +} + +/// Looks through new ShadowMountPlus log lines for a registration failure of this title. +pub fn register_failure(log: &str, title_id: &str) -> Option<String> { + let mut ours = false; + for line in log.lines() { + if line.contains("[ACTION]") { + // "Installing: Name (TITLE)" / "Remounting: Name": track whether the following lines are about us. + ours = line.contains(&format!("({title_id})")); + continue; + } + if ours && line.contains("AppInstallTitleDir bridge unavailable") { + return Some( + "ShadowMountPlus mounted the game but couldn't register it: its system hook was lost, which happens \ + after rest mode in ShadowMountPlus 1.7beta4 and older. Update ShadowMountPlus (1.7beta5 fixes it) or \ + restart it, then use Check again." + .into(), + ); + } + if ours && line.contains("sceAppInstUtilAppInstallTitleDir unavailable") { + return Some( + "ShadowMountPlus couldn't register the game (the PS5's install service wasn't available). Restart \ + ShadowMountPlus, then use Check again." + .into(), + ); + } + if line.contains("retry limit reached") && line.contains(&format!("({title_id})")) { + return Some( + "ShadowMountPlus gave up on the game after two attempts. Restart ShadowMountPlus, then use Check again. \ + Its log is /data/shadowmount/debug.log." + .into(), + ); + } + if ours { + if let Some(code) = line.split("[REG] FAIL: ").nth(1) { + return Some(format!( + "The PS5 refused to register the game (error {}). Restart ShadowMountPlus and use Check again; \ + if it keeps failing, the dump may need a backport for your firmware.", + code.trim() + )); + } + } + } + None +} + +fn log_size(ftp: &mut Ftp) -> Option<u64> { + ftp.size(SMP_LOG).ok().flatten() +} + +/// Waits until ShadowMountPlus has registered the image, it reports a failure, or `timeout`. pub fn wait_for_mount( s: &Settings, title_id: &str, @@ -284,35 +355,53 @@ pub fn wait_for_mount( timeout: Duration, cancel: &std::sync::atomic::AtomicBool, tick: &mut dyn FnMut(u64), -) -> Result<bool, String> { +) -> Result<MountOutcome, String> { let start = Instant::now(); - let link = format!("/user/app/{title_id}/mount_img.lnk"); + let status_path = format!("{SMP_DIR}/manual.status"); + // Only log lines written from now on are about this attempt. + let mut log_offset = connect(s).ok().and_then(|mut f| { + let n = log_size(&mut f); + f.quit(); + n + }); let mut last_nudge = Instant::now(); while start.elapsed() < timeout { - if last_nudge.elapsed() >= Duration::from_secs(30) { - last_nudge = Instant::now(); - if let Ok(mut ftp) = connect(s) { - let _ = request_scan(&mut ftp, title_id, image_remote, None); - ftp.quit(); - } - } if cancel.load(std::sync::atomic::Ordering::Relaxed) { return Err("Cancelled".into()); } tick(start.elapsed().as_secs()); if let Ok(mut ftp) = connect(s) { - if let Ok(Some(bytes)) = ftp.retr(&link) { - let text = String::from_utf8_lossy(&bytes); - if text.lines().any(|l| l.trim() == image_remote) { + if let Ok(Some(bytes)) = ftp.retr(&status_path) { + if manual_status_installed(&String::from_utf8_lossy(&bytes), title_id, image_remote) { ftp.quit(); - return Ok(true); + return Ok(MountOutcome::Registered); } } + if let Some(size) = log_size(&mut ftp) { + // The log rotates to debug.log.1 when it grows; start over from 0 then. + let from = match log_offset { + Some(o) if o <= size => o, + _ => 0, + }; + if size > from { + if let Ok(Some(new)) = ftp.retr_from(SMP_LOG, from) { + if let Some(reason) = register_failure(&String::from_utf8_lossy(&new), title_id) { + ftp.quit(); + return Ok(MountOutcome::Failed(reason)); + } + } + } + log_offset = Some(log_offset.map_or(size, |o| if o <= size { o } else { 0 })); + } + if last_nudge.elapsed() >= Duration::from_secs(30) { + last_nudge = Instant::now(); + let _ = request_scan(&mut ftp, title_id, image_remote, None); + } ftp.quit(); } std::thread::sleep(Duration::from_secs(3)); } - Ok(false) + Ok(MountOutcome::Unconfirmed) } #[cfg(test)] @@ -344,6 +433,35 @@ mod tests { assert!(upsert_hint(before, &["image_ro", "image_rw"], &names(), Some("image_ro=PPSA01234.exfat")).is_none()); } + #[test] + fn manual_status_needs_installed_title_and_path() { + let st = "installed\tPPSA01234\t/data/homebrew/PPSA01234.ffpfsc\tSample Game\ndeleted\tPPSA05678\t/data/homebrew/PPSA05678.ffpfsc\tX\n"; + assert!(manual_status_installed(st, "PPSA01234", "/data/homebrew/PPSA01234.ffpfsc")); + assert!(!manual_status_installed(st, "PPSA05678", "/data/homebrew/PPSA05678.ffpfsc")); + assert!(!manual_status_installed(st, "PPSA01234", "/data/homebrew/PPSA01234-app")); + } + + #[test] + fn spots_the_lost_hook_failure_from_the_real_log() { + // Lines as ShadowMountPlus 1.7beta4 logged them when its hook was gone. + let log = "[01:45:13] [ACTION] Installing: Super Meat Boy 3D (PPSA31162)\n\ +[01:45:17] [LINK] mount_img.lnk created: /user/app/PPSA31162/mount_img.lnk -> /data/homebrew/PPSA31162.ffpfsc layers=2\n\ +[01:45:17] [REG] internal AppInstallTitleDir bridge unavailable\n\ +[01:45:17] NOTIFY: Register failed: Super Meat Boy 3D (PPSA31162)\n"; + assert!(register_failure(log, "PPSA31162").unwrap().contains("system hook was lost")); + assert_eq!(register_failure(log, "PPSA01234"), None, "another game's failure isn't ours"); + } + + #[test] + fn other_register_failures() { + let fail = "[ACTION] Installing: G (PPSA01234)\n[REG] FAIL: 0x80990015\n"; + assert!(register_failure(fail, "PPSA01234").unwrap().contains("0x80990015")); + let gave_up = "[SKIP] mount/register retry limit reached (2/2): G (PPSA01234)\n"; + assert!(register_failure(gave_up, "PPSA01234").unwrap().contains("gave up")); + let ok = "[ACTION] Installing: G (PPSA01234)\n[REG] Installed NEW!\n"; + assert_eq!(register_failure(ok, "PPSA01234"), None); + } + #[test] fn fnv_matches_game_compressor_file_names() { // Same FNV-1a 32 Game Compressor uses for its validations/<TITLE>-<hash>.json names. diff --git a/src/lib/Focus.svelte b/src/lib/Focus.svelte index 36ed023..c1ee716 100644 --- a/src/lib/Focus.svelte +++ b/src/lib/Focus.svelte @@ -79,7 +79,7 @@ {:else} <div class="idle"> <span class="pulse"></span> - <span class="mono">Checking /user/app/{job.dump.titleId}/mount_img.lnk every 3 s</span> + <span class="mono">Waiting for ShadowMountPlus to register {job.dump.titleId}</span> </div> {/if} </div> @@ -107,7 +107,7 @@ </div> {:else if job.status === "done"} <div class="kicker ok">{job.stages[3].state === "warn" ? "Uploaded" : "Done"}</div> - <h2>{job.stages[3].state === "warn" ? "On the PS5, not mounted yet" : "Ready to play"}</h2> + <h2>{job.stages[3].state === "warn" ? "On the PS5, but not registered yet" : "Ready to play"}</h2> <dl class="stats wide"> <div><dt>Original</dt><dd class="num">{gb(job.dump.totalBytes)}</dd></div> <div><dt>Image</dt><dd class="num">{gb(job.imageBytes)}</dd></div> @@ -116,8 +116,8 @@ </dl> {#if job.stages[3].state === "warn"} <p class="desc"> - The image is on the PS5 and listed in ShadowMountPlus's manual.lst, but the mount wasn't confirmed in time. - It often appears a little later; check the game list on the PS5. + The image is on the PS5, but ShadowMountPlus hasn't registered the game. The note at the top says why. Once + you've fixed that (usually by restarting ShadowMountPlus), use Check again. </p> {/if} <div class="actions"> diff --git a/src/lib/Help.svelte b/src/lib/Help.svelte index 0066508..e843f67 100644 --- a/src/lib/Help.svelte +++ b/src/lib/Help.svelte @@ -41,6 +41,13 @@ "If it keeps failing, the dump itself may be changing or damaged. Copy it again, or check the drive it's on.", ], }, + { + q: "ShadowMountPlus couldn't register the game", + a: [ + "The image is on the PS5 and ShadowMountPlus mounted it, but it couldn't add the game to the home screen.", + "\"System hook was lost\" happens after rest mode in ShadowMountPlus 1.7beta4 and older. Update to 1.7beta5 or newer, or restart ShadowMountPlus, then use Check again.", + ], + }, { q: "Mount not confirmed", a: [ diff --git a/src/lib/Setup.svelte b/src/lib/Setup.svelte index 3984126..809e348 100644 --- a/src/lib/Setup.svelte +++ b/src/lib/Setup.svelte @@ -256,7 +256,6 @@ .req li { display: flex; gap: 10px; align-items: center; color: var(--muted); } .req li::before { content: ""; width: 12px; height: 12px; border-radius: 50%; border: 1.5px solid var(--faint); flex: none; } .tips li { border: 1px solid var(--line); border-radius: 10px; padding: 12px 14px; color: var(--muted); } - .tips b { color: var(--text); font-weight: 500; } kbd { font: 500 11px var(--mono); border: 1px solid var(--line-strong); border-radius: 4px; padding: 1px 5px; color: var(--text); } .scan { height: 2px; background: var(--line); border-radius: 2px; overflow: hidden; position: relative; margin-top: 8px; } diff --git a/tests/fake_ps5.py b/tests/fake_ps5.py index 53bbad5..f28bf93 100644 --- a/tests/fake_ps5.py +++ b/tests/fake_ps5.py @@ -11,23 +11,40 @@ cfg = os.path.join(root, "data/shadowmount/config.ini") if not os.path.exists(cfg): open(cfg, "w").write("# ShadowMountPlus\nmount_read_only=1\nimage_ro=OTHER.exfat\n") open(os.path.join(root, "data/shadowmount/autotune.ini"), "w").write("image_sector=PPSA00001.ffpfsc:4096\n") + open(os.path.join(root, "data/shadowmount/debug.log"), "w").write("[00:00:00] ShadowMount+ (fake)\n") def fake_smp(): + """Mimics ShadowMountPlus 1.7: link files first, then registration, then manual.status. + + Create data/shadowmount/.broken-hook to reproduce a lost ShellCore hook: the link files + are written but registration fails, so manual.status never says "installed". + """ + smp = os.path.join(root, "data/shadowmount") hb = os.path.join(root, "data/homebrew") + done = set() while True: - # Like the real one in practice: new images are only picked up once manual.lst lists them. try: - listed = open(os.path.join(root, "data/shadowmount/manual.lst")).read().split() + listed = open(os.path.join(smp, "manual.lst")).read().split() except FileNotFoundError: listed = [] for n in os.listdir(hb): - if n.endswith(".ffpfsc") and not n.startswith(".") and f"/data/homebrew/{n}" in listed: - tid = n[:9] - d = os.path.join(root, "user/app", tid); os.makedirs(d, exist_ok=True) - lnk = os.path.join(d, "mount_img.lnk") - if not os.path.exists(lnk): - time.sleep(4) - open(lnk, "w").write(f"/data/homebrew/{n}\n/mnt/shadowmnt/pfsc/{tid}_deadbeef/{tid}.exfat\n") + path = f"/data/homebrew/{n}" + if not n.endswith(".ffpfsc") or n.startswith(".") or path not in listed or path in done: + continue + done.add(path) + tid = n[:9] + time.sleep(4) + d = os.path.join(root, "user/app", tid); os.makedirs(d, exist_ok=True) + open(os.path.join(d, "mount_img.lnk"), "w").write(f"{path}\n/mnt/shadowmnt/pfsc/{tid}_deadbeef/{tid}.exfat\n") + with open(os.path.join(smp, "debug.log"), "a") as log: + log.write(f"[00:00:00] [ACTION] Installing: Test Game ({tid})\n") + if os.path.exists(os.path.join(smp, ".broken-hook")): + log.write("[00:00:04] [REG] internal AppInstallTitleDir bridge unavailable\n") + log.write(f"[00:00:04] NOTIFY: Register failed: Test Game ({tid})\n") + continue + log.write("[00:00:04] [REG] Installed NEW!\n") + with open(os.path.join(smp, "manual.status"), "a") as st: + st.write(f"installed\t{tid}\t{path}\tTest Game\n") time.sleep(1) threading.Thread(target=fake_smp, daemon=True).start()