diff --git a/src/cli/syncback.rs b/src/cli/syncback.rs index a122d3d1..1de59e06 100644 --- a/src/cli/syncback.rs +++ b/src/cli/syncback.rs @@ -18,7 +18,7 @@ use crate::{ project::Project, roblox_api, serve_session::ServeSession, - syncback::{syncback_loop, FsSnapshot}, + syncback::{syncback_loop_with_walked_paths, FsSnapshot}, }; use super::{resolve_path, sourcemap::write_sourcemap_from_syncback, GlobalOptions}; @@ -153,25 +153,25 @@ impl SyncbackCommand { } }; + let total_timer = Instant::now(); + let input_kind = FileKind::from_path(&path_new).context(UNKNOWN_INPUT_KIND_ERR)?; let dom_start_timer = Instant::now(); let dom_new = read_dom(&path_new, input_kind)?; - log::debug!( - "Finished opening file in {:0.02}s", - dom_start_timer.elapsed().as_secs_f32() - ); + let dom_elapsed = dom_start_timer.elapsed(); + log::info!("[PERF] parse rbxl: {:.3}s", dom_elapsed.as_secs_f64()); - // Use oneshot Vfs for syncback - file watching isn't needed and - // watcher errors shouldn't terminate the process let vfs = Vfs::new_oneshot(); let project_start_timer = Instant::now(); - let session_old = ServeSession::new_oneshot(vfs, path_old.clone())?; - log::debug!( - "Finished opening project in {:0.02}s", - project_start_timer.elapsed().as_secs_f32() + let mut session_old = ServeSession::new_oneshot(vfs, path_old.clone())?; + let project_elapsed = project_start_timer.elapsed(); + log::info!( + "[PERF] init old tree (prefetch+snapshot+patch): {:.3}s", + project_elapsed.as_secs_f64() ); + let pre_walked_paths = session_old.take_walked_paths(); let mut dom_old = session_old.tree(); log::debug!("Old root: {}", dom_old.inner().root().class); @@ -196,16 +196,18 @@ impl SyncbackCommand { } else { log::info!("Beginning syncback (clean mode)..."); } - let result = syncback_loop( + let result = syncback_loop_with_walked_paths( session_old.vfs(), &mut dom_old, dom_new, session_old.root_project(), self.incremental, + pre_walked_paths, )?; - log::debug!( - "Syncback finished in {:.02}s!", - syncback_timer.elapsed().as_secs_f32() + let syncback_elapsed = syncback_timer.elapsed(); + log::info!( + "[PERF] syncback_loop total: {:.3}s", + syncback_elapsed.as_secs_f64() ); let base_path = session_old.root_project().folder_location(); @@ -235,14 +237,18 @@ impl SyncbackCommand { log::info!("Writing to the file system..."); + let git_cache_timer = Instant::now(); let git_cache = crate::git::GitIndexCache::new(base_path); + log::info!( + "[PERF] git index cache build: {:.3}s (entries: {})", + git_cache_timer.elapsed().as_secs_f64(), + git_cache.as_ref().map_or(0, |c| c.len()), + ); + let write_timer = Instant::now(); if self.sourcemap { let sourcemap_path = base_path.join("sourcemap.json"); - // Run file writes and sourcemap generation in parallel. - // The sourcemap is built entirely from in-memory data (WeakDom + path map), - // so it doesn't need to wait for files to be on disk. let (write_result, sourcemap_result) = std::thread::scope(|s| { let write_handle = s.spawn(|| { result.fs_snapshot.write_to_vfs_parallel( @@ -280,6 +286,10 @@ impl SyncbackCommand { git_cache.as_ref(), )?; } + log::info!( + "[PERF] write_to_vfs_parallel: {:.3}s", + write_timer.elapsed().as_secs_f64() + ); log::info!( "Finished syncback: wrote {} files/folders, removed {}.", @@ -287,7 +297,12 @@ impl SyncbackCommand { result.fs_snapshot.removed_paths().len() ); + let git_refresh_timer = Instant::now(); crate::git::refresh_git_index(base_path); + log::info!( + "[PERF] git refresh_index: {:.3}s", + git_refresh_timer.elapsed().as_secs_f64() + ); // Delete input file if using default Project.rbxl location if let Some(input_path) = &delete_input_after_syncback { @@ -309,9 +324,11 @@ impl SyncbackCommand { log::info!("Aborting before writing to file system due to `--dry-run`"); } - // It is potentially prohibitively expensive to drop a ServeSession, - // and the program is about to exit anyway so we're just going to forget - // about it. + log::info!( + "[PERF] TOTAL syncback command: {:.3}s", + total_timer.elapsed().as_secs_f64() + ); + forget(session_old); // Temp file is automatically cleaned up when _temp_file is dropped diff --git a/src/git.rs b/src/git.rs index 2e7cf4b9..29e5286e 100644 --- a/src/git.rs +++ b/src/git.rs @@ -248,13 +248,25 @@ pub struct GitIndexCache { impl GitIndexCache { pub fn new(project_root: &Path) -> Option { + let timer = Instant::now(); let repo_root = git_repo_root(project_root)?; - let output = Command::new("git") - .args(["ls-files", "--stage"]) - .current_dir(&repo_root) - .output() - .ok()?; + let project_rel_prefix = project_root + .strip_prefix(&repo_root) + .ok() + .and_then(|p| p.to_str()) + .map(|s| s.replace('\\', "/")); + + let mut cmd = Command::new("git"); + cmd.args(["ls-files", "--stage"]); + if let Some(ref prefix) = project_rel_prefix { + if !prefix.is_empty() { + cmd.arg("--").arg(prefix); + } + } + cmd.current_dir(&repo_root); + + let output = cmd.output().ok()?; if !output.status.success() { return None; @@ -263,7 +275,6 @@ impl GitIndexCache { let mut entries = HashMap::new(); let stdout = String::from_utf8_lossy(&output.stdout); for line in stdout.lines() { - // Format: \t let (meta, path) = match line.split_once('\t') { Some(pair) => pair, None => continue, @@ -283,10 +294,18 @@ impl GitIndexCache { entries.insert(project_rel, hash_hex); } - log::debug!("GitIndexCache: loaded {} index entries", entries.len()); + log::debug!( + "GitIndexCache: loaded {} index entries in {:.3}s", + entries.len(), + timer.elapsed().as_secs_f64() + ); Some(Self { entries }) } + pub fn len(&self) -> usize { + self.entries.len() + } + /// Returns `true` if the new content's blob SHA1 matches the git index /// entry for this path, meaning the file on disk almost certainly /// already has this content. diff --git a/src/serve_session.rs b/src/serve_session.rs index b6e555c4..ded1c72c 100644 --- a/src/serve_session.rs +++ b/src/serve_session.rs @@ -127,6 +127,11 @@ pub struct ServeSession { /// Used as diff baseline so that files committed after session start /// still appear in `changedIds` for auto-select defaults. initial_head_commit: Option, + + /// Filesystem paths discovered during prefetch walk (non-root entries). + /// Available for syncback to reuse for orphan detection, avoiding a + /// redundant walkdir. + prefetch_walked_paths: Option>, } /// Collect all filesystem paths reachable from the project tree's `$path` @@ -321,12 +326,18 @@ pub fn collect_path_roots(node: &crate::project::ProjectNode, base: &Path, out: impl ServeSession { /// Shared initialization: loads the project and builds the initial /// snapshot tree. Used by both `new()` and `new_oneshot()`. - fn init_tree(vfs: &Vfs, start_path: &Path) -> Result<(Project, RojoTree), ServeSessionError> { + /// Returns the walked paths from prefetch (if available) for syncback reuse. + fn init_tree( + vfs: &Vfs, + start_path: &Path, + ) -> Result<(Project, RojoTree, Option>), ServeSessionError> { log::trace!("Starting new ServeSession at path {}", start_path.display()); let root_project = Project::load_initial_project(vfs, start_path)?; let sync_scripts_only = root_project.sync_scripts_only.unwrap_or(false); + let mut walked_paths: Option> = None; + if std::env::var("ATLAS_SEQUENTIAL").is_err() { let prefetch_start = Instant::now(); match prefetch_project_files(&root_project, sync_scripts_only) { @@ -338,6 +349,46 @@ impl ServeSession { prefetch_start.elapsed() ); if !cache.is_file.is_empty() { + let ignore_rules = root_project.path_ignore_rules(); + let project_path = root_project.folder_location(); + let git_glob = crate::glob::Glob::new(".git/**").unwrap(); + let has_hidden_component = |p: &Path| -> bool { + if let Some(parent) = p.parent() { + for component in parent.components() { + if let Some(name) = component.as_os_str().to_str() { + if name.starts_with('.') { + return true; + } + } + } + } + if let Some(name) = p.file_name().and_then(|n| n.to_str()) { + if name.starts_with('.') && name != ".gitkeep" { + return true; + } + } + false + }; + let paths: HashSet = cache + .is_file + .keys() + .filter(|p| { + let test_path = p.strip_prefix(project_path).unwrap_or(p); + if git_glob.is_match(test_path) { + return false; + } + if has_hidden_component(test_path) { + return false; + } + ignore_rules.iter().all(|rule| rule.passes(p)) + }) + .cloned() + .collect(); + log::info!( + "[PERF] captured {} walked paths from prefetch for orphan reuse", + paths.len() + ); + walked_paths = Some(paths); vfs.set_prefetch_cache(cache); } } @@ -432,7 +483,7 @@ impl ServeSession { }); log::debug!("Watch + patch in {:.1?}", patch_start.elapsed()); - Ok((root_project, tree)) + Ok((root_project, tree, walked_paths)) } /// Start a new serve session from the given in-memory filesystem and start @@ -449,7 +500,7 @@ impl ServeSession { let start_path = start_path.as_ref(); let start_time = Instant::now(); - let (root_project, tree) = Self::init_tree(&vfs, start_path)?; + let (root_project, tree, _walked_paths) = Self::init_tree(&vfs, start_path)?; let session_id = SessionId::new(); let message_queue = MessageQueue::new(); @@ -512,6 +563,7 @@ impl ServeSession { ref_path_index: Some(ref_path_index), git_repo_root, initial_head_commit, + prefetch_walked_paths: None, }) } @@ -524,7 +576,7 @@ impl ServeSession { let start_path = start_path.as_ref(); let start_time = Instant::now(); - let (root_project, tree) = Self::init_tree(&vfs, start_path)?; + let (root_project, tree, walked_paths) = Self::init_tree(&vfs, start_path)?; Ok(Self { change_processor: None, @@ -539,9 +591,14 @@ impl ServeSession { ref_path_index: None, git_repo_root: None, initial_head_commit: None, + prefetch_walked_paths: walked_paths, }) } + pub fn take_walked_paths(&mut self) -> Option> { + self.prefetch_walked_paths.take() + } + pub fn tree_handle(&self) -> Arc> { Arc::clone(&self.tree) } diff --git a/src/syncback/fs_snapshot.rs b/src/syncback/fs_snapshot.rs index b08839cb..ed23e3de 100644 --- a/src/syncback/fs_snapshot.rs +++ b/src/syncback/fs_snapshot.rs @@ -291,6 +291,16 @@ impl FsSnapshot { ) -> io::Result<()> { let base_path = base.as_ref(); + log::info!( + "[PERF] write_to_vfs_parallel: {} files, {} dirs to add; {} files, {} dirs to remove", + self.added_files.len(), + self.added_dirs.len(), + self.removed_files.len(), + self.removed_dirs.len(), + ); + + let phase1_timer = std::time::Instant::now(); + // Phase 1: Create directories (sequential - parent must exist before child) let skipped_dirs = AtomicUsize::new(0); { @@ -308,11 +318,21 @@ impl FsSnapshot { }; } } // Release lock before parallel phase + log::info!( + "[PERF] phase1 create dirs: {:.3}s", + phase1_timer.elapsed().as_secs_f64() + ); + + let phase2_timer = std::time::Instant::now(); // Phase 2: Write files (parallel - independent operations) let write_errors = AtomicUsize::new(0); let first_error: std::sync::Mutex> = std::sync::Mutex::new(None); let skipped_files = AtomicUsize::new(0); + let git_skipped = AtomicUsize::new(0); + let byte_skipped = AtomicUsize::new(0); + + let size_skipped = AtomicUsize::new(0); self.added_files.par_iter().for_each(|(path, contents)| { let full_path = base_path.join(path); @@ -320,16 +340,24 @@ impl FsSnapshot { if let Some(cache) = git_cache { if cache.file_matches_index(path, contents) { skipped_files.fetch_add(1, Ordering::Relaxed); + git_skipped.fetch_add(1, Ordering::Relaxed); return; } } - match std::fs::read(&full_path) { - Ok(existing) if existing == *contents => { - skipped_files.fetch_add(1, Ordering::Relaxed); - return; + match std::fs::metadata(&full_path) { + Ok(meta) if meta.len() != contents.len() as u64 => { + size_skipped.fetch_add(1, Ordering::Relaxed); } - _ => {} + Ok(_) => match std::fs::read(&full_path) { + Ok(existing) if existing == *contents => { + skipped_files.fetch_add(1, Ordering::Relaxed); + byte_skipped.fetch_add(1, Ordering::Relaxed); + return; + } + _ => {} + }, + Err(_) => {} } if let Err(err) = write_with_retry(&full_path, contents) { @@ -341,6 +369,14 @@ impl FsSnapshot { } }); + log::info!( + "[PERF] phase2 write files: {:.3}s (git_skip={}, byte_skip={}, size_diff={})", + phase2_timer.elapsed().as_secs_f64(), + git_skipped.load(Ordering::Relaxed), + byte_skipped.load(Ordering::Relaxed), + size_skipped.load(Ordering::Relaxed), + ); + // Check for write errors if let Some(err) = first_error.into_inner().unwrap() { let error_count = write_errors.load(Ordering::Relaxed); @@ -350,8 +386,9 @@ impl FsSnapshot { return Err(err); } + let phase3_timer = std::time::Instant::now(); + // Phase 3: Remove files not inside removed directories (parallel) - // Uses retry logic on Windows for transient errors. let files_to_remove: Vec<_> = self .removed_files .iter() @@ -372,6 +409,11 @@ impl FsSnapshot { } }); + log::info!( + "[PERF] phase3 remove files: {:.3}s", + phase3_timer.elapsed().as_secs_f64() + ); + // Check for remove errors if let Some(err) = first_remove_error.into_inner().unwrap() { let error_count = remove_errors.load(Ordering::Relaxed); @@ -384,6 +426,8 @@ impl FsSnapshot { return Err(err); } + let phase4_timer = std::time::Instant::now(); + // Phase 4: Remove directories (sequential - uses VFS for proper unwatch handling) { let mut lock = vfs.lock(); @@ -402,6 +446,11 @@ impl FsSnapshot { } } + log::info!( + "[PERF] phase4 remove dirs: {:.3}s", + phase4_timer.elapsed().as_secs_f64() + ); + let skipped_file_count = skipped_files.load(Ordering::Relaxed); let skipped_dir_count = skipped_dirs.load(Ordering::Relaxed); let written_files = self.added_files.len() - skipped_file_count; diff --git a/src/syncback/mod.rs b/src/syncback/mod.rs index 9b04685a..85684c70 100644 --- a/src/syncback/mod.rs +++ b/src/syncback/mod.rs @@ -97,11 +97,34 @@ pub fn syncback_loop( project: &Project, incremental: bool, ) -> anyhow::Result { - syncback_loop_with_stats(vfs, old_tree, new_tree, project, incremental, None) + syncback_loop_with_stats(vfs, old_tree, new_tree, project, incremental, None, None) +} + +pub fn syncback_loop_with_walked_paths( + vfs: &Vfs, + old_tree: &mut RojoTree, + new_tree: WeakDom, + project: &Project, + incremental: bool, + pre_walked_paths: Option>, +) -> anyhow::Result { + syncback_loop_with_stats( + vfs, + old_tree, + new_tree, + project, + incremental, + None, + pre_walked_paths, + ) } /// Runs the syncback loop with an optional external stats tracker. /// If no stats are provided, an internal one is created and logged at the end. +/// +/// `pre_walked_paths`: If provided, these paths are used for orphan detection +/// instead of re-walking the filesystem. Avoids a redundant walkdir when the +/// caller has already enumerated the project files (e.g. via prefetch). pub fn syncback_loop_with_stats( vfs: &Vfs, old_tree: &mut RojoTree, @@ -109,6 +132,7 @@ pub fn syncback_loop_with_stats( project: &Project, incremental: bool, external_stats: Option<&SyncbackStats>, + pre_walked_paths: Option>, ) -> anyhow::Result { // Create internal stats if not provided externally let internal_stats = SyncbackStats::new(); @@ -130,11 +154,11 @@ pub fn syncback_loop_with_stats( // Collect all instance paths BEFORE pruning so we can track external references // (references to instances that will be pruned, like SoundGroups in SoundService). - log::debug!("Collecting instance paths before pruning..."); + log::info!("[PERF] syncback_loop entered"); let pre_prune_paths = collect_all_paths(&new_tree); - log::debug!( - "syncback: collect_all_paths in {:.1?}", - phase_timer.elapsed() + log::info!( + "[PERF] collect_all_paths: {:.3}s", + phase_timer.elapsed().as_secs_f64() ); // TODO: Add a better way to tell if the root of a project is a directory @@ -171,14 +195,17 @@ pub fn syncback_loop_with_stats( if ignore_hidden { strip_hidden_services(&mut new_tree); } - log::debug!("syncback: prune + filter in {:.1?}", phase_timer.elapsed()); + log::info!( + "[PERF] prune + filter: {:.3}s", + phase_timer.elapsed().as_secs_f64() + ); let phase_timer = std::time::Instant::now(); let mut deferred_referents = collect_referents(&new_tree, &pre_prune_paths, None); let placeholder_map = std::mem::take(&mut deferred_referents.placeholder_to_source_and_target); - log::debug!( - "syncback: collect_referents in {:.1?}", - phase_timer.elapsed() + log::info!( + "[PERF] collect_referents: {:.3}s", + phase_timer.elapsed().as_secs_f64() ); let phase_timer = std::time::Instant::now(); @@ -235,211 +262,206 @@ pub fn syncback_loop_with_stats( if !ignore_referents { link_referents(deferred_referents, &mut new_tree)?; } - log::debug!( - "syncback: filter props + link refs in {:.1?}", - phase_timer.elapsed() + log::info!( + "[PERF] filter props + link refs: {:.3}s", + phase_timer.elapsed().as_secs_f64() ); new_tree.root_mut().name = old_tree.root().name().to_string(); let phase_timer = std::time::Instant::now(); - let (old_hashes, new_hashes) = rayon::join( - || hash_tree(project, old_tree.inner(), old_tree.get_root_id()), - || hash_tree(project, &new_tree, new_tree.root_ref()), - ); - log::debug!( - "syncback: hash both trees (parallel) in {:.1?}", - phase_timer.elapsed() - ); + let (old_hashes, new_hashes) = if incremental { + let result = rayon::join( + || hash_tree(project, old_tree.inner(), old_tree.get_root_id()), + || hash_tree(project, &new_tree, new_tree.root_ref()), + ); + log::info!( + "[PERF] hash both trees (parallel): {:.3}s", + phase_timer.elapsed().as_secs_f64() + ); + result + } else { + log::info!("[PERF] hash skipped (clean mode)"); + (HashMap::new(), HashMap::new()) + }; let project_path = project.folder_location(); let phase_timer = std::time::Instant::now(); let existing_paths: HashSet = if !incremental { - let mut paths = HashSet::new(); + if let Some(pre_walked) = pre_walked_paths.filter(|p| p.len() > 100) { + log::info!( + "[PERF] orphan scan: reusing {} pre-walked paths", + pre_walked.len() + ); + pre_walked + } else { + let mut paths = HashSet::new(); - // Get the source directories from the project's tree structure. - // We need to collect ALL $path directories defined in the project, - // not just instigating_source metadata (which may point to project file). - let mut dirs_to_scan: Vec = Vec::new(); + // Get the source directories from the project's tree structure. + // We need to collect ALL $path directories defined in the project, + // not just instigating_source metadata (which may point to project file). + let mut dirs_to_scan: Vec = Vec::new(); - // Helper to recursively collect $path DIRECTORY entries from project tree - // Only directories need to be scanned for orphan detection; single files - // don't contain orphans that need to be removed. - fn collect_paths_from_project( - node: &crate::project::ProjectNode, - base_path: &Path, - paths: &mut Vec, - ) { - // If this node has a $path that points to a directory, add it - if let Some(ref path_node) = node.path { - let resolved = base_path.join(path_node.path()); - // Only add directories - single files don't need orphan scanning - if resolved.is_dir() && !paths.contains(&resolved) { - log::trace!("Found $path directory in project: {}", resolved.display()); - paths.push(resolved); + // Recursively collect $path DIRECTORY entries from project tree. + // Only directories need to be scanned for orphan detection. + fn collect_paths_from_project( + node: &crate::project::ProjectNode, + base_path: &Path, + paths: &mut Vec, + ) { + if let Some(ref path_node) = node.path { + let resolved = base_path.join(path_node.path()); + if resolved.is_dir() && !paths.contains(&resolved) { + log::trace!("Found $path directory in project: {}", resolved.display()); + paths.push(resolved); + } + } + for child in node.children.values() { + collect_paths_from_project(child, base_path, paths); } } - // Recursively check children - for child in node.children.values() { - collect_paths_from_project(child, base_path, paths); - } - } - // Collect paths from the project tree definition - collect_paths_from_project(&project.tree, project_path, &mut dirs_to_scan); + collect_paths_from_project(&project.tree, project_path, &mut dirs_to_scan); - // NOTE: We intentionally do NOT scan the project root folder itself. - // Only directories explicitly referenced via $path should be scanned. - // Scanning the root would delete unrelated files like .gitignore, README.md, etc. - // - // However, we DO need to collect alternate file representations of $path entries. - // For example, if $path: "src" expects a directory, but "src.luau" exists as a file - // (perhaps the user accidentally converted the directory to a file), that orphan - // file should be removed. We collect these as individual files to check, not as - // directories to scan recursively. - let mut orphan_files_to_check: Vec = Vec::new(); + // Collect alternate file representations of $path entries. + // e.g., if $path: "src" expects a directory, but "src.luau" exists as a file, + // that orphan file should be removed. + let mut orphan_files_to_check: Vec = Vec::new(); - // Helper to find alternate file extensions for a path - fn collect_alternate_files( - node: &crate::project::ProjectNode, - base_path: &Path, - files: &mut Vec, - ) { - if let Some(ref path_node) = node.path { - let path_str = path_node.path(); - let resolved = base_path.join(path_str); + fn collect_alternate_files( + node: &crate::project::ProjectNode, + base_path: &Path, + files: &mut Vec, + ) { + if let Some(ref path_node) = node.path { + let path_str = path_node.path(); + let resolved = base_path.join(path_str); - // If the $path points to a directory, check for file alternates - if resolved.is_dir() { - // Common Rojo file extensions that could be alternates - let extensions = [ - ".luau", - ".lua", - ".server.luau", - ".server.lua", - ".client.luau", - ".client.lua", - ".local.luau", - ".local.lua", - ]; - for ext in extensions { - // Create alternate filename by appending extension to path name - let path_str_display = path_str.display().to_string(); - let alt_file = base_path.join(format!("{}{}", path_str_display, ext)); - if alt_file.exists() && alt_file.is_file() { - log::trace!( - "Found alternate file for $path '{}': {}", - path_str_display, - alt_file.display() - ); - files.push(alt_file); + if resolved.is_dir() { + let extensions = [ + ".luau", + ".lua", + ".server.luau", + ".server.lua", + ".client.luau", + ".client.lua", + ".local.luau", + ".local.lua", + ]; + for ext in extensions { + let path_str_display = path_str.display().to_string(); + let alt_file = base_path.join(format!("{}{}", path_str_display, ext)); + if alt_file.exists() && alt_file.is_file() { + log::trace!( + "Found alternate file for $path '{}': {}", + path_str_display, + alt_file.display() + ); + files.push(alt_file); + } } } } - } - for child in node.children.values() { - collect_alternate_files(child, base_path, files); - } - } - collect_alternate_files(&project.tree, project_path, &mut orphan_files_to_check); - - // Also check instance metadata for paths that might not be in project - // (e.g., from nested project references) - let root = old_tree.root(); - log::trace!( - "Root instance: name={}, class={}", - root.name(), - root.class_name() - ); - if let Some(source) = &root.metadata().instigating_source { - let path = source.path(); - // Skip project files - we want source directories - if !path.to_string_lossy().ends_with(".project.json5") - && !path.to_string_lossy().ends_with(".project.json") - { - log::trace!("Root has instigating_source: {}", path.display()); - if path.exists() && !dirs_to_scan.contains(&path.to_path_buf()) { - dirs_to_scan.push(path.to_path_buf()); + for child in node.children.values() { + collect_alternate_files(child, base_path, files); } } - } + collect_alternate_files(&project.tree, project_path, &mut orphan_files_to_check); - // Check children for additional paths - for ref_id in old_tree.inner().root().children() { - if let Some(inst) = old_tree.get_instance(*ref_id) { - if let Some(source) = &inst.metadata().instigating_source { - let path = source.path(); - if !path.to_string_lossy().ends_with(".project.json5") - && !path.to_string_lossy().ends_with(".project.json") - && path.exists() - && !dirs_to_scan.contains(&path.to_path_buf()) - { + // Check instance metadata for paths that might not be in the project + // (e.g., from nested project references) + let root = old_tree.root(); + log::trace!( + "Root instance: name={}, class={}", + root.name(), + root.class_name() + ); + if let Some(source) = &root.metadata().instigating_source { + let path = source.path(); + if !path.to_string_lossy().ends_with(".project.json5") + && !path.to_string_lossy().ends_with(".project.json") + { + log::trace!("Root has instigating_source: {}", path.display()); + if path.exists() && !dirs_to_scan.contains(&path.to_path_buf()) { dirs_to_scan.push(path.to_path_buf()); } } } - } - if log::log_enabled!(log::Level::Trace) { - let dirs_str: Vec<_> = dirs_to_scan - .iter() - .map(|p| p.display().to_string()) - .collect(); - log::trace!("dirs_to_scan: {:?}", dirs_str); - } - - for dir in &dirs_to_scan { - if !dir.is_dir() { - continue; - } - if let Some(name) = dir.file_name().and_then(|n| n.to_str()) { - if name.starts_with('.') && name != ".gitkeep" { - continue; - } - } - for entry in walkdir::WalkDir::new(dir) - .follow_links(true) - .into_iter() - .filter_entry(|e| { - if e.depth() == 0 { - return true; + for ref_id in old_tree.inner().root().children() { + if let Some(inst) = old_tree.get_instance(*ref_id) { + if let Some(source) = &inst.metadata().instigating_source { + let path = source.path(); + if !path.to_string_lossy().ends_with(".project.json5") + && !path.to_string_lossy().ends_with(".project.json") + && path.exists() + && !dirs_to_scan.contains(&path.to_path_buf()) + { + dirs_to_scan.push(path.to_path_buf()); + } } - e.file_name() - .to_str() - .is_none_or(|n| !n.starts_with('.') || n == ".gitkeep") - }) - .flatten() - { - if entry.depth() == 0 { + } + } + + if log::log_enabled!(log::Level::Trace) { + let dirs_str: Vec<_> = dirs_to_scan + .iter() + .map(|p| p.display().to_string()) + .collect(); + log::trace!("dirs_to_scan: {:?}", dirs_str); + } + + for dir in &dirs_to_scan { + if !dir.is_dir() { continue; } - let path = entry.path().to_path_buf(); - if !is_valid_path(&ignore_patterns, project_path, &path) { + if let Some(name) = dir.file_name().and_then(|n| n.to_str()) { + if name.starts_with('.') && name != ".gitkeep" { + continue; + } + } + for entry in walkdir::WalkDir::new(dir) + .follow_links(true) + .into_iter() + .filter_entry(|e| { + if e.depth() == 0 { + return true; + } + e.file_name() + .to_str() + .is_none_or(|n| !n.starts_with('.') || n == ".gitkeep") + }) + .flatten() + { + if entry.depth() == 0 { + continue; + } + let path = entry.path().to_path_buf(); + if !is_valid_path(&ignore_patterns, project_path, &path) { + continue; + } + paths.insert(path); + } + } + + for file in &orphan_files_to_check { + if !is_valid_path(&ignore_patterns, project_path, file) { continue; } - paths.insert(path); + log::trace!("Adding alternate file to orphan check: {}", file.display()); + paths.insert(file.clone()); } - } - // Also add any alternate file representations we found earlier - // (e.g., src.luau when $path: "src" is a directory) - for file in &orphan_files_to_check { - if !is_valid_path(&ignore_patterns, project_path, file) { - continue; - } - log::trace!("Adding alternate file to orphan check: {}", file.display()); - paths.insert(file.clone()); - } - - log::debug!("Scanned {} existing paths from filesystem", paths.len()); - paths + log::debug!("Scanned {} existing paths from filesystem", paths.len()); + paths + } // end else (no pre_walked_paths) } else { HashSet::new() }; - log::debug!( - "syncback: orphan scan in {:.1?} ({} paths)", - phase_timer.elapsed(), + log::info!( + "[PERF] orphan scan: {:.3}s ({} paths)", + phase_timer.elapsed().as_secs_f64(), existing_paths.len() ); @@ -468,9 +490,16 @@ pub fn syncback_loop_with_stats( let mut fs_snapshot = FsSnapshot::new(); let mut instance_paths: HashMap> = HashMap::new(); + let mut walk_count: usize = 0; + let mut walk_syncback_ns: u128 = 0; + let mut walk_merge_ns: u128 = 0; + let mut walk_path_ns: u128 = 0; 'syncback: while let Some(snapshot) = snapshots.pop() { + walk_count += 1; + let path_start = std::time::Instant::now(); let inst_path = snapshot.get_new_inst_path(snapshot.new); + walk_path_ns += path_start.elapsed().as_nanos(); // In incremental mode, we can quickly check that two subtrees are identical // and if they are, skip reconciling them. In clean mode, we always process // all instances to ensure fresh structure. @@ -517,6 +546,7 @@ pub fn syncback_loop_with_stats( continue; } + let syncback_start = std::time::Instant::now(); let syncback = match middleware.syncback(&snapshot) { Ok(syncback) => syncback, Err(err) if middleware == Middleware::Dir => { @@ -551,6 +581,8 @@ pub fn syncback_loop_with_stats( Err(err) => anyhow::bail!("Failed to syncback {inst_path} because {err}"), }; + walk_syncback_ns += syncback_start.elapsed().as_nanos(); + if !syncback.removed_children.is_empty() { log::debug!( "removed children for {inst_path}: {}", @@ -603,13 +635,22 @@ pub fn syncback_loop_with_stats( instance_paths.insert(snapshot.new, files_for_instance); } + let merge_start = std::time::Instant::now(); fs_snapshot.merge_with_filter(syncback.fs_snapshot, |path| { is_valid_path(&ignore_patterns, project_path, path) }); + walk_merge_ns += merge_start.elapsed().as_nanos(); snapshots.extend(syncback.children); } - log::debug!("syncback: main walk loop in {:.1?}", phase_timer.elapsed()); + log::info!( + "[PERF] main walk loop: {:.3}s ({} instances, syncback={:.3}s, merge={:.3}s, path={:.3}s)", + phase_timer.elapsed().as_secs_f64(), + walk_count, + walk_syncback_ns as f64 / 1e9, + walk_merge_ns as f64 / 1e9, + walk_path_ns as f64 / 1e9, + ); let phase_timer = std::time::Instant::now(); { @@ -629,19 +670,19 @@ pub fn syncback_loop_with_stats( let relative = crate::compute_relative_ref_path(&source_abs, &target_abs); substitutions.push((placeholder.clone(), relative)); } - log::debug!( - "syncback: built {} ref substitutions in {:.1?}", - substitutions.len(), - phase_timer.elapsed() + log::info!( + "[PERF] build ref substitutions: {:.3}s (count={})", + phase_timer.elapsed().as_secs_f64(), + substitutions.len() ); let sub_timer = std::time::Instant::now(); if !substitutions.is_empty() { fs_snapshot.fix_ref_paths(&substitutions); } - log::debug!( - "syncback: applied ref substitutions in {:.1?}", - sub_timer.elapsed() + log::info!( + "[PERF] apply ref substitutions: {:.3}s", + sub_timer.elapsed().as_secs_f64() ); } @@ -870,7 +911,10 @@ pub fn syncback_loop_with_stats( } } - log::debug!("syncback: orphan removal in {:.1?}", phase_timer.elapsed()); + log::info!( + "[PERF] orphan removal: {:.3}s", + phase_timer.elapsed().as_secs_f64() + ); if external_stats.is_none() { stats.log_summary(); diff --git a/src/syncback/ref_properties.rs b/src/syncback/ref_properties.rs index b62ce232..8f17d555 100644 --- a/src/syncback/ref_properties.rs +++ b/src/syncback/ref_properties.rs @@ -172,14 +172,28 @@ struct IdRefLink { /// Collects all instance paths in a WeakDom before any pruning occurs. /// Returns a map of Ref -> filesystem-name-compatible path for all instances. pub fn collect_all_paths(dom: &WeakDom) -> HashMap { + let root_ref = dom.root_ref(); let mut paths = HashMap::new(); let mut queue = VecDeque::new(); - queue.push_back(dom.root_ref()); + + paths.insert(root_ref, String::new()); + queue.push_back(root_ref); while let Some(inst_ref) = queue.pop_front() { let inst = dom.get_by_ref(inst_ref).unwrap(); - queue.extend(inst.children().iter().copied()); - paths.insert(inst_ref, tentative_fs_path(dom, inst_ref)); + let parent_path = paths.get(&inst_ref).unwrap().clone(); + + for &child_ref in inst.children() { + let child = dom.get_by_ref(child_ref).unwrap(); + let segment = tentative_fs_name(child); + let child_path = if parent_path.is_empty() { + segment + } else { + format!("{}/{}", parent_path, segment) + }; + paths.insert(child_ref, child_path); + queue.push_back(child_ref); + } } paths