diff --git a/crates/pet-mac-commandlinetools/src/lib.rs b/crates/pet-mac-commandlinetools/src/lib.rs index 12edd5de..83dc82c9 100644 --- a/crates/pet-mac-commandlinetools/src/lib.rs +++ b/crates/pet-mac-commandlinetools/src/lib.rs @@ -9,6 +9,9 @@ use pet_core::{ Locator, LocatorKind, }; use pet_fs::path::resolve_symlink; +use pet_python_utils::macos::{ + add_macos_system_python_alias, is_macos_system_python, resolve_macos_system_python_env, +}; use pet_python_utils::version; use pet_python_utils::{env::ResolvedPythonEnv, executable::find_executables}; use pet_virtualenv::is_virtualenv; @@ -107,6 +110,13 @@ impl Locator for MacCmdLineTools { if std::env::consts::OS != "macos" { return None; } + + let resolved_system_alias = if is_macos_system_python(&env.executable) { + Some(resolve_macos_system_python_env(env)?) + } else { + None + }; + let env = resolved_system_alias.as_ref().unwrap_or(env); // Assume we create a virtual env from a python install, // Then the exe in the virtual env bin will be a symlink to the homebrew python install. // Hence the first part of the condition will be true, but the second part will be false. @@ -165,29 +175,6 @@ impl Locator for MacCmdLineTools { let mut resolved_environments = vec![]; - // We know /usr/bin/python3 can end up pointing to this same Python exe as well - // Hence look for those symlinks as well. - // Unfortunately /usr/bin/python3 is not a real symlink - // Hence we must spawn and verify it points to the same Python exe. - for possible_exes in [PathBuf::from("/usr/bin/python3")] { - if !symlinks.contains(&possible_exes) { - if let Some(resolved_env) = ResolvedPythonEnv::from(&possible_exes) { - if symlinks.contains(&resolved_env.executable) { - resolved_environments.push(resolved_env.clone()); - - symlinks.push(possible_exes); - // Use the latest accurate information we have. - version = Some(resolved_env.version); - prefix = Some(resolved_env.prefix); - arch = if resolved_env.is64_bit { - Some(Architecture::X64) - } else { - Some(Architecture::X86) - }; - } - } - } - } // Similarly the final exe can be /Library/Developer/CommandLineTools/Library/Frameworks/Python3.framework/Versions/3.9/bin/python3.9 // & we might have another file `python3` in that bin directory which would point to the same exe. // Lets get those as well. @@ -205,6 +192,7 @@ impl Locator for MacCmdLineTools { } } + add_macos_system_python_alias(&mut symlinks); symlinks.sort(); symlinks.dedup(); diff --git a/crates/pet-mac-xcode/src/lib.rs b/crates/pet-mac-xcode/src/lib.rs index 9ed76de8..e83ac0f3 100644 --- a/crates/pet-mac-xcode/src/lib.rs +++ b/crates/pet-mac-xcode/src/lib.rs @@ -9,6 +9,9 @@ use pet_core::{ Locator, LocatorKind, }; use pet_fs::path::resolve_symlink; +use pet_python_utils::macos::{ + add_macos_system_python_alias, is_macos_system_python, resolve_macos_system_python_env, +}; use pet_python_utils::version; use pet_python_utils::{env::ResolvedPythonEnv, executable::find_executables}; use pet_virtualenv::is_virtualenv; @@ -38,6 +41,13 @@ impl Locator for MacXCode { if std::env::consts::OS != "macos" { return None; } + + let resolved_system_alias = if is_macos_system_python(&env.executable) { + Some(resolve_macos_system_python_env(env)?) + } else { + None + }; + let env = resolved_system_alias.as_ref().unwrap_or(env); // Assume we create a virtual env from a python install, // Then the exe in the virtual env bin will be a symlink to the homebrew python install. // Hence the first part of the condition will be true, but the second part will be false. @@ -98,28 +108,6 @@ impl Locator for MacXCode { let mut resolved_environments = vec![]; - // We know /usr/bin/python3 can end up pointing to this same Python exe as well - // Hence look for those symlinks as well. - // Unfortunately /usr/bin/python3 is not a real symlink - // Hence we must spawn and verify it points to the same Python exe. - for possible_exes in [PathBuf::from("/usr/bin/python3")] { - if !symlinks.contains(&possible_exes) { - if let Some(resolved_env) = ResolvedPythonEnv::from(&possible_exes) { - if symlinks.contains(&resolved_env.executable) { - resolved_environments.push(resolved_env.clone()); - symlinks.push(possible_exes); - // Use the latest accurate information we have. - version = Some(resolved_env.version); - prefix = Some(resolved_env.prefix); - arch = if resolved_env.is64_bit { - Some(Architecture::X64) - } else { - Some(Architecture::X86) - }; - } - } - } - } // Similarly the final exe can be /Applications/Xcode.app/Contents/Developer/Library/Frameworks/Python3.framework/Versions/3.9/bin/python3.9 // & we might have another file `python3` in that bin directory which would point to the same exe. // Lets get those as well. @@ -137,6 +125,7 @@ impl Locator for MacXCode { } } + add_macos_system_python_alias(&mut symlinks); symlinks.sort(); symlinks.dedup(); diff --git a/crates/pet-python-utils/src/lib.rs b/crates/pet-python-utils/src/lib.rs index 9647595c..3383b948 100644 --- a/crates/pet-python-utils/src/lib.rs +++ b/crates/pet-python-utils/src/lib.rs @@ -7,5 +7,6 @@ pub mod env; pub mod executable; pub mod fs_cache; mod headers; +pub mod macos; pub mod platform_dirs; pub mod version; diff --git a/crates/pet-python-utils/src/macos.rs b/crates/pet-python-utils/src/macos.rs new file mode 100644 index 00000000..507fdc33 --- /dev/null +++ b/crates/pet-python-utils/src/macos.rs @@ -0,0 +1,224 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +use std::{ + env, + path::{Path, PathBuf}, +}; + +use pet_core::env::PythonEnv; +use pet_fs::path::{resolve_any_symlink, resolve_symlink}; + +const SYSTEM_PYTHON_DIR: &str = "/usr/bin"; +const XCODE_SELECT_LINK: &str = "/var/db/xcode_select_link"; +const DEFAULT_XCODE_DEVELOPER_DIR: &str = "/Applications/Xcode.app/Contents/Developer"; +const DEFAULT_COMMAND_LINE_TOOLS_DIR: &str = "/Library/Developer/CommandLineTools"; + +pub fn is_macos_system_python(executable: &Path) -> bool { + let mut components = executable.components(); + matches!(components.next(), Some(std::path::Component::RootDir)) + && matches!(components.next(), Some(std::path::Component::Normal(part)) if part == "usr") + && matches!(components.next(), Some(std::path::Component::Normal(part)) if part == "bin") + && matches!(components.next(), Some(std::path::Component::Normal(name)) if is_macos_python_name(name)) + && components.next().is_none() +} + +fn is_macos_python_name(name: &std::ffi::OsStr) -> bool { + let Some(name) = name.to_str() else { + return false; + }; + if name == "python3" { + return true; + } + let Some(minor) = name.strip_prefix("python3.") else { + return false; + }; + !minor.is_empty() && minor.bytes().all(|byte| byte.is_ascii_digit()) +} + +pub fn resolve_macos_system_python(executable: &Path) -> Option { + if std::env::consts::OS != "macos" || !is_macos_system_python(executable) { + return None; + } + let developer_dir = active_developer_dir()?; + selected_python_with(executable, &developer_dir, Path::is_file) +} + +pub fn resolve_macos_system_python_env(env: &PythonEnv) -> Option { + let executable = resolve_macos_system_python(&env.executable)?; + let mut resolved = PythonEnv::new(executable, env.prefix.clone(), env.version.clone()); + let mut aliases = env.symlinks.clone().unwrap_or_default(); + aliases.push(env.executable.clone()); + aliases.sort(); + aliases.dedup(); + resolved.symlinks = Some(aliases); + Some(resolved) +} + +pub fn add_macos_system_python_alias(symlinks: &mut Vec) { + let alias = PathBuf::from(SYSTEM_PYTHON_DIR).join("python3"); + let Some(selected) = resolve_macos_system_python(&alias) else { + return; + }; + let resolved = resolve_symlink(&selected).unwrap_or_else(|| selected.clone()); + add_alias_if_target_matches(symlinks, alias, &selected, &resolved); +} + +fn active_developer_dir() -> Option { + let environment = env::var_os("DEVELOPER_DIR").map(PathBuf::from); + let selected = resolve_any_symlink(&PathBuf::from(XCODE_SELECT_LINK)); + active_developer_dir_with(environment, selected, Path::is_dir) +} + +fn active_developer_dir_with( + environment: Option, + selected: Option, + is_dir: impl Fn(&Path) -> bool, +) -> Option { + environment + .into_iter() + .chain(selected) + .chain([ + PathBuf::from(DEFAULT_XCODE_DEVELOPER_DIR), + PathBuf::from(DEFAULT_COMMAND_LINE_TOOLS_DIR), + ]) + .map(normalize_developer_dir) + .find(|path| is_dir(path)) +} + +fn normalize_developer_dir(path: PathBuf) -> PathBuf { + if path.extension().is_some_and(|extension| extension == "app") { + path.join("Contents").join("Developer") + } else { + path + } +} + +fn selected_python_with( + alias: &Path, + developer_dir: &Path, + mut is_file: impl FnMut(&Path) -> bool, +) -> Option { + if !is_macos_system_python(alias) { + return None; + } + let candidate = developer_dir + .join("usr") + .join("bin") + .join(alias.file_name()?); + is_file(&candidate).then_some(candidate) +} + +fn add_alias_if_target_matches( + symlinks: &mut Vec, + alias: PathBuf, + selected: &Path, + resolved: &Path, +) { + if symlinks + .iter() + .any(|path| path == selected || path == resolved) + { + symlinks.push(alias); + symlinks.sort(); + symlinks.dedup(); + } +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn system_python_requires_a_python_name_directly_under_usr_bin() { + assert!(is_macos_system_python(Path::new("/usr/bin/python3"))); + assert!(is_macos_system_python(Path::new("/usr/bin/python3.12"))); + assert!(!is_macos_system_python(Path::new("/usr/bin/python"))); + assert!(!is_macos_system_python(Path::new("/usr/local/bin/python3"))); + assert!(!is_macos_system_python(Path::new( + "/usr/bin/python3-config" + ))); + } + + #[test] + fn public_resolvers_reject_non_system_python() { + let executable = Path::new("/usr/local/bin/python3"); + assert!(resolve_macos_system_python(executable).is_none()); + + let env = PythonEnv::new(executable.to_path_buf(), None, None); + assert!(resolve_macos_system_python_env(&env).is_none()); + } + + #[test] + fn developer_dir_prefers_environment_and_normalizes_app_bundle() { + let selected = active_developer_dir_with( + Some(PathBuf::from("/Applications/Xcode_16.app")), + Some(PathBuf::from(DEFAULT_COMMAND_LINE_TOOLS_DIR)), + |_| true, + ); + + assert_eq!( + selected, + Some(PathBuf::from( + "/Applications/Xcode_16.app/Contents/Developer" + )) + ); + } + + #[test] + fn developer_dir_falls_back_to_selected_link_then_standard_locations() { + let selected = active_developer_dir_with( + None, + Some(PathBuf::from( + "/Applications/Xcode_Beta.app/Contents/Developer", + )), + |_| true, + ); + assert_eq!( + selected, + Some(PathBuf::from( + "/Applications/Xcode_Beta.app/Contents/Developer" + )) + ); + + let fallback = active_developer_dir_with(None, None, |path| { + path == Path::new(DEFAULT_COMMAND_LINE_TOOLS_DIR) + }); + assert_eq!( + fallback, + Some(PathBuf::from(DEFAULT_COMMAND_LINE_TOOLS_DIR)) + ); + } + + #[test] + fn selected_python_maps_alias_without_spawning() { + let developer_dir = Path::new(DEFAULT_COMMAND_LINE_TOOLS_DIR); + let expected = developer_dir.join("usr/bin/python3"); + let mut file_checks = 0; + + let selected = selected_python_with(Path::new("/usr/bin/python3"), developer_dir, |path| { + file_checks += 1; + path == expected + }); + + assert_eq!(selected, Some(expected)); + assert_eq!(file_checks, 1); + } + + #[test] + fn alias_is_added_only_for_a_matching_selected_target() { + let selected = PathBuf::from("/Library/Developer/CommandLineTools/usr/bin/python3"); + let resolved = PathBuf::from( + "/Library/Developer/CommandLineTools/Library/Frameworks/Python3.framework/Versions/3.9/bin/python3.9", + ); + let alias = PathBuf::from("/usr/bin/python3"); + let mut symlinks = vec![resolved.clone()]; + + add_alias_if_target_matches(&mut symlinks, alias.clone(), &selected, &resolved); + assert!(symlinks.contains(&alias)); + + let mut unrelated = vec![PathBuf::from("/opt/homebrew/bin/python3")]; + add_alias_if_target_matches(&mut unrelated, alias.clone(), &selected, &resolved); + assert!(!unrelated.contains(&alias)); + } +} diff --git a/crates/pet/src/locators.rs b/crates/pet/src/locators.rs index a0b84205..98e1b4bf 100644 --- a/crates/pet/src/locators.rs +++ b/crates/pet/src/locators.rs @@ -20,11 +20,12 @@ use pet_pixi::Pixi; use pet_poetry::Poetry; use pet_pyenv::PyEnv; use pet_python_utils::env::ResolvedPythonEnv; +use pet_python_utils::macos::is_macos_system_python; use pet_uv::Uv; use pet_venv::Venv; use pet_virtualenv::VirtualEnv; use pet_virtualenvwrapper::VirtualEnvWrapper; -use std::path::PathBuf; +use std::path::{Path, PathBuf}; use std::sync::Arc; use tracing::{info_span, instrument}; @@ -138,7 +139,9 @@ pub fn identify_python_environment_using_locators( // We try to get the interpreter info, hoping that the real exe returned might be identifiable. let _resolve_span = info_span!("resolve_python_env", executable = %executable.display()).entered(); - if let Some(resolved_env) = ResolvedPythonEnv::from(&executable) { + if let Some(resolved_env) = + resolve_interpreter_if_allowed(&executable, std::env::consts::OS, ResolvedPythonEnv::from) + { let env = resolved_env.to_python_env(); if let Some(env) = locators.iter().find_map(|loc| loc.try_from(&env)) { trace!("Env ({:?}) in Path resolved as {:?}", executable, env.kind); @@ -175,6 +178,22 @@ pub fn identify_python_environment_using_locators( None } +fn resolve_interpreter_if_allowed( + executable: &Path, + operating_system: &str, + resolve_interpreter: impl Fn(&Path) -> Option, +) -> Option { + if operating_system == "macos" && is_macos_system_python(executable) { + trace!( + "Skipping unresolved macOS system Python shim without spawning: {:?}", + executable + ); + None + } else { + resolve_interpreter(executable) + } +} + fn create_unknown_env( resolved_env: ResolvedPythonEnv, fallback_category: Option, @@ -243,3 +262,33 @@ fn find_symlinks(_executable: &PathBuf) -> Option> { // Lets wait and see if this is necessary. None } + +#[cfg(test)] +mod tests { + use super::*; + use std::cell::Cell; + + #[test] + fn unresolved_macos_system_python_does_not_spawn() { + let calls = Cell::new(0); + let result = resolve_interpreter_if_allowed(Path::new("/usr/bin/python3"), "macos", |_| { + calls.set(calls.get() + 1); + None + }); + + assert!(result.is_none()); + assert_eq!(calls.get(), 0); + } + + #[test] + fn unresolved_non_macos_python_still_uses_fallback_resolver() { + let calls = Cell::new(0); + let result = resolve_interpreter_if_allowed(Path::new("/usr/bin/python3"), "linux", |_| { + calls.set(calls.get() + 1); + None + }); + + assert!(result.is_none()); + assert_eq!(calls.get(), 1); + } +} diff --git a/crates/pet/tests/e2e_performance.rs b/crates/pet/tests/e2e_performance.rs index 38620078..7a6cf453 100644 --- a/crates/pet/tests/e2e_performance.rs +++ b/crates/pet/tests/e2e_performance.rs @@ -6,12 +6,15 @@ //! These tests spawn the pet server as a subprocess and communicate via JSONRPC //! to measure discovery performance from a client perspective. +use pet_core::telemetry::refresh_progress::{ + RefreshProgress, RefreshProgressPhase, RefreshProgressStatus, +}; use serde::Deserialize; use serde_json::{json, Value}; -use std::collections::{HashMap, VecDeque}; +use std::collections::{BTreeMap, HashMap, VecDeque}; use std::env; use std::io::{BufRead, BufReader, Read, Write}; -use std::path::PathBuf; +use std::path::{Path, PathBuf}; use std::process::{Child, ChildStdin, ChildStdout, Command, Stdio}; use std::sync::atomic::{AtomicU32, Ordering}; use std::sync::{Arc, Mutex}; @@ -199,14 +202,18 @@ pub struct Manager { struct SharedState { environments: Mutex>, managers: Mutex>, + refresh_progress: Mutex>, + capture_refresh_progress: bool, first_env_time: Mutex>, } impl SharedState { - fn new() -> Self { + fn new(capture_refresh_progress: bool) -> Self { Self { environments: Mutex::new(Vec::new()), managers: Mutex::new(Vec::new()), + refresh_progress: Mutex::new(Vec::new()), + capture_refresh_progress, first_env_time: Mutex::new(None), } } @@ -231,9 +238,23 @@ impl SharedState { self.managers.lock().unwrap().push(mgr); } } - "log" | "telemetry" => { - // Ignore log and telemetry notifications + "telemetry" if self.capture_refresh_progress => { + if params.get("event").and_then(Value::as_str) == Some("RefreshProgress") { + if let Some(progress) = params + .get("data") + .and_then(|data| data.get("refreshProgress")) + .and_then(|value| { + serde_json::from_value::(value.clone()).ok() + }) + { + self.refresh_progress + .lock() + .expect("refresh progress mutex poisoned") + .push(progress); + } + } } + "log" => {} _ => { // Unknown notification } @@ -243,6 +264,10 @@ impl SharedState { fn clear(&self) { self.environments.lock().unwrap().clear(); self.managers.lock().unwrap().clear(); + self.refresh_progress + .lock() + .expect("refresh progress mutex poisoned") + .clear(); *self.first_env_time.lock().unwrap() = None; } } @@ -253,6 +278,7 @@ pub struct PetClient { stdin: ChildStdin, stdout: BufReader, stderr_tail: Arc>>, + interpreter_probe_timeouts: Arc>>, stderr_handle: Option>, state: Arc, start_time: Instant, @@ -261,6 +287,14 @@ pub struct PetClient { impl PetClient { /// Spawn the pet server and create a client pub fn spawn() -> Result { + Self::spawn_with_options(false) + } + + fn spawn_with_refresh_progress() -> Result { + Self::spawn_with_options(true) + } + + fn spawn_with_options(capture_refresh_progress: bool) -> Result { let pet_exe = get_pet_executable(); if !pet_exe.exists() { @@ -292,15 +326,21 @@ impl PetClient { .take() .expect("PET stderr must be piped by the command above"); let stderr_tail = Arc::new(Mutex::new(VecDeque::with_capacity(STDERR_TAIL_LINES))); - let stderr_handle = spawn_stderr_reader(stderr, stderr_tail.clone()); + let interpreter_probe_timeouts = Arc::new(Mutex::new(BTreeMap::new())); + let stderr_handle = spawn_stderr_reader( + stderr, + stderr_tail.clone(), + interpreter_probe_timeouts.clone(), + ); Ok(Self { process, stdin, stdout: BufReader::new(stdout), stderr_tail, + interpreter_probe_timeouts, stderr_handle: Some(stderr_handle), - state: Arc::new(SharedState::new()), + state: Arc::new(SharedState::new(capture_refresh_progress)), start_time, }) } @@ -378,6 +418,13 @@ impl PetClient { .join("\n") } + fn interpreter_probe_timeout_counts(&self) -> BTreeMap { + self.interpreter_probe_timeouts + .lock() + .expect("interpreter probe timeout mutex poisoned") + .clone() + } + /// Configure the server pub fn configure(&mut self, config: Value) -> Result { let start = Instant::now(); @@ -417,6 +464,14 @@ impl PetClient { self.state.managers.lock().unwrap().clone() } + fn get_refresh_progress(&self) -> Vec { + self.state + .refresh_progress + .lock() + .expect("refresh progress mutex poisoned") + .clone() + } + /// Get time from start to first environment pub fn time_to_first_env(&self) -> Option { self.state @@ -511,6 +566,39 @@ fn get_workspace_dir() -> PathBuf { }) } +fn interpreter_probe_timeout_label(line: &str) -> Option<&'static str> { + if !line.contains("Timed out after") || !line.contains("resolving Python via spawn") { + return None; + } + if line.contains("/usr/bin/python3") { + Some("usrBinPython3") + } else if line.contains("CommandLineTools") { + Some("commandLineTools") + } else if line.contains("hostedtoolcache") { + Some("hostedToolcache") + } else if line.contains("/Library/Frameworks/Python.framework") { + Some("pythonOrgFramework") + } else if line.contains("/usr/local/bin") { + Some("usrLocalBin") + } else { + Some("other") + } +} + +#[test] +fn interpreter_probe_timeouts_are_classified_without_exposing_paths() { + assert_eq!( + interpreter_probe_timeout_label( + r#"Timed out after 15s resolving Python via spawn for "/usr/bin/python3"; killing child."# + ), + Some("usrBinPython3") + ); + assert_eq!( + interpreter_probe_timeout_label("ordinary PET warning"), + None + ); +} + fn read_jsonrpc_message(reader: &mut impl BufRead) -> Result { let mut content_length = None; loop { @@ -546,6 +634,7 @@ fn read_jsonrpc_message(reader: &mut impl BufRead) -> Result { fn spawn_stderr_reader( stderr: impl Read + Send + 'static, stderr_tail: Arc>>, + interpreter_probe_timeouts: Arc>>, ) -> JoinHandle<()> { thread::spawn(move || { for line in BufReader::new(stderr).lines() { @@ -553,6 +642,13 @@ fn spawn_stderr_reader( Ok(line) => line, Err(error) => format!("Failed to read PET stderr: {error}"), }; + if let Some(label) = interpreter_probe_timeout_label(&line) { + *interpreter_probe_timeouts + .lock() + .expect("interpreter probe timeout mutex poisoned") + .entry(label.to_string()) + .or_default() += 1; + } let mut tail = stderr_tail.lock().expect("PET stderr tail mutex poisoned"); if tail.len() == STDERR_TAIL_LINES { tail.pop_front(); @@ -581,17 +677,180 @@ fn jsonrpc_reader_preserves_buffered_follow_up_message() { #[test] fn stderr_reader_drains_input_and_bounds_diagnostic_tail() { - let input = (0..STDERR_TAIL_LINES + 5) - .map(|index| format!("line {index}\n")) - .collect::(); + let timeout_line = + r#"Timed out after 15s resolving Python via spawn for "/usr/bin/python3"; killing child."#; + let input = format!( + "{timeout_line}\n{}", + (0..STDERR_TAIL_LINES + 5) + .map(|index| format!("line {index}\n")) + .collect::() + ); let tail = Arc::new(Mutex::new(VecDeque::new())); - let handle = spawn_stderr_reader(std::io::Cursor::new(input.into_bytes()), tail.clone()); + let timeout_counts = Arc::new(Mutex::new(BTreeMap::new())); + let handle = spawn_stderr_reader( + std::io::Cursor::new(input.into_bytes()), + tail.clone(), + timeout_counts.clone(), + ); handle.join().unwrap(); let tail = tail.lock().unwrap(); assert_eq!(tail.len(), STDERR_TAIL_LINES); assert_eq!(tail.front().map(String::as_str), Some("line 5")); assert_eq!(tail.back().map(String::as_str), Some("line 104")); + drop(tail); + assert_eq!( + timeout_counts.lock().unwrap().get("usrBinPython3"), + Some(&1) + ); +} + +fn refresh_phase_name(phase: RefreshProgressPhase) -> &'static str { + match phase { + RefreshProgressPhase::Locators => "locators", + RefreshProgressPhase::Path => "path", + RefreshProgressPhase::GlobalVirtualEnvs => "globalVirtualEnvs", + RefreshProgressPhase::Workspaces => "workspaces", + } +} + +fn collect_refresh_progress( + progress: &[RefreshProgress], + phase_stats: &mut BTreeMap, + locator_stats: &mut BTreeMap, +) { + for event in progress + .iter() + .filter(|event| event.status == RefreshProgressStatus::Completed) + { + if let (Some(locator), Some(duration)) = (&event.locator_name, event.locator_elapsed_ms) { + locator_stats + .entry(locator.clone()) + .or_default() + .add(duration); + } else if let Some(duration) = event.phase_elapsed_ms { + phase_stats + .entry(refresh_phase_name(event.phase).to_string()) + .or_default() + .add(duration); + } + } +} + +fn statistics_json(statistics: &BTreeMap) -> BTreeMap { + statistics + .iter() + .map(|(name, metrics)| (name.clone(), metrics.to_json())) + .collect() +} + +fn record_interpreter_probe_timeouts( + client: &PetClient, + probe_timeout_counts: &mut BTreeMap, +) { + let timeout_counts = client.interpreter_probe_timeout_counts(); + for (label, count) in &timeout_counts { + *probe_timeout_counts.entry(label.clone()).or_default() += count; + } + if !timeout_counts.is_empty() { + println!(" Interpreter probe timeouts: {timeout_counts:?}"); + } +} + +fn collect_refresh_diagnostics( + workspace_dir: &Path, + cache_dir: &Path, + phase_stats: &mut BTreeMap, + locator_stats: &mut BTreeMap, + probe_timeout_counts: &mut BTreeMap, +) { + let diagnostic_cache_dir = cache_dir.join("refresh-progress"); + let _ = std::fs::remove_dir_all(&diagnostic_cache_dir); + std::fs::create_dir_all(&diagnostic_cache_dir) + .expect("Failed to create refresh diagnostic cache dir"); + + println!("\nCollecting untimed refresh diagnostics..."); + for iteration in 0..STAT_ITERATIONS { + let mut client = + PetClient::spawn_with_refresh_progress().expect("Failed to spawn diagnostic server"); + client + .configure(json!({ + "workspaceDirectories": [workspace_dir], + "cacheDirectory": diagnostic_cache_dir + })) + .expect("Failed to configure diagnostic server"); + let (result, _) = client + .refresh(None) + .expect("Failed to run diagnostic refresh"); + + collect_refresh_progress(&client.get_refresh_progress(), phase_stats, locator_stats); + record_interpreter_probe_timeouts(&client, probe_timeout_counts); + println!( + " Diagnostic iteration {}: refresh={}ms, envs={}", + iteration + 1, + result.duration, + client.get_environments().len() + ); + } +} + +#[test] +fn refresh_progress_notifications_are_collected_only_when_enabled() { + let notification = json!({ + "event": "RefreshProgress", + "data": { + "refreshProgress": { + "refreshId": 7, + "phase": "locators", + "status": "completed", + "elapsedMs": 25, + "locatorName": "Conda", + "locatorElapsedMs": 20 + } + } + }); + + let disabled_state = SharedState::new(false); + disabled_state.handle_notification("telemetry", notification.clone()); + assert!(disabled_state.refresh_progress.lock().unwrap().is_empty()); + + let state = SharedState::new(true); + state.handle_notification("telemetry", notification); + let progress = state.refresh_progress.lock().unwrap(); + assert_eq!(progress.len(), 1); + assert_eq!(progress[0].locator_name.as_deref(), Some("Conda")); + assert_eq!(progress[0].locator_elapsed_ms, Some(20)); +} + +#[test] +fn refresh_progress_aggregation_separates_phases_and_locators() { + let progress = vec![ + RefreshProgress { + refresh_id: 1, + phase: RefreshProgressPhase::Locators, + status: RefreshProgressStatus::Completed, + elapsed_ms: 30, + phase_elapsed_ms: Some(30), + locator_name: None, + locator_elapsed_ms: None, + }, + RefreshProgress { + refresh_id: 1, + phase: RefreshProgressPhase::Locators, + status: RefreshProgressStatus::Completed, + elapsed_ms: 25, + phase_elapsed_ms: None, + locator_name: Some("Conda".to_string()), + locator_elapsed_ms: Some(20), + }, + ]; + let mut phases = BTreeMap::new(); + let mut locators = BTreeMap::new(); + + collect_refresh_progress(&progress, &mut phases, &mut locators); + + assert_eq!(phases["locators"].samples, vec![30]); + assert_eq!(locators["Conda"].samples, vec![20]); } // ============================================================================ @@ -1083,8 +1342,10 @@ fn test_performance_summary() { let mut startup_stats = StatisticalMetrics::new(); let mut refresh_stats = StatisticalMetrics::new(); let mut time_to_first_env_stats = StatisticalMetrics::new(); - let mut env_count = 0usize; - let mut manager_count = 0usize; + let mut phase_stats = BTreeMap::new(); + let mut locator_stats = BTreeMap::new(); + let mut probe_timeout_counts: BTreeMap = BTreeMap::new(); + let mut expected_inventory = None; let cache_dir = get_test_cache_dir(); let _ = std::fs::remove_dir_all(&cache_dir); @@ -1114,21 +1375,54 @@ fn test_performance_summary() { let (result, _) = client.refresh(None).expect("Failed to refresh"); refresh_stats.add(result.duration); - env_count = client.get_environments().len(); - manager_count = client.get_managers().len(); + let inventory = (client.get_environments().len(), client.get_managers().len()); + if let Some(expected) = expected_inventory { + assert_eq!( + inventory, expected, + "Environment and manager inventory changed after iteration 1" + ); + } else { + expected_inventory = Some(inventory); + } if let Some(ttfe) = client.time_to_first_env() { time_to_first_env_stats.add(ttfe.as_millis()); } + record_interpreter_probe_timeouts(&client, &mut probe_timeout_counts); println!( " Iteration {}: startup={}ms, refresh={}ms, envs={}", i + 1, startup_time, result.duration, - env_count + inventory.0 + ); + } + + let (env_count, manager_count) = + expected_inventory.expect("Performance summary must run at least one iteration"); + collect_refresh_diagnostics( + &workspace_dir, + &cache_dir, + &mut phase_stats, + &mut locator_stats, + &mut probe_timeout_counts, + ); + + for phase in ["locators", "path", "globalVirtualEnvs", "workspaces"] { + let count = phase_stats + .get(phase) + .map(StatisticalMetrics::count) + .unwrap_or_default(); + assert_eq!( + count, STAT_ITERATIONS, + "Expected one completed {phase} phase per refresh iteration" ); } + assert!( + !locator_stats.is_empty(), + "Expected per-locator timing in RefreshProgress telemetry" + ); // Print statistical summary println!("\n----------------------------------------"); @@ -1139,10 +1433,19 @@ fn test_performance_summary() { if time_to_first_env_stats.count() > 0 { time_to_first_env_stats.print_summary("Time to first env"); } + for (phase, metrics) in &phase_stats { + metrics.print_summary(&format!("Phase {phase}")); + } + for (locator, metrics) in &locator_stats { + metrics.print_summary(&format!("Locator {locator}")); + } println!("Environments found: {}", env_count); println!("Managers found: {}", manager_count); println!("========================================\n"); + let phase_json = statistics_json(&phase_stats); + let locator_json = statistics_json(&locator_stats); + // Output as JSON for CI parsing // Includes both P50 values at top level (for backwards compatibility) and full stats let json_output = serde_json::to_string_pretty(&json!({ @@ -1155,7 +1458,10 @@ fn test_performance_summary() { "server_startup": startup_stats.to_json(), "full_refresh": refresh_stats.to_json(), "time_to_first_env": time_to_first_env_stats.to_json() - } + }, + "phases": phase_json, + "locators": locator_json, + "interpreter_probe_timeouts": probe_timeout_counts })) .unwrap(); diff --git a/docs/QUALITY_SNAPSHOTS.md b/docs/QUALITY_SNAPSHOTS.md index 60791236..79461ffa 100644 --- a/docs/QUALITY_SNAPSHOTS.md +++ b/docs/QUALITY_SNAPSHOTS.md @@ -46,7 +46,8 @@ cargo test --release --features ci-perf --test e2e_performance test_performance_ ``` The E2E client keeps one buffered stdout reader for the process lifetime and continuously drains a bounded stderr tail so protocol read-ahead and pipe backpressure cannot distort measurements. +Phase and locator telemetry is collected in separate, untimed refreshes so diagnostic processing cannot backpressure the timed JSON-RPC refreshes. ## Known investigations -The persistent macOS cold-refresh tail is tracked by issue #504. Existing tail latency is represented in the baseline, but any further regression is still gated. +The macOS cold-refresh tail is tracked by issue #504. Phase and locator distributions plus privacy-safe interpreter timeout counts verify that the tail does not recur.