Detect failed ShadowMountPlus registration

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

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<Option<Vec<u8>>, 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<Option<Vec<u8>>, 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);

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(&param).unwrap().replace("PPSA00001", "PPSA00002");
+        std::fs::write(&param, 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");
     }
 }

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/<TITLE>/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.

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">

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

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; }

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