Fix caching of Node.js runtime paths and improve error messages (#32198)

* `state.last_options` was never being updated, so the caching wasn't
working.

* If node on the PATH was too old it was logging errors on every
invocation even though managed node is being used.

Release Notes:

- Fixed caching of Node.js runtime paths and improved error messages.

crates/node_runtime/src/node_runtime.rs

@@ -3,16 +3,18 @@ use async_compression::futures::bufread::GzipDecoder;
 use async_tar::Archive;
 use futures::{AsyncReadExt, FutureExt as _, channel::oneshot, future::Shared};
 use http_client::{HttpClient, Url};
+use log::Level;
 use semver::Version;
 use serde::Deserialize;
 use smol::io::BufReader;
 use smol::{fs, lock::Mutex};
+use std::fmt::Display;
 use std::{
     env::{self, consts},
     ffi::OsString,
     io,
     path::{Path, PathBuf},
-    process::{Output, Stdio},
+    process::Output,
     sync::Arc,
 };
 use util::ResultExt;
@@ -63,46 +65,136 @@ impl NodeRuntime {
         })))
     }
 
-    async fn instance(&self) -> Result<Box<dyn NodeRuntimeTrait>> {
+    async fn instance(&self) -> Box<dyn NodeRuntimeTrait> {
         let mut state = self.0.lock().await;
 
-        while state.options.borrow().is_none() {
+        let options = loop {
-            state.options.changed().await?;
+            match state.options.borrow().as_ref() {
-        }
+                Some(options) => break options.clone(),
-        let options = state.options.borrow().clone().unwrap();
+                None => {}
+            }
+            match state.options.changed().await {
+                Ok(()) => {}
+                // failure case not cached
+                Err(err) => {
+                    return Box::new(UnavailableNodeRuntime {
+                        error_message: err.to_string().into(),
+                    });
+                }
+            }
+        };
+
         if state.last_options.as_ref() != Some(&options) {
             state.instance.take();
         }
         if let Some(instance) = state.instance.as_ref() {
-            return Ok(instance.boxed_clone());
+            return instance.boxed_clone();
         }
 
         if let Some((node, npm)) = options.use_paths.as_ref() {
-            let instance = SystemNodeRuntime::new(node.clone(), npm.clone()).await?;
+            let instance = match SystemNodeRuntime::new(node.clone(), npm.clone()).await {
+                Ok(instance) => {
+                    log::info!("using Node.js from `node.path` in settings: {:?}", instance);
+                    Box::new(instance)
+                }
+                Err(err) => {
+                    // failure case not cached, since it's cheap to check again
+                    return Box::new(UnavailableNodeRuntime {
+                        error_message: format!(
+                            "failure checking Node.js from `node.path` in settings ({}): {:?}",
+                            node.display(),
+                            err
+                        )
+                        .into(),
+                    });
+                }
+            };
             state.instance = Some(instance.boxed_clone());
-            return Ok(instance);
+            state.last_options = Some(options);
+            return instance;
         }
 
-        if options.allow_path_lookup {
+        let system_node_error = if options.allow_path_lookup {
             state.shell_env_loaded.clone().await.ok();
-            if let Some(instance) = SystemNodeRuntime::detect().await {
+            match SystemNodeRuntime::detect().await {
-                state.instance = Some(instance.boxed_clone());
+                Ok(instance) => {
-                return Ok(instance);
+                    log::info!("using Node.js found on PATH: {:?}", instance);
+                    state.instance = Some(instance.boxed_clone());
+                    state.last_options = Some(options);
+                    return Box::new(instance);
+                }
+                Err(err) => Some(err),
             }
-        }
+        } else {
+            None
+        };
 
         let instance = if options.allow_binary_download {
-            ManagedNodeRuntime::install_if_needed(&state.http).await?
+            let (log_level, why_using_managed) = match system_node_error {
+                Some(err @ DetectError::Other(_)) => (Level::Warn, err.to_string()),
+                Some(err @ DetectError::NotInPath(_)) => (Level::Info, err.to_string()),
+                None => (
+                    Level::Info,
+                    "`node.ignore_system_version` is `true` in settings".to_string(),
+                ),
+            };
+            match ManagedNodeRuntime::install_if_needed(&state.http).await {
+                Ok(instance) => {
+                    log::log!(
+                        log_level,
+                        "using Zed managed Node.js at {} since {}",
+                        instance.installation_path.display(),
+                        why_using_managed
+                    );
+                    Box::new(instance) as Box<dyn NodeRuntimeTrait>
+                }
+                Err(err) => {
+                    // failure case is cached, since downloading + installing may be expensive. The
+                    // downside of this is that it may fail due to an intermittent network issue.
+                    //
+                    // TODO: Have `install_if_needed` indicate which failure cases are retryable
+                    // and/or have shared tracking of when internet is available.
+                    Box::new(UnavailableNodeRuntime {
+                        error_message: format!(
+                            "failure while downloading and/or installing Zed managed Node.js, \
+                            restart Zed to retry: {}",
+                            err
+                        )
+                        .into(),
+                    }) as Box<dyn NodeRuntimeTrait>
+                }
+            }
+        } else if let Some(system_node_error) = system_node_error {
+            // failure case not cached, since it's cheap to check again
+            //
+            // TODO: When support is added for setting `options.allow_binary_download`, update this
+            // error message.
+            return Box::new(UnavailableNodeRuntime {
+                error_message: format!(
+                    "failure while checking system Node.js from PATH: {}",
+                    system_node_error
+                )
+                .into(),
+            });
         } else {
-            Box::new(UnavailableNodeRuntime)
+            // failure case is cached because it will always happen with these options
+            //
+            // TODO: When support is added for setting `options.allow_binary_download`, update this
+            // error message.
+            Box::new(UnavailableNodeRuntime {
+                error_message: "`node` settings do not allow any way to use Node.js"
+                    .to_string()
+                    .into(),
+            })
         };
 
         state.instance = Some(instance.boxed_clone());
-        return Ok(instance);
+        state.last_options = Some(options);
+        return instance;
     }
 
     pub async fn binary_path(&self) -> Result<PathBuf> {
-        self.instance().await?.binary_path()
+        self.instance().await.binary_path()
     }
 
     pub async fn run_npm_subcommand(
@@ -113,7 +205,7 @@ impl NodeRuntime {
     ) -> Result<Output> {
         let http = self.0.lock().await.http.clone();
         self.instance()
-            .await?
+            .await
             .run_npm_subcommand(Some(directory), http.proxy(), subcommand, args)
             .await
     }
@@ -124,7 +216,7 @@ impl NodeRuntime {
         name: &str,
     ) -> Result<Option<String>> {
         self.instance()
-            .await?
+            .await
             .npm_package_installed_version(local_package_directory, name)
             .await
     }
@@ -133,7 +225,7 @@ impl NodeRuntime {
         let http = self.0.lock().await.http.clone();
         let output = self
             .instance()
-            .await?
+            .await
             .run_npm_subcommand(
                 None,
                 http.proxy(),
@@ -279,7 +371,7 @@ impl ManagedNodeRuntime {
     #[cfg(windows)]
     const NPM_PATH: &str = "node_modules/npm/bin/npm-cli.js";
 
-    async fn install_if_needed(http: &Arc<dyn HttpClient>) -> Result<Box<dyn NodeRuntimeTrait>> {
+    async fn install_if_needed(http: &Arc<dyn HttpClient>) -> Result<Self> {
         log::info!("Node runtime install_if_needed");
 
         let os = match consts::OS {
@@ -303,20 +395,43 @@ impl ManagedNodeRuntime {
         let npm_file = node_dir.join(Self::NPM_PATH);
         let node_ca_certs = env::var(NODE_CA_CERTS_ENV_VAR).unwrap_or_else(|_| String::new());
 
-        let result = util::command::new_smol_command(&node_binary)
+        let valid = if fs::metadata(&node_binary).await.is_ok() {
-            .env_clear()
+            let result = util::command::new_smol_command(&node_binary)
-            .env(NODE_CA_CERTS_ENV_VAR, node_ca_certs)
+                .env_clear()
-            .arg(npm_file)
+                .env(NODE_CA_CERTS_ENV_VAR, node_ca_certs)
-            .arg("--version")
+                .arg(npm_file)
-            .stdin(Stdio::null())
+                .arg("--version")
-            .stdout(Stdio::null())
+                .args(["--cache".into(), node_dir.join("cache")])
-            .stderr(Stdio::null())
+                .args(["--userconfig".into(), node_dir.join("blank_user_npmrc")])
-            .args(["--cache".into(), node_dir.join("cache")])
+                .args(["--globalconfig".into(), node_dir.join("blank_global_npmrc")])
-            .args(["--userconfig".into(), node_dir.join("blank_user_npmrc")])
+                .output()
-            .args(["--globalconfig".into(), node_dir.join("blank_global_npmrc")])
+                .await;
-            .status()
+            match result {
-            .await;
+                Ok(output) => {
-        let valid = matches!(result, Ok(status) if status.success());
+                    if output.status.success() {
+                        true
+                    } else {
+                        log::warn!(
+                            "Zed managed Node.js binary at {} failed check with output: {:?}",
+                            node_binary.display(),
+                            output
+                        );
+                        false
+                    }
+                }
+                Err(err) => {
+                    log::warn!(
+                        "Zed managed Node.js binary at {} failed check, so re-downloading it. \
+                        Error: {}",
+                        node_binary.display(),
+                        err
+                    );
+                    false
+                }
+            }
+        } else {
+            false
+        };
 
         if !valid {
             _ = fs::remove_dir_all(&node_containing_dir).await;
@@ -338,11 +453,14 @@ impl ManagedNodeRuntime {
                     ArchiveType::Zip => "zip",
                 }
             );
+
             let url = format!("https://nodejs.org/dist/{version}/{file_name}");
+            log::info!("Downloading Node.js binary from {url}");
             let mut response = http
                 .get(&url, Default::default(), true)
                 .await
                 .context("error downloading Node binary tarball")?;
+            log::info!("Download of Node.js complete, extracting...");
 
             let body = response.body_mut();
             match archive_type {
@@ -353,6 +471,7 @@ impl ManagedNodeRuntime {
                 }
                 ArchiveType::Zip => extract_zip(&node_containing_dir, body).await?,
             }
+            log::info!("Extracted Node.js to {}", node_containing_dir.display())
         }
 
         // Note: Not in the `if !valid {}` so we can populate these for existing installations
@@ -360,9 +479,9 @@ impl ManagedNodeRuntime {
         _ = fs::write(node_dir.join("blank_user_npmrc"), []).await;
         _ = fs::write(node_dir.join("blank_global_npmrc"), []).await;
 
-        anyhow::Ok(Box::new(ManagedNodeRuntime {
+        anyhow::Ok(ManagedNodeRuntime {
             installation_path: node_dir,
-        }))
+        })
     }
 }
 
@@ -469,7 +588,7 @@ impl NodeRuntimeTrait for ManagedNodeRuntime {
     }
 }
 
-#[derive(Clone)]
+#[derive(Debug, Clone)]
 pub struct SystemNodeRuntime {
     node: PathBuf,
     npm: PathBuf,
@@ -479,7 +598,7 @@ pub struct SystemNodeRuntime {
 
 impl SystemNodeRuntime {
     const MIN_VERSION: semver::Version = Version::new(20, 0, 0);
-    async fn new(node: PathBuf, npm: PathBuf) -> Result<Box<dyn NodeRuntimeTrait>> {
+    async fn new(node: PathBuf, npm: PathBuf) -> Result<Self> {
         let output = util::command::new_smol_command(&node)
             .arg("--version")
             .output()
@@ -517,13 +636,31 @@ impl SystemNodeRuntime {
         this.global_node_modules =
             PathBuf::from(String::from_utf8_lossy(&output.stdout).to_string());
 
-        Ok(Box::new(this))
+        Ok(this)
     }
 
-    async fn detect() -> Option<Box<dyn NodeRuntimeTrait>> {
+    async fn detect() -> std::result::Result<Self, DetectError> {
-        let node = which::which("node").ok()?;
+        let node = which::which("node").map_err(DetectError::NotInPath)?;
-        let npm = which::which("npm").ok()?;
+        let npm = which::which("npm").map_err(DetectError::NotInPath)?;
-        Self::new(node, npm).await.log_err()
+        Self::new(node, npm).await.map_err(DetectError::Other)
+    }
+}
+
+enum DetectError {
+    NotInPath(which::Error),
+    Other(anyhow::Error),
+}
+
+impl Display for DetectError {
+    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+        match self {
+            DetectError::NotInPath(err) => {
+                write!(f, "system Node.js wasn't found on PATH: {}", err)
+            }
+            DetectError::Other(err) => {
+                write!(f, "checking system Node.js failed with error: {}", err)
+            }
+        }
     }
 }
 
@@ -603,15 +740,18 @@ pub async fn read_package_installed_version(
     Ok(Some(package_json.version))
 }
 
-pub struct UnavailableNodeRuntime;
+#[derive(Clone)]
+pub struct UnavailableNodeRuntime {
+    error_message: Arc<String>,
+}
 
 #[async_trait::async_trait]
 impl NodeRuntimeTrait for UnavailableNodeRuntime {
     fn boxed_clone(&self) -> Box<dyn NodeRuntimeTrait> {
-        Box::new(UnavailableNodeRuntime)
+        Box::new(self.clone())
     }
     fn binary_path(&self) -> Result<PathBuf> {
-        bail!("binary_path: no node runtime available")
+        bail!("{}", self.error_message)
     }
 
     async fn run_npm_subcommand(
@@ -621,7 +761,7 @@ impl NodeRuntimeTrait for UnavailableNodeRuntime {
         _: &str,
         _: &[&str],
     ) -> anyhow::Result<Output> {
-        bail!("run_npm_subcommand: no node runtime available")
+        bail!("{}", self.error_message)
     }
 
     async fn npm_package_installed_version(
@@ -629,7 +769,7 @@ impl NodeRuntimeTrait for UnavailableNodeRuntime {
         _local_package_directory: &Path,
         _: &str,
     ) -> Result<Option<String>> {
-        bail!("npm_package_installed_version: no node runtime available")
+        bail!("{}", self.error_message)
     }
 }