perf: improve startup instrumentation and replace npx with npm install (#208)

Add comprehensive tracing instrumentation across the entire agent startup path (gigacode CLI, ACP HTTP adapter, agent installation, and process spawning) to enable detailed performance profiling. Replace npm-based agent process launchers that use npx (incurring resolution overhead on every spawn) with pre-installed npm packages, reducing startup latency. Improve error diagnostics when agent processes crash by capturing exit codes and stderr tails. Update error handling to map exited processes to dedicated error variants with actionable error messages.

Co-authored-by: Claude Haiku 4.5 <noreply@anthropic.com>

gigacode/src/main.rs

@@ -11,6 +11,7 @@ fn main() {
 }
 
 fn run() -> Result<(), CliError> {
+    let started = std::time::Instant::now();
     let cli = GigacodeCli::parse();
     let config = CliConfig {
         token: cli.token,
@@ -34,5 +35,18 @@ fn run() -> Result<(), CliError> {
         eprintln!("failed to init logging: {err}");
         return Err(err);
     }
-    run_command(&command, &config)
+    tracing::info!(
+        command = ?command,
+        startup_ms = started.elapsed().as_millis() as u64,
+        "gigacode.run: command starting"
+    );
+    let command_started = std::time::Instant::now();
+    let result = run_command(&command, &config);
+    tracing::info!(
+        command = ?command,
+        command_ms = command_started.elapsed().as_millis() as u64,
+        total_ms = started.elapsed().as_millis() as u64,
+        "gigacode.run: command exited"
+    );
+    result
 }

server/packages/acp-http-adapter/src/app.rs

@@ -93,6 +93,20 @@ fn map_error(err: AdapterError) -> Response {
             "timeout",
             "timed out waiting for agent response",
         ),
+        AdapterError::Exited { exit_code, stderr } => {
+            let detail = if let Some(stderr) = stderr {
+                format!(
+                    "agent process exited before responding (exit_code: {:?}, stderr: {})",
+                    exit_code, stderr
+                )
+            } else {
+                format!(
+                    "agent process exited before responding (exit_code: {:?})",
+                    exit_code
+                )
+            };
+            problem(StatusCode::BAD_GATEWAY, "agent_exited", &detail)
+        }
         AdapterError::Write(write) => problem(
             StatusCode::BAD_GATEWAY,
             "write_failed",

server/packages/acp-http-adapter/src/main.rs

@@ -32,6 +32,7 @@ async fn main() {
 }
 
 async fn run() -> Result<(), Box<dyn std::error::Error + Send + Sync>> {
+    let started = std::time::Instant::now();
     tracing_subscriber::fmt()
         .with_env_filter(
             tracing_subscriber::EnvFilter::try_from_default_env()
@@ -41,6 +42,12 @@ async fn run() -> Result<(), Box<dyn std::error::Error + Send + Sync>> {
         .init();
 
     let cli = Cli::parse();
+    tracing::info!(
+        host = %cli.host,
+        port = cli.port,
+        startup_ms = started.elapsed().as_millis() as u64,
+        "acp-http-adapter.run: starting server"
+    );
     run_server(ServerConfig {
         host: cli.host,
         port: cli.port,

server/packages/acp-http-adapter/src/process.rs

@@ -16,6 +16,7 @@ use tokio_stream::wrappers::BroadcastStream;
 use crate::registry::LaunchSpec;
 
 const RING_BUFFER_SIZE: usize = 1024;
+const STDERR_TAIL_SIZE: usize = 16;
 
 #[derive(Debug, Error)]
 pub enum AdapterError {
@@ -33,6 +34,11 @@ pub enum AdapterError {
     Serialize(serde_json::Error),
     #[error("failed to write subprocess stdin: {0}")]
     Write(std::io::Error),
+    #[error("agent process exited before responding")]
+    Exited {
+        exit_code: Option<i32>,
+        stderr: Option<String>,
+    },
     #[error("timeout waiting for response")]
     Timeout,
 }
@@ -61,6 +67,7 @@ pub struct AdapterRuntime {
     shutting_down: AtomicBool,
     spawned_at: Instant,
     first_stdout: Arc<AtomicBool>,
+    stderr_tail: Arc<Mutex<VecDeque<String>>>,
 }
 
 impl AdapterRuntime {
@@ -120,6 +127,7 @@ impl AdapterRuntime {
             shutting_down: AtomicBool::new(false),
             spawned_at: spawn_start,
             first_stdout: Arc::new(AtomicBool::new(false)),
+            stderr_tail: Arc::new(Mutex::new(VecDeque::with_capacity(STDERR_TAIL_SIZE))),
         };
 
         runtime.spawn_stdout_loop(stdout);
@@ -198,6 +206,16 @@ impl AdapterRuntime {
                         "post: response channel dropped (agent process may have exited)"
                     );
                     self.pending.lock().await.remove(&key);
+                    if let Some((exit_code, stderr)) = self.try_process_exit_info().await {
+                        tracing::error!(
+                            method = %method,
+                            id = %key,
+                            exit_code = ?exit_code,
+                            stderr = ?stderr,
+                            "post: agent process exited before response channel completed"
+                        );
+                        return Err(AdapterError::Exited { exit_code, stderr });
+                    }
                     Err(AdapterError::Timeout)
                 }
                 Err(_) => {
@@ -213,6 +231,16 @@ impl AdapterRuntime {
                         "post: TIMEOUT waiting for agent response"
                     );
                     self.pending.lock().await.remove(&key);
+                    if let Some((exit_code, stderr)) = self.try_process_exit_info().await {
+                        tracing::error!(
+                            method = %method,
+                            id = %key,
+                            exit_code = ?exit_code,
+                            stderr = ?stderr,
+                            "post: agent process exited before timeout completed"
+                        );
+                        return Err(AdapterError::Exited { exit_code, stderr });
+                    }
                     Err(AdapterError::Timeout)
                 }
             }
@@ -445,6 +473,7 @@ impl AdapterRuntime {
 
     fn spawn_stderr_loop(&self, stderr: tokio::process::ChildStderr) {
         let spawned_at = self.spawned_at;
+        let stderr_tail = self.stderr_tail.clone();
 
         tokio::spawn(async move {
             let mut lines = BufReader::new(stderr).lines();
@@ -452,6 +481,13 @@ impl AdapterRuntime {
 
             while let Ok(Some(line)) = lines.next_line().await {
                 line_count += 1;
+                {
+                    let mut tail = stderr_tail.lock().await;
+                    tail.push_back(line.clone());
+                    while tail.len() > STDERR_TAIL_SIZE {
+                        tail.pop_front();
+                    }
+                }
                 tracing::info!(
                     line_number = line_count,
                     age_ms = spawned_at.elapsed().as_millis() as u64,
@@ -560,6 +596,28 @@ impl AdapterRuntime {
         tracing::debug!(method = method, id = %id, "stdin: write+flush complete");
         Ok(())
     }
+
+    async fn try_process_exit_info(&self) -> Option<(Option<i32>, Option<String>)> {
+        let mut child = self.child.lock().await;
+        match child.try_wait() {
+            Ok(Some(status)) => {
+                let exit_code = status.code();
+                drop(child);
+                let stderr = self.stderr_tail_summary().await;
+                Some((exit_code, stderr))
+            }
+            Ok(None) => None,
+            Err(_) => None,
+        }
+    }
+
+    async fn stderr_tail_summary(&self) -> Option<String> {
+        let tail = self.stderr_tail.lock().await;
+        if tail.is_empty() {
+            return None;
+        }
+        Some(tail.iter().cloned().collect::<Vec<_>>().join("\n"))
+    }
 }
 
 fn id_key(value: &Value) -> String {

server/packages/agent-management/Cargo.toml

@@ -20,3 +20,4 @@ url.workspace = true
 dirs.workspace = true
 tempfile.workspace = true
 time.workspace = true
+tracing.workspace = true

server/packages/agent-management/src/agents.rs

@@ -4,6 +4,7 @@ use std::fs;
 use std::io::{self, Read};
 use std::path::{Path, PathBuf};
 use std::process::{Command, Stdio};
+use std::time::Instant;
 
 use flate2::read::GzDecoder;
 use reqwest::blocking::Client;
@@ -321,6 +322,14 @@ impl AgentManager {
         agent: AgentId,
         options: InstallOptions,
     ) -> Result<InstallResult, AgentError> {
+        let install_started = Instant::now();
+        tracing::info!(
+            agent = agent.as_str(),
+            reinstall = options.reinstall,
+            native_version = ?options.version,
+            agent_process_version = ?options.agent_process_version,
+            "agent_manager.install: starting"
+        );
         fs::create_dir_all(&self.install_dir)?;
         fs::create_dir_all(self.install_dir.join("agent_processes"))?;
 
@@ -345,10 +354,20 @@ impl AgentManager {
             artifacts.push(artifact);
         }
 
-        Ok(InstallResult {
+        let result = InstallResult {
             artifacts,
             already_installed,
-        })
+        };
+
+        tracing::info!(
+            agent = agent.as_str(),
+            already_installed = result.already_installed,
+            artifact_count = result.artifacts.len(),
+            total_ms = elapsed_ms(install_started),
+            "agent_manager.install: completed"
+        );
+
+        Ok(result)
     }
 
     pub fn is_installed(&self, agent: AgentId) -> bool {
@@ -392,25 +411,41 @@ impl AgentManager {
         &self,
         agent: AgentId,
     ) -> Result<AgentProcessLaunchSpec, AgentError> {
+        let started = Instant::now();
         if agent == AgentId::Mock {
-            return Ok(AgentProcessLaunchSpec {
+            let spec = AgentProcessLaunchSpec {
                 program: self.agent_process_path(agent),
                 args: Vec::new(),
                 env: HashMap::new(),
                 source: InstallSource::Builtin,
                 version: Some("builtin".to_string()),
-            });
+            };
+            tracing::info!(
+                agent = agent.as_str(),
+                source = ?spec.source,
+                total_ms = elapsed_ms(started),
+                "agent_manager.resolve_agent_process: resolved builtin"
+            );
+            return Ok(spec);
         }
 
         let launcher = self.agent_process_path(agent);
         if launcher.exists() {
-            return Ok(AgentProcessLaunchSpec {
+            let spec = AgentProcessLaunchSpec {
                 program: launcher,
                 args: Vec::new(),
                 env: HashMap::new(),
                 source: InstallSource::LocalPath,
                 version: None,
-            });
+            };
+            tracing::info!(
+                agent = agent.as_str(),
+                source = ?spec.source,
+                program = %spec.program.display(),
+                total_ms = elapsed_ms(started),
+                "agent_manager.resolve_agent_process: resolved local launcher"
+            );
+            return Ok(spec);
         }
 
         if let Some(bin) = agent.agent_process_binary_hint().and_then(find_in_path) {
@@ -419,29 +454,47 @@ impl AgentManager {
             } else {
                 Vec::new()
             };
-            return Ok(AgentProcessLaunchSpec {
+            let spec = AgentProcessLaunchSpec {
                 program: bin,
                 args,
                 env: HashMap::new(),
                 source: InstallSource::LocalPath,
                 version: None,
-            });
+            };
+            tracing::info!(
+                agent = agent.as_str(),
+                source = ?spec.source,
+                program = %spec.program.display(),
+                args = ?spec.args,
+                total_ms = elapsed_ms(started),
+                "agent_manager.resolve_agent_process: resolved PATH binary hint"
+            );
+            return Ok(spec);
         }
 
         if agent == AgentId::Opencode {
             let native = self.resolve_binary(agent)?;
-            return Ok(AgentProcessLaunchSpec {
+            let spec = AgentProcessLaunchSpec {
                 program: native,
                 args: vec!["acp".to_string()],
                 env: HashMap::new(),
                 source: InstallSource::LocalPath,
                 version: None,
-            });
+            };
+            tracing::info!(
+                agent = agent.as_str(),
+                source = ?spec.source,
+                program = %spec.program.display(),
+                args = ?spec.args,
+                total_ms = elapsed_ms(started),
+                "agent_manager.resolve_agent_process: resolved opencode native"
+            );
+            return Ok(spec);
         }
 
         Err(AgentError::AgentProcessNotFound {
             agent,
-            hint: Some("run install to provision ACP agent process".to_string()),
+            hint: Some(format!("run step 3: `sandbox-agent install-agent {agent}`")),
         })
     }
 
@@ -454,11 +507,23 @@ impl AgentManager {
         agent: AgentId,
         options: &InstallOptions,
     ) -> Result<Option<InstalledArtifact>, AgentError> {
+        let started = Instant::now();
         if !options.reinstall && self.native_installed(agent) {
+            tracing::info!(
+                agent = agent.as_str(),
+                total_ms = elapsed_ms(started),
+                "agent_manager.install_native: already installed"
+            );
             return Ok(None);
         }
 
         let path = self.binary_path(agent);
+        tracing::info!(
+            agent = agent.as_str(),
+            path = %path.display(),
+            version_override = ?options.version,
+            "agent_manager.install_native: installing"
+        );
         match agent {
             AgentId::Claude => install_claude(&path, self.platform, options.version.as_deref())?,
             AgentId::Codex => install_codex(&path, self.platform, options.version.as_deref())?,
@@ -474,12 +539,22 @@ impl AgentManager {
             }
         }
 
-        Ok(Some(InstalledArtifact {
+        let artifact = InstalledArtifact {
             kind: InstalledArtifactKind::NativeAgent,
             path,
             version: self.version(agent).ok().flatten(),
             source: InstallSource::Fallback,
-        }))
+        };
+
+        tracing::info!(
+            agent = agent.as_str(),
+            source = ?artifact.source,
+            version = ?artifact.version,
+            total_ms = elapsed_ms(started),
+            "agent_manager.install_native: completed"
+        );
+
+        Ok(Some(artifact))
     }
 
     fn install_agent_process(
@@ -487,8 +562,14 @@ impl AgentManager {
         agent: AgentId,
         options: &InstallOptions,
     ) -> Result<Option<InstalledArtifact>, AgentError> {
+        let started = Instant::now();
         if !options.reinstall {
             if self.agent_process_status(agent).is_some() {
+                tracing::info!(
+                    agent = agent.as_str(),
+                    total_ms = elapsed_ms(started),
+                    "agent_manager.install_agent_process: already installed"
+                );
                 return Ok(None);
             }
         }
@@ -496,22 +577,104 @@ impl AgentManager {
         if agent == AgentId::Mock {
             let path = self.agent_process_path(agent);
             write_mock_agent_process_launcher(&path)?;
-            return Ok(Some(InstalledArtifact {
+            let artifact = InstalledArtifact {
                 kind: InstalledArtifactKind::AgentProcess,
                 path,
                 version: Some("builtin".to_string()),
                 source: InstallSource::Builtin,
-            }));
+            };
+            tracing::info!(
+                agent = agent.as_str(),
+                source = ?artifact.source,
+                total_ms = elapsed_ms(started),
+                "agent_manager.install_agent_process: installed builtin launcher"
+            );
+            return Ok(Some(artifact));
         }
 
         if let Some(artifact) = self.install_agent_process_from_registry(agent, options)? {
+            tracing::info!(
+                agent = agent.as_str(),
+                source = ?artifact.source,
+                version = ?artifact.version,
+                total_ms = elapsed_ms(started),
+                "agent_manager.install_agent_process: installed from registry"
+            );
             return Ok(Some(artifact));
         }
 
         let artifact = self.install_agent_process_fallback(agent, options)?;
+        tracing::info!(
+            agent = agent.as_str(),
+            source = ?artifact.source,
+            version = ?artifact.version,
+            total_ms = elapsed_ms(started),
+            "agent_manager.install_agent_process: installed from fallback"
+        );
         Ok(Some(artifact))
     }
 
+    fn install_npm_agent_process_package(
+        &self,
+        agent: AgentId,
+        package: &str,
+        args: &[String],
+        env: &HashMap<String, String>,
+        source: InstallSource,
+        version: Option<String>,
+    ) -> Result<InstalledArtifact, AgentError> {
+        let started = Instant::now();
+        let root = self.agent_process_storage_dir(agent);
+        if root.exists() {
+            fs::remove_dir_all(&root)?;
+        }
+        fs::create_dir_all(&root)?;
+
+        let npm_install_started = Instant::now();
+        install_npm_package(&root, package, agent)?;
+        let npm_install_ms = elapsed_ms(npm_install_started);
+
+        let bin_name = agent.agent_process_binary_hint().ok_or_else(|| {
+            AgentError::ExtractFailed(format!(
+                "missing executable hint for agent process package: {agent}"
+            ))
+        })?;
+
+        let cmd_path = npm_bin_path(&root, bin_name);
+        if !cmd_path.exists() {
+            return Err(AgentError::ExtractFailed(format!(
+                "installed package missing executable: {}",
+                cmd_path.display()
+            )));
+        }
+
+        let launcher = self.agent_process_path(agent);
+        let write_started = Instant::now();
+        write_exec_agent_process_launcher(&launcher, &cmd_path, args, env)?;
+        let write_ms = elapsed_ms(write_started);
+        let verify_started = Instant::now();
+        verify_command(&launcher, &[])?;
+        let verify_ms = elapsed_ms(verify_started);
+
+        tracing::info!(
+            agent = agent.as_str(),
+            package = %package,
+            cmd = %cmd_path.display(),
+            npm_install_ms = npm_install_ms,
+            write_ms = write_ms,
+            verify_ms = verify_ms,
+            total_ms = elapsed_ms(started),
+            "agent_manager.install_npm_agent_process_package: completed"
+        );
+
+        Ok(InstalledArtifact {
+            kind: InstalledArtifactKind::AgentProcess,
+            path: launcher,
+            version,
+            source,
+        })
+    }
+
     fn agent_process_status(&self, agent: AgentId) -> Option<AgentProcessStatus> {
         if agent == AgentId::Mock {
             return Some(AgentProcessStatus {
@@ -540,59 +703,111 @@ impl AgentManager {
         agent: AgentId,
         options: &InstallOptions,
     ) -> Result<Option<InstalledArtifact>, AgentError> {
+        let started = Instant::now();
         let Some(registry_id) = agent.agent_process_registry_id() else {
             return Ok(None);
         };
 
+        tracing::info!(
+            agent = agent.as_str(),
+            registry_id = registry_id,
+            url = %self.registry_url,
+            "agent_manager.install_agent_process_from_registry: fetching registry"
+        );
+        let fetch_started = Instant::now();
         let registry = fetch_registry(&self.registry_url)?;
+        tracing::info!(
+            agent = agent.as_str(),
+            registry_id = registry_id,
+            fetch_ms = elapsed_ms(fetch_started),
+            "agent_manager.install_agent_process_from_registry: registry fetched"
+        );
         let Some(entry) = registry.agents.into_iter().find(|a| a.id == registry_id) else {
+            tracing::info!(
+                agent = agent.as_str(),
+                registry_id = registry_id,
+                total_ms = elapsed_ms(started),
+                "agent_manager.install_agent_process_from_registry: missing entry"
+            );
             return Ok(None);
         };
 
         if let Some(npx) = entry.distribution.npx {
             let package =
                 apply_npx_version_override(&npx.package, options.agent_process_version.as_deref());
-            let launcher = self.agent_process_path(agent);
+            let version = options
-            write_npx_agent_process_launcher(&launcher, &package, &npx.args, &npx.env)?;
+                .agent_process_version
-            verify_command(&launcher, &[])?;
+                .clone()
-            return Ok(Some(InstalledArtifact {
+                .or(entry.version)
-                kind: InstalledArtifactKind::AgentProcess,
+                .or(extract_npx_version(&package));
-                path: launcher,
+            let artifact = self.install_npm_agent_process_package(
-                version: options
+                agent,
-                    .agent_process_version
+                &package,
-                    .clone()
+                &npx.args,
-                    .or(entry.version)
+                &npx.env,
-                    .or(extract_npx_version(&package)),
+                InstallSource::Registry,
-                source: InstallSource::Registry,
+                version,
-            }));
+            )?;
+            tracing::info!(
+                agent = agent.as_str(),
+                package = %package,
+                total_ms = elapsed_ms(started),
+                "agent_manager.install_agent_process_from_registry: npm package installed"
+            );
+            return Ok(Some(artifact));
         }
 
         if let Some(binary) = entry.distribution.binary {
             let key = self.platform.registry_key();
             if let Some(target) = binary.get(key) {
                 let archive_url = Url::parse(&target.archive)?;
+                let download_started = Instant::now();
                 let payload = download_bytes(&archive_url)?;
+                let download_ms = elapsed_ms(download_started);
                 let root = self.agent_process_storage_dir(agent);
                 if root.exists() {
                     fs::remove_dir_all(&root)?;
                 }
                 fs::create_dir_all(&root)?;
+                let unpack_started = Instant::now();
                 unpack_archive(&payload, &archive_url, &root)?;
+                let unpack_ms = elapsed_ms(unpack_started);
 
                 let cmd_path = resolve_extracted_command(&root, &target.cmd)?;
                 let launcher = self.agent_process_path(agent);
+                let write_started = Instant::now();
                 write_exec_agent_process_launcher(&launcher, &cmd_path, &target.args, &target.env)?;
+                let write_ms = elapsed_ms(write_started);
+                let verify_started = Instant::now();
                 verify_command(&launcher, &[])?;
+                let verify_ms = elapsed_ms(verify_started);
 
-                return Ok(Some(InstalledArtifact {
+                let artifact = InstalledArtifact {
                     kind: InstalledArtifactKind::AgentProcess,
                     path: launcher,
                     version: options.agent_process_version.clone().or(entry.version),
                     source: InstallSource::Registry,
-                }));
+                };
+                tracing::info!(
+                    agent = agent.as_str(),
+                    archive_url = %archive_url,
+                    download_ms = download_ms,
+                    unpack_ms = unpack_ms,
+                    write_ms = write_ms,
+                    verify_ms = verify_ms,
+                    total_ms = elapsed_ms(started),
+                    "agent_manager.install_agent_process_from_registry: binary launcher installed"
+                );
+                return Ok(Some(artifact));
             }
         }
 
+        tracing::info!(
+            agent = agent.as_str(),
+            registry_id = registry_id,
+            total_ms = elapsed_ms(started),
+            "agent_manager.install_agent_process_from_registry: no compatible distribution"
+        );
         Ok(None)
     }
 
@@ -601,24 +816,44 @@ impl AgentManager {
         agent: AgentId,
         options: &InstallOptions,
     ) -> Result<InstalledArtifact, AgentError> {
-        let launcher = self.agent_process_path(agent);
+        let started = Instant::now();
-
+        let artifact = match agent {
-        match agent {
             AgentId::Claude => {
                 let package = fallback_npx_package(
                     "@zed-industries/claude-agent-acp",
                     options.agent_process_version.as_deref(),
                 );
-                write_npx_agent_process_launcher(&launcher, &package, &[], &HashMap::new())?;
+                self.install_npm_agent_process_package(
+                    agent,
+                    &package,
+                    &[],
+                    &HashMap::new(),
+                    InstallSource::Fallback,
+                    options
+                        .agent_process_version
+                        .clone()
+                        .or(extract_npx_version(&package)),
+                )?
             }
             AgentId::Codex => {
                 let package = fallback_npx_package(
                     "@zed-industries/codex-acp",
                     options.agent_process_version.as_deref(),
                 );
-                write_npx_agent_process_launcher(&launcher, &package, &[], &HashMap::new())?;
+                self.install_npm_agent_process_package(
+                    agent,
+                    &package,
+                    &[],
+                    &HashMap::new(),
+                    InstallSource::Fallback,
+                    options
+                        .agent_process_version
+                        .clone()
+                        .or(extract_npx_version(&package)),
+                )?
             }
             AgentId::Opencode => {
+                let launcher = self.agent_process_path(agent);
                 let native = self.resolve_binary(agent)?;
                 write_exec_agent_process_launcher(
                     &launcher,
@@ -626,37 +861,82 @@ impl AgentManager {
                     &["acp".to_string()],
                     &HashMap::new(),
                 )?;
+                verify_command(&launcher, &[])?;
+                InstalledArtifact {
+                    kind: InstalledArtifactKind::AgentProcess,
+                    path: launcher,
+                    version: options.agent_process_version.clone(),
+                    source: InstallSource::Fallback,
+                }
             }
             AgentId::Amp => {
                 let package =
                     fallback_npx_package("amp-acp", options.agent_process_version.as_deref());
-                write_npx_agent_process_launcher(&launcher, &package, &[], &HashMap::new())?;
+                self.install_npm_agent_process_package(
+                    agent,
+                    &package,
+                    &[],
+                    &HashMap::new(),
+                    InstallSource::Fallback,
+                    options
+                        .agent_process_version
+                        .clone()
+                        .or(extract_npx_version(&package)),
+                )?
             }
             AgentId::Pi => {
                 let package =
                     fallback_npx_package("pi-acp", options.agent_process_version.as_deref());
-                write_npx_agent_process_launcher(&launcher, &package, &[], &HashMap::new())?;
+                self.install_npm_agent_process_package(
+                    agent,
+                    &package,
+                    &[],
+                    &HashMap::new(),
+                    InstallSource::Fallback,
+                    options
+                        .agent_process_version
+                        .clone()
+                        .or(extract_npx_version(&package)),
+                )?
             }
             AgentId::Cursor => {
                 let package = fallback_npx_package(
                     "@blowmage/cursor-agent-acp",
                     options.agent_process_version.as_deref(),
                 );
-                write_npx_agent_process_launcher(&launcher, &package, &[], &HashMap::new())?;
+                self.install_npm_agent_process_package(
+                    agent,
+                    &package,
+                    &[],
+                    &HashMap::new(),
+                    InstallSource::Fallback,
+                    options
+                        .agent_process_version
+                        .clone()
+                        .or(extract_npx_version(&package)),
+                )?
             }
             AgentId::Mock => {
+                let launcher = self.agent_process_path(agent);
                 write_mock_agent_process_launcher(&launcher)?;
+                InstalledArtifact {
+                    kind: InstalledArtifactKind::AgentProcess,
+                    path: launcher,
+                    version: options.agent_process_version.clone(),
+                    source: InstallSource::Fallback,
+                }
             }
-        }
+        };
 
-        verify_command(&launcher, &[])?;
+        tracing::info!(
+            agent = agent.as_str(),
+            source = ?artifact.source,
+            version = ?artifact.version,
+            total_ms = elapsed_ms(started),
+            "agent_manager.install_agent_process_fallback: launcher installed"
+        );
 
-        Ok(InstalledArtifact {
+        Ok(artifact)
-            kind: InstalledArtifactKind::AgentProcess,
-            path: launcher,
-            version: options.agent_process_version.clone(),
-            source: InstallSource::Fallback,
-        })
     }
 }
 
@@ -732,6 +1012,10 @@ pub enum AgentError {
     RegistryParse(String),
     #[error("command verification failed: {0}")]
     VerifyFailed(String),
+    #[error(
+        "npm is required to install {agent}. install npm, then run step 3: `sandbox-agent install-agent {agent}`"
+    )]
+    MissingNpm { agent: AgentId },
 }
 
 fn fallback_npx_package(base: &str, version: Option<&str>) -> String {
@@ -779,15 +1063,36 @@ fn split_package_version(package: &str) -> Option<(&str, &str)> {
     }
 }
 
-fn write_npx_agent_process_launcher(
+fn install_npm_package(root: &Path, package: &str, agent: AgentId) -> Result<(), AgentError> {
-    path: &Path,
+    let mut command = Command::new("npm");
-    package: &str,
+    command
-    args: &[String],
+        .arg("install")
-    env: &HashMap<String, String>,
+        .arg("--no-audit")
-) -> Result<(), AgentError> {
+        .arg("--no-fund")
-    let mut command = vec!["npx".to_string(), "-y".to_string(), package.to_string()];
+        .arg("--prefix")
-    command.extend(args.iter().cloned());
+        .arg(root)
-    write_launcher(path, &command, env)
+        .arg(package)
+        .stdout(Stdio::null())
+        .stderr(Stdio::null());
+
+    match command.status() {
+        Ok(status) if status.success() => Ok(()),
+        Ok(status) => Err(AgentError::VerifyFailed(format!(
+            "npm install failed for {agent} with status {status}. run step 3: `sandbox-agent install-agent {agent}`"
+        ))),
+        Err(err) if err.kind() == io::ErrorKind::NotFound => Err(AgentError::MissingNpm { agent }),
+        Err(err) => Err(AgentError::VerifyFailed(format!(
+            "failed to execute npm for {agent}: {err}"
+        ))),
+    }
+}
+
+fn npm_bin_path(root: &Path, bin_name: &str) -> PathBuf {
+    let mut path = root.join("node_modules").join(".bin").join(bin_name);
+    if cfg!(windows) {
+        path.set_extension("cmd");
+    }
+    path
 }
 
 fn write_exec_agent_process_launcher(
@@ -998,6 +1303,15 @@ fn install_claude(
     platform: Platform,
     version: Option<&str>,
 ) -> Result<(), AgentError> {
+    let started = Instant::now();
+    tracing::info!(
+        path = %path.display(),
+        platform = ?platform,
+        version_override = ?version,
+        "agent_manager.install_claude: starting"
+    );
+
+    let version_started = Instant::now();
     let version = match version {
         Some(version) => version.to_string(),
         None => {
@@ -1009,6 +1323,7 @@ fn install_claude(
             text.trim().to_string()
         }
     };
+    let version_ms = elapsed_ms(version_started);
 
     let platform_segment = match platform {
         Platform::LinuxX64 => "linux-x64",
@@ -1023,12 +1338,26 @@ fn install_claude(
     let url = Url::parse(&format!(
         "https://storage.googleapis.com/claude-code-dist-86c565f3-f756-42ad-8dfa-d59b1c096819/claude-code-releases/{version}/{platform_segment}/claude"
     ))?;
+    let download_started = Instant::now();
     let bytes = download_bytes(&url)?;
+    let download_ms = elapsed_ms(download_started);
+    let write_started = Instant::now();
     write_executable(path, &bytes)?;
+    tracing::info!(
+        version = %version,
+        url = %url,
+        bytes = bytes.len(),
+        version_ms = version_ms,
+        download_ms = download_ms,
+        write_ms = elapsed_ms(write_started),
+        total_ms = elapsed_ms(started),
+        "agent_manager.install_claude: completed"
+    );
     Ok(())
 }
 
 fn install_amp(path: &Path, platform: Platform, version: Option<&str>) -> Result<(), AgentError> {
+    let started = Instant::now();
     let version = match version {
         Some(version) => version.to_string(),
         None => {
@@ -1053,12 +1382,25 @@ fn install_amp(path: &Path, platform: Platform, version: Option<&str>) -> Result
     let url = Url::parse(&format!(
         "https://storage.googleapis.com/amp-public-assets-prod-0/cli/{version}/amp-{platform_segment}"
     ))?;
+    let download_started = Instant::now();
     let bytes = download_bytes(&url)?;
+    let download_ms = elapsed_ms(download_started);
+    let write_started = Instant::now();
     write_executable(path, &bytes)?;
+    tracing::info!(
+        version = %version,
+        url = %url,
+        bytes = bytes.len(),
+        download_ms = download_ms,
+        write_ms = elapsed_ms(write_started),
+        total_ms = elapsed_ms(started),
+        "agent_manager.install_amp: completed"
+    );
     Ok(())
 }
 
 fn install_codex(path: &Path, platform: Platform, version: Option<&str>) -> Result<(), AgentError> {
+    let started = Instant::now();
     let target = match platform {
         Platform::LinuxX64 | Platform::LinuxX64Musl => "x86_64-unknown-linux-musl",
         Platform::LinuxArm64 => "aarch64-unknown-linux-musl",
@@ -1077,11 +1419,15 @@ fn install_codex(path: &Path, platform: Platform, version: Option<&str>) -> Resu
         ))?,
     };
 
+    let download_started = Instant::now();
     let bytes = download_bytes(&url)?;
+    let download_ms = elapsed_ms(download_started);
     let temp_dir = tempfile::tempdir()?;
+    let unpack_started = Instant::now();
     let cursor = io::Cursor::new(bytes);
     let mut archive = tar::Archive::new(GzDecoder::new(cursor));
     archive.unpack(temp_dir.path())?;
+    let unpack_ms = elapsed_ms(unpack_started);
 
     let expected = if cfg!(windows) {
         format!("codex-{target}.exe")
@@ -1091,7 +1437,17 @@ fn install_codex(path: &Path, platform: Platform, version: Option<&str>) -> Resu
 
     let binary = find_file_recursive(temp_dir.path(), &expected)?
         .ok_or_else(|| AgentError::ExtractFailed(format!("missing {expected}")))?;
+    let move_started = Instant::now();
     move_executable(&binary, path)?;
+    tracing::info!(
+        url = %url,
+        target = target,
+        download_ms = download_ms,
+        unpack_ms = unpack_ms,
+        move_ms = elapsed_ms(move_started),
+        total_ms = elapsed_ms(started),
+        "agent_manager.install_codex: completed"
+    );
     Ok(())
 }
 
@@ -1100,7 +1456,15 @@ fn install_opencode(
     platform: Platform,
     version: Option<&str>,
 ) -> Result<(), AgentError> {
-    match platform {
+    let started = Instant::now();
+    tracing::info!(
+        path = %path.display(),
+        platform = ?platform,
+        version_override = ?version,
+        "agent_manager.install_opencode: starting"
+    );
+
+    let result = match platform {
         Platform::MacosArm64 => {
             let url = match version {
                 Some(version) => Url::parse(&format!(
@@ -1141,22 +1505,46 @@ fn install_opencode(
                 ))?,
             };
 
+            let download_started = Instant::now();
             let bytes = download_bytes(&url)?;
+            let download_ms = elapsed_ms(download_started);
             let temp_dir = tempfile::tempdir()?;
+            let unpack_started = Instant::now();
             let cursor = io::Cursor::new(bytes);
             let mut archive = tar::Archive::new(GzDecoder::new(cursor));
             archive.unpack(temp_dir.path())?;
+            let unpack_ms = elapsed_ms(unpack_started);
             let binary = find_file_recursive(temp_dir.path(), "opencode")
                 .or_else(|_| find_file_recursive(temp_dir.path(), "opencode.exe"))?
                 .ok_or_else(|| AgentError::ExtractFailed("missing opencode".to_string()))?;
+            let move_started = Instant::now();
             move_executable(&binary, path)?;
+            tracing::info!(
+                url = %url,
+                download_ms = download_ms,
+                unpack_ms = unpack_ms,
+                move_ms = elapsed_ms(move_started),
+                "agent_manager.install_opencode: tarball extraction complete"
+            );
             Ok(())
         }
+    };
+
+    if result.is_ok() {
+        tracing::info!(
+            total_ms = elapsed_ms(started),
+            "agent_manager.install_opencode: completed"
+        );
     }
+
+    result
 }
 
 fn install_zip_binary(path: &Path, url: &Url, binary_name: &str) -> Result<(), AgentError> {
+    let started = Instant::now();
+    let download_started = Instant::now();
     let bytes = download_bytes(url)?;
+    let download_ms = elapsed_ms(download_started);
     let reader = io::Cursor::new(bytes);
     let mut archive =
         zip::ZipArchive::new(reader).map_err(|err| AgentError::ExtractFailed(err.to_string()))?;
@@ -1173,7 +1561,16 @@ fn install_zip_binary(path: &Path, url: &Url, binary_name: &str) -> Result<(), A
         let out_path = temp_dir.path().join(binary_name);
         let mut out_file = fs::File::create(&out_path)?;
         io::copy(&mut file, &mut out_file)?;
+        let move_started = Instant::now();
         move_executable(&out_path, path)?;
+        tracing::info!(
+            url = %url,
+            binary_name = binary_name,
+            download_ms = download_ms,
+            move_ms = elapsed_ms(move_started),
+            total_ms = elapsed_ms(started),
+            "agent_manager.install_zip_binary: completed"
+        );
         return Ok(());
     }
     Err(AgentError::ExtractFailed(format!("missing {binary_name}")))
@@ -1231,6 +1628,10 @@ fn find_file_recursive(dir: &Path, filename: &str) -> Result<Option<PathBuf>, Ag
     Ok(None)
 }
 
+fn elapsed_ms(start: Instant) -> u64 {
+    start.elapsed().as_millis() as u64
+}
+
 fn parse_version_output(output: &std::process::Output) -> Option<String> {
     let stdout = String::from_utf8_lossy(&output.stdout);
     let stderr = String::from_utf8_lossy(&output.stderr);
@@ -1265,6 +1666,38 @@ mod tests {
         }
     }
 
+    fn write_fake_npm(path: &Path) {
+        write_exec(
+            path,
+            r#"#!/usr/bin/env sh
+set -e
+prefix=""
+while [ "$#" -gt 0 ]; do
+  case "$1" in
+    install|--no-audit|--no-fund)
+      shift
+      ;;
+    --prefix)
+      prefix="$2"
+      shift 2
+      ;;
+    *)
+      shift
+      ;;
+  esac
+done
+[ -n "$prefix" ] || exit 1
+mkdir -p "$prefix/node_modules/.bin"
+for bin in claude-code-acp codex-acp amp-acp pi-acp cursor-agent-acp; do
+  echo '#!/usr/bin/env sh' > "$prefix/node_modules/.bin/$bin"
+  echo 'exit 0' >> "$prefix/node_modules/.bin/$bin"
+  chmod +x "$prefix/node_modules/.bin/$bin"
+done
+exit 0
+"#,
+        );
+    }
+
     fn env_lock() -> &'static Mutex<()> {
         static LOCK: OnceLock<Mutex<()>> = OnceLock::new();
         LOCK.get_or_init(|| Mutex::new(()))
@@ -1407,7 +1840,7 @@ mod tests {
 
         let bin_dir = temp_dir.path().join("bin");
         fs::create_dir_all(&bin_dir).expect("create bin dir");
-        write_exec(&bin_dir.join("npx"), "#!/usr/bin/env sh\nexit 0\n");
+        write_fake_npm(&bin_dir.join("npm"));
 
         let original_path = std::env::var_os("PATH").unwrap_or_default();
         let mut paths = vec![bin_dir.clone()];
@@ -1455,8 +1888,8 @@ mod tests {
         let launcher =
             fs::read_to_string(manager.agent_process_path(AgentId::Codex)).expect("launcher");
         assert!(
-            launcher.contains("@example/codex-acp@9.9.9"),
+            launcher.contains("node_modules/.bin/codex-acp"),
-            "launcher should include overridden package version"
+            "launcher should invoke installed codex executable"
         );
     }
 
@@ -1474,7 +1907,7 @@ mod tests {
 
         let bin_dir = temp_dir.path().join("bin");
         fs::create_dir_all(&bin_dir).expect("create bin dir");
-        write_exec(&bin_dir.join("npx"), "#!/usr/bin/env sh\nexit 0\n");
+        write_fake_npm(&bin_dir.join("npm"));
 
         let original_path = std::env::var_os("PATH").unwrap_or_default();
         let mut paths = vec![bin_dir.clone()];
@@ -1496,6 +1929,39 @@ mod tests {
         assert_eq!(agent_process_artifact.source, InstallSource::Fallback);
     }
 
+    #[test]
+    fn install_returns_missing_npm_error_for_npm_backed_agents() {
+        let _env_lock = env_lock().lock().expect("env lock");
+
+        let temp_dir = tempfile::tempdir().expect("create tempdir");
+        let mut manager = AgentManager::with_platform(temp_dir.path(), Platform::LinuxX64);
+
+        write_exec(
+            &manager.binary_path(AgentId::Codex),
+            "#!/usr/bin/env sh\nexit 0\n",
+        );
+
+        let bin_dir = temp_dir.path().join("bin");
+        fs::create_dir_all(&bin_dir).expect("create bin dir");
+
+        let original_path = std::env::var_os("PATH").unwrap_or_default();
+        let combined_path = std::env::join_paths([bin_dir]).expect("join PATH");
+        let _path_guard = EnvVarGuard::set("PATH", &combined_path);
+
+        manager.registry_url = serve_registry_once(serde_json::json!({ "agents": [] }));
+
+        let error = manager
+            .install(AgentId::Codex, InstallOptions::default())
+            .expect_err("install should fail without npm");
+
+        match error {
+            AgentError::MissingNpm { agent } => assert_eq!(agent, AgentId::Codex),
+            other => panic!("expected MissingNpm, got {other:?}"),
+        }
+
+        drop(original_path);
+    }
+
     #[test]
     fn reinstall_mock_returns_agent_process_artifact() {
         let temp_dir = tempfile::tempdir().expect("create tempdir");
@@ -1522,7 +1988,7 @@ mod tests {
     }
 
     #[test]
-    fn install_pi_skips_native_and_writes_fallback_npx_launcher() {
+    fn install_pi_skips_native_and_installs_fallback_npm_launcher() {
         let _env_lock = env_lock().lock().expect("env lock");
 
         let temp_dir = tempfile::tempdir().expect("create tempdir");
@@ -1530,7 +1996,7 @@ mod tests {
 
         let bin_dir = temp_dir.path().join("bin");
         fs::create_dir_all(&bin_dir).expect("create bin dir");
-        write_exec(&bin_dir.join("npx"), "#!/usr/bin/env sh\nexit 0\n");
+        write_fake_npm(&bin_dir.join("npm"));
 
         let original_path = std::env::var_os("PATH").unwrap_or_default();
         let mut paths = vec![bin_dir.clone()];
@@ -1564,8 +2030,8 @@ mod tests {
         let launcher =
             fs::read_to_string(manager.agent_process_path(AgentId::Pi)).expect("read pi launcher");
         assert!(
-            launcher.contains("pi-acp"),
+            launcher.contains("node_modules/.bin/pi-acp"),
-            "pi launcher should reference pi-acp package"
+            "pi launcher should use installed pi executable"
         );
 
         // resolve_agent_process should now find it.
@@ -1590,7 +2056,7 @@ mod tests {
     }
 
     #[test]
-    fn install_cursor_skips_native_and_writes_fallback_npx_launcher() {
+    fn install_cursor_skips_native_and_installs_fallback_npm_launcher() {
         let _env_lock = env_lock().lock().expect("env lock");
 
         let temp_dir = tempfile::tempdir().expect("create tempdir");
@@ -1598,7 +2064,7 @@ mod tests {
 
         let bin_dir = temp_dir.path().join("bin");
         fs::create_dir_all(&bin_dir).expect("create bin dir");
-        write_exec(&bin_dir.join("npx"), "#!/usr/bin/env sh\nexit 0\n");
+        write_fake_npm(&bin_dir.join("npm"));
 
         let original_path = std::env::var_os("PATH").unwrap_or_default();
         let mut paths = vec![bin_dir.clone()];
@@ -1630,8 +2096,8 @@ mod tests {
         let launcher = fs::read_to_string(manager.agent_process_path(AgentId::Cursor))
             .expect("read cursor launcher");
         assert!(
-            launcher.contains("@blowmage/cursor-agent-acp"),
+            launcher.contains("node_modules/.bin/cursor-agent-acp"),
-            "cursor launcher should reference @blowmage/cursor-agent-acp package"
+            "cursor launcher should use installed cursor executable"
         );
 
         let spec = manager

server/packages/sandbox-agent/src/acp_proxy_runtime.rs

@@ -165,7 +165,7 @@ impl AcpProxyRuntime {
                     error = %err,
                     "acp_proxy: POST → error"
                 );
-                Err(map_adapter_error(err))
+                Err(map_adapter_error(err, Some(instance.agent)))
             }
         }
     }
@@ -277,27 +277,28 @@ impl AcpProxyRuntime {
         server_id: &str,
         agent: AgentId,
     ) -> Result<Arc<ProxyInstance>, SandboxError> {
-        let start = std::time::Instant::now();
+        let total_started = std::time::Instant::now();
         tracing::info!(
             server_id = server_id,
             agent = agent.as_str(),
             "create_instance: starting"
         );
 
+        let install_started = std::time::Instant::now();
         self.ensure_installed(agent).await?;
-        let install_elapsed = start.elapsed();
         tracing::info!(
             server_id = server_id,
             agent = agent.as_str(),
-            install_ms = install_elapsed.as_millis() as u64,
+            install_ms = install_started.elapsed().as_millis() as u64,
             "create_instance: agent installed/verified"
         );
 
+        let resolve_started = std::time::Instant::now();
         let manager = self.inner.agent_manager.clone();
         let launch = tokio::task::spawn_blocking(move || manager.resolve_agent_process(agent))
             .await
             .map_err(|err| SandboxError::StreamError {
-                message: format!("failed to resolve ACP agent process launch spec: {err}"),
+                message: format!("failed to resolve agent process launch spec: {err}"),
             })?
             .map_err(|err| SandboxError::StreamError {
                 message: err.to_string(),
@@ -308,10 +309,11 @@ impl AcpProxyRuntime {
             agent = agent.as_str(),
             program = ?launch.program,
             args = ?launch.args,
-            resolve_ms = start.elapsed().as_millis() as u64,
+            resolve_ms = resolve_started.elapsed().as_millis() as u64,
             "create_instance: launch spec resolved, spawning"
         );
 
+        let spawn_started = std::time::Instant::now();
         let runtime = AdapterRuntime::start(
             LaunchSpec {
                 program: launch.program,
@@ -321,12 +323,13 @@ impl AcpProxyRuntime {
             self.inner.request_timeout,
         )
         .await
-        .map_err(map_adapter_error)?;
+        .map_err(|err| map_adapter_error(err, Some(agent)))?;
 
-        let total_ms = start.elapsed().as_millis() as u64;
+        let total_ms = total_started.elapsed().as_millis() as u64;
         tracing::info!(
             server_id = server_id,
             agent = agent.as_str(),
+            spawn_ms = spawn_started.elapsed().as_millis() as u64,
             total_ms = total_ms,
             "create_instance: ready"
         );
@@ -340,16 +343,27 @@ impl AcpProxyRuntime {
     }
 
     async fn ensure_installed(&self, agent: AgentId) -> Result<(), SandboxError> {
+        let started = std::time::Instant::now();
         if self.inner.require_preinstall {
             if !self.is_ready(agent).await {
                 return Err(SandboxError::AgentNotInstalled {
                     agent: agent.as_str().to_string(),
                 });
             }
+            tracing::info!(
+                agent = agent.as_str(),
+                total_ms = started.elapsed().as_millis() as u64,
+                "ensure_installed: preinstall requirement satisfied"
+            );
             return Ok(());
         }
 
         if self.is_ready(agent).await {
+            tracing::info!(
+                agent = agent.as_str(),
+                total_ms = started.elapsed().as_millis() as u64,
+                "ensure_installed: already ready"
+            );
             return Ok(());
         }
 
@@ -363,9 +377,19 @@ impl AcpProxyRuntime {
         let _guard = lock.lock().await;
 
         if self.is_ready(agent).await {
+            tracing::info!(
+                agent = agent.as_str(),
+                total_ms = started.elapsed().as_millis() as u64,
+                "ensure_installed: became ready while waiting for lock"
+            );
             return Ok(());
         }
 
+        tracing::info!(
+            agent = agent.as_str(),
+            "ensure_installed: installing missing artifacts"
+        );
+        let install_started = std::time::Instant::now();
         let manager = self.inner.agent_manager.clone();
         tokio::task::spawn_blocking(move || manager.install(agent, InstallOptions::default()))
             .await
@@ -378,6 +402,12 @@ impl AcpProxyRuntime {
                 stderr: Some(err.to_string()),
             })?;
 
+        tracing::info!(
+            agent = agent.as_str(),
+            install_ms = install_started.elapsed().as_millis() as u64,
+            total_ms = started.elapsed().as_millis() as u64,
+            "ensure_installed: install complete"
+        );
         Ok(())
     }
 
@@ -432,7 +462,7 @@ impl AcpDispatch for AcpProxyRuntime {
     }
 }
 
-fn map_adapter_error(err: AdapterError) -> SandboxError {
+fn map_adapter_error(err: AdapterError, agent: Option<AgentId>) -> SandboxError {
     match err {
         AdapterError::InvalidEnvelope => SandboxError::InvalidRequest {
             message: "request body must be a JSON-RPC object".to_string(),
@@ -446,6 +476,29 @@ fn map_adapter_error(err: AdapterError) -> SandboxError {
         AdapterError::Write(error) => SandboxError::StreamError {
             message: format!("failed writing to agent stdin: {error}"),
         },
+        AdapterError::Exited { exit_code, stderr } => {
+            if let Some(agent) = agent {
+                SandboxError::AgentProcessExited {
+                    agent: agent.as_str().to_string(),
+                    exit_code,
+                    stderr,
+                }
+            } else {
+                SandboxError::StreamError {
+                    message: if let Some(stderr) = stderr {
+                        format!(
+                            "agent process exited before responding (exit_code: {:?}, stderr: {})",
+                            exit_code, stderr
+                        )
+                    } else {
+                        format!(
+                            "agent process exited before responding (exit_code: {:?})",
+                            exit_code
+                        )
+                    },
+                }
+            }
+        }
         AdapterError::Spawn(error) => SandboxError::StreamError {
             message: format!("failed to start agent process: {error}"),
         },