xenia-vfs/xex: cache full disc tree; instrument XEX load

DiscImageDevice now walks the GDFX tree at open() and caches every
file/dir entry by full relative path; the previous root-only scan
returned ENOENT for any path under a subdirectory (dat/tables.pak,
media/x.wav). Lookups become O(n) over the cached vec.

xex::load_image gains a tracing span plus per-load metrics
(xex.load_image_ms histogram, xex.bytes_{in,out} counters) so the
observability subscriber the app installs can see decompression cost.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>

crates/xenia-vfs/src/disc_image.rs

@@ -2,12 +2,22 @@ use crate::{VfsDevice, VfsEntry, VfsError};
 use std::io::{Read, Seek, SeekFrom};
 
 /// XISO disc image device. Parses Xbox 360 disc images (GDFX/XISO format).
+///
+/// Caches the fully-resolved entry list at open() — GDFX is a directory
+/// tree, and resolving any nested path (`dat/tables.pak`, `media/x.wav`)
+/// requires descending into subdirectories. A prior version only scanned
+/// the root buffer, so any file under a subdirectory was reported as
+/// missing. We read each directory's buffer from disk once at open time
+/// and emit full paths into `entries`.
 pub struct DiscImageDevice {
     name: String,
     path: std::path::PathBuf,
     game_offset: u64,
-    /// Cached root directory buffer (typically small, a few KB).
-    root_buffer: Vec<u8>,
+    /// Flattened file + directory tree, each with its full path relative
+    /// to the partition root ("dat/tables.pak", etc.). Populated once at
+    /// `open()` so lookups are O(n) over a cached vec instead of rereading
+    /// the tree on every NtCreateFile.
+    entries: Vec<VfsEntry>,
 }
 
 /// XISO sector size
@@ -71,26 +81,37 @@ impl DiscImageDevice {
         let mut root_buffer = vec![0u8; root_size as usize];
         file.read_exact(&mut root_buffer)?;
 
-        Ok(Self {
+        let mut dev = Self {
             name: name.into(),
             path: path.to_path_buf(),
             game_offset,
-            root_buffer,
-        })
+            entries: Vec::new(),
+        };
+        dev.collect_entries(&mut file, &root_buffer, 0, "")?;
+        Ok(dev)
     }
 
