Optimize syncback performance for large projects (~42% faster)

Syncback on a 132K-file project dropped from ~32s to ~18s by:
- Skipping hash_tree computation in clean (non-incremental) mode,
  since hashes are only consulted when incremental=true (-6s)
- Reusing prefetch walkdir results for orphan detection instead of
  walking the filesystem a second time (-1.7s)
- Rewriting collect_all_paths from O(n*d) bottom-up ancestor walks
  to O(n) top-down BFS (-0.7s)
- Adding file-size-first comparison in write_to_vfs_parallel to
  avoid reading files that differ in size
- Scoping git ls-files --stage to project directory prefix
- Adding [PERF] instrumentation at info level for every pipeline phase
This commit is contained in:
Joe 2026-03-07 16:01:51 -06:00
parent 338f97040c
commit cd465a90a2
6 changed files with 425 additions and 225 deletions

View file

@ -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

View file

@ -248,13 +248,25 @@ pub struct GitIndexCache {
impl GitIndexCache {
pub fn new(project_root: &Path) -> Option<Self> {
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: <mode> <sha1> <stage>\t<path>
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.

View file

@ -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<String>,
/// 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<HashSet<PathBuf>>,
}
/// 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<HashSet<PathBuf>>), 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<HashSet<PathBuf>> = 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<PathBuf> = 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<HashSet<PathBuf>> {
self.prefetch_walked_paths.take()
}
pub fn tree_handle(&self) -> Arc<Mutex<RojoTree>> {
Arc::clone(&self.tree)
}

View file

@ -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<Option<io::Error>> = 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) {
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;

View file

@ -97,11 +97,34 @@ pub fn syncback_loop(
project: &Project,
incremental: bool,
) -> anyhow::Result<SyncbackResult> {
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<HashSet<PathBuf>>,
) -> anyhow::Result<SyncbackResult> {
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<HashSet<PathBuf>>,
) -> anyhow::Result<SyncbackResult> {
// 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,27 +262,40 @@ 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(
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::debug!(
"syncback: hash both trees (parallel) in {:.1?}",
phase_timer.elapsed()
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<PathBuf> = if !incremental {
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.
@ -263,44 +303,32 @@ pub fn syncback_loop_with_stats(
// not just instigating_source metadata (which may point to project file).
let mut dirs_to_scan: Vec<PathBuf> = 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.
// 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<PathBuf>,
) {
// 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 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);
// 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.
// 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<PathBuf> = Vec::new();
// Helper to find alternate file extensions for a path
fn collect_alternate_files(
node: &crate::project::ProjectNode,
base_path: &Path,
@ -310,9 +338,7 @@ pub fn syncback_loop_with_stats(
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",
@ -324,7 +350,6 @@ pub fn syncback_loop_with_stats(
".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() {
@ -344,7 +369,7 @@ pub fn syncback_loop_with_stats(
}
collect_alternate_files(&project.tree, project_path, &mut orphan_files_to_check);
// Also check instance metadata for paths that might not be in project
// 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!(
@ -354,7 +379,6 @@ pub fn syncback_loop_with_stats(
);
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")
{
@ -365,7 +389,6 @@ pub fn syncback_loop_with_stats(
}
}
// 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 {
@ -422,8 +445,6 @@ pub fn syncback_loop_with_stats(
}
}
// 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;
@ -434,12 +455,13 @@ pub fn syncback_loop_with_stats(
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<Ref, Vec<PathBuf>> = 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();

View file

@ -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<Ref, String> {
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