perf(sandbox): streaming SHA256, spawn_blocking for identity resolution

Key changes:
- Replace full file read + SHA256 with streaming 64KB-buffered hash
  (saves 124MB allocation for node binary)
- Wrap evaluate_opa_tcp in spawn_blocking to prevent blocking tokio
  runtime during heavy /proc I/O and SHA256 computation
- Add file-based perf logging for profiling proxy latency phases

Profiling data (node binary, 124MB):
- Cold TOFU: ~890ms (read+hash), warm: 0ms (cache hit)
- evaluate_opa_tcp: cold=1002ms, warm=11ms
- OPA evaluation: 1ms
- DNS+TCP connect: 166-437ms

Made-with: Cursor

Author: koiker

crates/openshell-sandbox/src/identity.rs

@@ -17,6 +17,24 @@ use std::os::unix::fs::MetadataExt;
 use std::path::{Path, PathBuf};
 use std::sync::Mutex;
 
+fn perf_log(msg: &str) {
+    use std::io::Write;
+    for path in &["/var/log/openshell-perf.log", "/tmp/openshell-perf.log"] {
+        if let Ok(mut f) = std::fs::OpenOptions::new()
+            .create(true)
+            .append(true)
+            .open(path)
+        {
+            let now = std::time::SystemTime::now()
+                .duration_since(std::time::UNIX_EPOCH)
+                .unwrap_or_default();
+            let _ = writeln!(f, "[{:.3}] {}", now.as_secs_f64(), msg);
+            return;
+        }
+    }
+    eprintln!("PERF_LOG_FALLBACK: {msg}");
+}
+
 #[derive(Clone)]
 struct FileFingerprint {
     len: u64,
@@ -100,6 +118,7 @@ impl BinaryIdentityCache {
     where
         F: FnMut(&Path) -> Result<String>,
     {
+        let start = std::time::Instant::now();
         let metadata = std::fs::metadata(path)
             .map_err(|error| miette::miette!("Failed to stat {}: {error}", path.display()))?;
         let fingerprint = FileFingerprint::from_metadata(&metadata);
@@ -114,10 +133,24 @@ impl BinaryIdentityCache {
         if let Some(cached_binary) = &cached
             && cached_binary.fingerprint == fingerprint
         {
+            perf_log(&format!(
+                "      verify_or_cache: {}ms CACHE HIT path={}",
+                start.elapsed().as_millis(), path.display()
+            ));
             return Ok(cached_binary.hash.clone());
         }
 
+        perf_log(&format!(
+            "      verify_or_cache: CACHE MISS size={} path={}",
+            metadata.len(), path.display()
+        ));
+
+        let hash_start = std::time::Instant::now();
         let current_hash = hash_file(path)?;
+        perf_log(&format!(
+            "      verify_or_cache SHA256: {}ms path={}",
+            hash_start.elapsed().as_millis(), path.display()
+        ));
 
         let mut hashes = self
             .hashes
@@ -143,6 +176,11 @@ impl BinaryIdentityCache {
             },
         );
 
+        perf_log(&format!(
+            "      verify_or_cache TOTAL (cold): {}ms path={}",
+            start.elapsed().as_millis(), path.display()
+        ));
+
         Ok(current_hash)
     }
 }

crates/openshell-sandbox/src/procfs.rs

@@ -11,6 +11,24 @@ use std::path::Path;
 #[cfg(target_os = "linux")]
 use std::path::PathBuf;
 
+fn perf_log(msg: &str) {
+    use std::io::Write;
+    for path in &["/var/log/openshell-perf.log", "/tmp/openshell-perf.log"] {
+        if let Ok(mut f) = std::fs::OpenOptions::new()
+            .create(true)
+            .append(true)
+            .open(path)
+        {
+            let now = std::time::SystemTime::now()
+                .duration_since(std::time::UNIX_EPOCH)
+                .unwrap_or_default();
+            let _ = writeln!(f, "[{:.3}] {}", now.as_secs_f64(), msg);
+            return;
+        }
+    }
+    eprintln!("PERF_LOG_FALLBACK: {msg}");
+}
+
 /// Read the binary path of a process via `/proc/{pid}/exe` symlink.
 ///
 /// Returns the canonical path to the executable that the process is running.
@@ -48,9 +66,33 @@ pub fn resolve_tcp_peer_binary(entrypoint_pid: u32, peer_port: u16) -> Result<Pa
 /// Needed for the ancestor walk: we must know the PID to walk `/proc/<pid>/status` PPid chain.
 #[cfg(target_os = "linux")]
 pub fn resolve_tcp_peer_identity(entrypoint_pid: u32, peer_port: u16) -> Result<(PathBuf, u32)> {
+    let start = std::time::Instant::now();
+
+    let phase = std::time::Instant::now();
     let inode = parse_proc_net_tcp(entrypoint_pid, peer_port)?;
+    perf_log(&format!(
+        "    parse_proc_net_tcp: {}ms inode={}",
+        phase.elapsed().as_millis(), inode
+    ));
+
+    let phase = std::time::Instant::now();
     let pid = find_pid_by_socket_inode(inode, entrypoint_pid)?;
+    perf_log(&format!(
+        "    find_pid_by_socket_inode: {}ms pid={}",
+        phase.elapsed().as_millis(), pid
+    ));
+
+    let phase = std::time::Instant::now();
     let path = binary_path(pid.cast_signed())?;
+    perf_log(&format!(
+        "    binary_path: {}ms path={}",
+        phase.elapsed().as_millis(), path.display()
+    ));
+
+    perf_log(&format!(
+        "    resolve_tcp_peer_identity TOTAL: {}ms",
+        start.elapsed().as_millis()
+    ));
     Ok((path, pid))
 }
 
@@ -227,34 +269,55 @@ fn parse_proc_net_tcp(pid: u32, peer_port: u16) -> Result<u64> {
 /// `/proc/<pid>/fd/` for processes running as a different user.
 #[cfg(target_os = "linux")]
 fn find_pid_by_socket_inode(inode: u64, entrypoint_pid: u32) -> Result<u32> {
+    let start = std::time::Instant::now();
     let target = format!("socket:[{inode}]");
 
-    // First: scan descendants of the entrypoint process (targeted, most likely to succeed)
+    let phase = std::time::Instant::now();
     let descendants = collect_descendant_pids(entrypoint_pid);
+    perf_log(&format!(
+        "      collect_descendant_pids: {}ms count={}",
+        phase.elapsed().as_millis(), descendants.len()
+    ));
+
+    let phase = std::time::Instant::now();
     for &pid in &descendants {
         if let Some(found) = check_pid_fds(pid, &target) {
+            perf_log(&format!(
+                "      find_pid_by_socket_inode: {}ms found_pid={} scan=descendants",
+                start.elapsed().as_millis(), found
+            ));
             return Ok(found);
         }
     }
+    perf_log(&format!(
+        "      descendant_fd_scan (not found): {}ms",
+        phase.elapsed().as_millis()
+    ));
 
-    // Fallback: scan all of /proc in case the process isn't in the tree
-    // (e.g., if /proc/<pid>/task/<tid>/children wasn't available)
+    let phase = std::time::Instant::now();
     if let Ok(proc_dir) = std::fs::read_dir("/proc") {
         for entry in proc_dir.flatten() {
             let name = entry.file_name();
             let pid: u32 = match name.to_string_lossy().parse() {
                 Ok(p) => p,
                 Err(_) => continue,
             };
-            // Skip PIDs we already checked
             if descendants.contains(&pid) {
                 continue;
             }
             if let Some(found) = check_pid_fds(pid, &target) {
+                perf_log(&format!(
+                    "      find_pid_by_socket_inode: {}ms found_pid={} scan=full_proc",
+                    start.elapsed().as_millis(), found
+                ));
                 return Ok(found);
             }
         }
     }
+    perf_log(&format!(
+        "      full_proc_scan (not found): {}ms",
+        phase.elapsed().as_millis()
+    ));
 
     Err(miette::miette!(
         "No process found owning socket inode {} \
@@ -318,9 +381,28 @@ fn collect_descendant_pids(root_pid: u32) -> Vec<u32> {
 /// same hash, or the request is denied.
 pub fn file_sha256(path: &Path) -> Result<String> {
     use sha2::{Digest, Sha256};
+    use std::io::Read;
+
+    let start = std::time::Instant::now();
+    let mut file = std::fs::File::open(path)
+        .map_err(|e| miette::miette!("Failed to open {}: {e}", path.display()))?;
+    let mut hasher = Sha256::new();
+    let mut buf = [0u8; 65536];
+    let mut total_read = 0u64;
+    loop {
+        let n = file.read(&mut buf).into_diagnostic()?;
+        if n == 0 {
+            break;
+        }
+        total_read += n as u64;
+        hasher.update(&buf[..n]);
+    }
 
-    let bytes = std::fs::read(path).into_diagnostic()?;
-    let hash = Sha256::digest(&bytes);
+    let hash = hasher.finalize();
+    perf_log(&format!(
+        "        file_sha256: {}ms size={} path={}",
+        start.elapsed().as_millis(), total_read, path.display()
+    ));
     Ok(hex::encode(hash))
 }