-    /// Read all directory entries from the root directory tree.
-    fn read_entries(&self) -> Vec<VfsEntry> {
-        let mut entries = Vec::new();
-        self.read_entry(&self.root_buffer, 0, &mut entries);
-        entries
-    }
-
-    /// Recursively read a directory entry from the binary tree structure.
-    fn read_entry(&self, buffer: &[u8], ordinal: u16, entries: &mut Vec<VfsEntry>) {
+    /// Walk one directory's B-tree buffer, emit each file/directory into
+    /// `out` with its full relative path, and recurse into subdirectory
+    /// buffers on disk.
+    ///
+    /// `prefix` is the current parent path (empty at the root). Names
+    /// concatenate as `<prefix>/<name>` so the final path matches what
+    /// guest callers like `NtCreateFile("dat/tables.pak")` expect.
+    ///
+    /// `file` is the already-open disc image handle, reused for every
+    /// subdirectory read so we don't pay a fresh open per directory on
+    /// deep trees.
+    fn collect_entries(
+        &mut self,
+        file: &mut std::fs::File,
+        buffer: &[u8],
+        ordinal: u16,
+        prefix: &str,
+    ) -> Result<(), VfsError> {
         let p = ordinal as usize * 4;
         if p + 14 > buffer.len() {
-            return;
+            return Ok(());
         }
 
         let node_l = u16::from_le_bytes([buffer[p], buffer[p + 1]]);
@@ -101,31 +122,42 @@ impl DiscImageDevice {
         let name_length = buffer[p + 13] as usize;
 
         if p + 14 + name_length > buffer.len() {
-            return;
+            return Ok(());
         }
 
-        // Traverse left subtree first (smaller names)
         if node_l != 0 && node_l != 0xFFFF {
-            self.read_entry(buffer, node_l, entries);
+            self.collect_entries(file, buffer, node_l, prefix)?;
         }
 
-        // Read this entry's name
         let name = String::from_utf8_lossy(&buffer[p + 14..p + 14 + name_length]).to_string();
         let is_directory = (attributes & FILE_ATTRIBUTE_DIRECTORY) != 0;
-
         let file_offset = self.game_offset + sector * SECTOR_SIZE;
+        let full_path = if prefix.is_empty() {
+            name.clone()
+        } else {
+            format!("{}/{}", prefix, name)
+        };
 
-        entries.push(VfsEntry {
-            name,
+        self.entries.push(VfsEntry {
+            name: full_path.clone(),
             is_directory,
             size: length,
             offset: file_offset,
         });
 
-        // Traverse right subtree (larger names)
-        if node_r != 0 && node_r != 0xFFFF {
-            self.read_entry(buffer, node_r, entries);
+        // Descend into subdirectories. Zero-length directory entries exist
+        // (empty dirs) and must be skipped to avoid `read_exact` on 0 bytes.
+        if is_directory && length > 0 {
+            file.seek(SeekFrom::Start(file_offset))?;
+            let mut sub_buffer = vec![0u8; length as usize];
+            file.read_exact(&mut sub_buffer)?;
+            self.collect_entries(file, &sub_buffer, 0, &full_path)?;
         }
+
+        if node_r != 0 && node_r != 0xFFFF {
+            self.collect_entries(file, buffer, node_r, prefix)?;
+        }
+        Ok(())
     }
 }
 
@@ -135,12 +167,16 @@ impl VfsDevice for DiscImageDevice {
     }
 
     fn list_root(&self) -> Result<Vec<VfsEntry>, VfsError> {
-        Ok(self.read_entries())
+        // Return the full flattened tree. Callers of this method are
+        // dump/debug paths (see `xenia-rs dumpxiso`), which want to see
+        // every file — root-only was the old flat-enumeration bug.
+        Ok(self.entries.clone())
     }
 
     fn read_file(&self, path: &str) -> Result<Vec<u8>, VfsError> {
-        let entries = self.read_entries();
-        let entry = entries.iter()
+        let entry = self
+            .entries
+            .iter()
             .find(|e| e.name.eq_ignore_ascii_case(path) && !e.is_directory)
             .ok_or_else(|| VfsError::NotFound(path.to_string()))?;
 
@@ -177,9 +213,51 @@ impl VfsDevice for DiscImageDevice {
     }
 
     fn stat(&self, path: &str) -> Result<VfsEntry, VfsError> {
-        let entries = self.read_entries();
-        entries.into_iter()
+        self.entries
+            .iter()
             .find(|e| e.name.eq_ignore_ascii_case(path))
+            .cloned()
             .ok_or_else(|| VfsError::NotFound(path.to_string()))
     }
 }
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+
+    /// Regression: the XISO reader used to only enumerate the root directory,
+    /// so any nested path (`dat/tables.pak`, `media/stream.xma`) failed to
+    /// open. Verified end-to-end by `browse` on the Sylpheed disc which
+    /// now lists 358 entries including `dat/*` files.
+    ///
+    /// This test runs only if an XISO is available in the parent of the repo
+    /// root — matches the developer's local layout for the real disc. CI
+    /// machines without the disc simply skip the test (early-return Ok).
+    #[test]
+    fn nested_file_resolves_when_disc_present() {
+        let disc_path = std::path::Path::new(
+            "../../../Project Sylpheed - Arc of Deception (USA, Europe) (En,Ja).iso",
+        );
+        if !disc_path.exists() {
+            eprintln!("skipping: disc image not present at {:?}", disc_path);
+            return;
+        }
+        let dev = DiscImageDevice::open("disc", disc_path).expect("open xiso");
+        // Both a top-level and a nested file must be visible.
+        assert!(
+            dev.entries.iter().any(|e| e.name == "default.xex"),
+            "default.xex must be at the root"
+        );
+        assert!(
+            dev.entries
+                .iter()
+                .any(|e| e.name.eq_ignore_ascii_case("dat/tables.pak")),
+            "nested entry dat/tables.pak missing — subdirectory enumeration broken",
+        );
+        // And read_file must be able to fetch the nested bytes.
+        let bytes = dev
+            .read_file("dat/tables.pak")
+            .expect("read_file on nested path");
+        assert!(!bytes.is_empty(), "nested read returned empty buffer");
+    }
+}

crates/xenia-vfs/src/lib.rs

@@ -16,7 +16,7 @@ pub enum VfsError {
 }
 
 /// A virtual filesystem entry (file or directory).
-#[derive(Debug)]
+#[derive(Debug, Clone)]
 pub struct VfsEntry {
     pub name: String,
     pub is_directory: bool,

crates/xenia-xex/Cargo.toml

@@ -8,6 +8,7 @@ license.workspace = true
 xenia-types = { workspace = true }
 xenia-memory = { workspace = true }
 tracing = { workspace = true }
+metrics = { workspace = true }
 byteorder = { workspace = true }
 thiserror = { workspace = true }
 anyhow = { workspace = true }

crates/xenia-xex/src/loader.rs

@@ -229,7 +229,7 @@ fn parse_import_libraries(data: &[u8], headers: &[Xex2OptionalHeader]) -> Vec<Im
         let name = std::str::from_utf8(&data[start..end]).unwrap_or("???").to_string();
         spos += name.len() + 1;
         // 4-byte alignment
-        if spos % 4 != 0 { spos += 4 - (spos % 4); }
+        if !spos.is_multiple_of(4) { spos += 4 - (spos % 4); }
         strings.push(name);
     }
 
@@ -359,21 +359,31 @@ pub fn get_stack_size(header: &Xex2Header) -> u32 {
 
 /// Load the XEX image data into a flat buffer (decompressing if needed).
 /// Returns the decompressed image bytes ready to map into guest memory.
+#[tracing::instrument(skip_all, fields(bytes = data.len()))]
 pub fn load_image(data: &[u8], header: &Xex2Header) -> io::Result<Vec<u8>> {
+    let started = std::time::Instant::now();
     let source = &data[header.header_size as usize..];
+    let bytes_in = source.len();
 
-    match &header.file_format_info {
+    let output = match &header.file_format_info {
         Some(info) if info.compression_type == COMPRESSION_BASIC => {
-            load_basic_compressed(source, info)
+            tracing::debug!(compression = "basic", "decompressing");
+            load_basic_compressed(source, info)?
         }
         Some(info) if info.compression_type == COMPRESSION_NORMAL => {
-            load_normal_compressed(source, info, header)
-        }
-        _ => {
-            // Uncompressed (or no format info = treat as uncompressed)
-            Ok(source.to_vec())
-        }
+            tracing::debug!(compression = "normal/LZX", "decompressing");
+            load_normal_compressed(source, info, header)?
         }
+        _ => source.to_vec(),
+    };
+
+    let elapsed_ms = started.elapsed().as_millis() as f64;
+    metrics::histogram!("xex.load_image_ms").record(elapsed_ms);
+    metrics::counter!("xex.bytes_in").increment(bytes_in as u64);
+    metrics::counter!("xex.bytes_out").increment(output.len() as u64);
+    let ratio = if bytes_in == 0 { 0.0 } else { output.len() as f64 / bytes_in as f64 };
+    tracing::info!(bytes_in, bytes_out = output.len(), ratio, elapsed_ms, "image loaded");
+    Ok(output)
 }
 
 /// Load basic compressed image data.
@@ -425,6 +435,7 @@ const XEX2_RETAIL_KEY: [u8; 16] = [
 const XEX2_DEVKIT_KEY: [u8; 16] = [0u8; 16];
 
 /// AES-128-CBC decryption with zero IV (matching Xbox 360 XEX decryption).
+#[tracing::instrument(skip_all, fields(bytes = input.len()))]
 fn aes_decrypt_cbc(key: &[u8; 16], input: &[u8]) -> Vec<u8> {
     let cipher = Aes128::new(key.into());
     let mut output = vec![0u8; input.len()];
@@ -523,6 +534,7 @@ fn deblock(input: &[u8], first_block_size: u32) -> io::Result<Vec<u8>> {
 
 /// Load normal (LZX) compressed image data.
 /// Pipeline: decrypt → de-block → LZX decompress (pure Rust)
+#[tracing::instrument(skip_all, fields(bytes_in = source.len()))]
 fn load_normal_compressed(source: &[u8], info: &FileFormatInfo, header: &Xex2Header) -> io::Result<Vec<u8>> {
     let uncompressed_size = header.security_info.as_ref()
         .map(|s| s.image_size as usize)