From a2c7968c60a02b5023d3fdc4177133fc1c8fe7f2 Mon Sep 17 00:00:00 2001 From: Joe Date: Sat, 7 Mar 2026 16:55:20 -0600 Subject: [PATCH] refactor: update git index refresh to a no-op and change logging level to debug The `refresh_git_index` function is now a no-op, as the previous implementation added unnecessary latency without meaningful benefits. Additionally, logging levels for performance metrics have been changed from info to debug across various modules to reduce verbosity and improve performance during normal operations. --- src/cli/serve.rs | 2 -- src/cli/syncback.rs | 19 ++++++------------- src/git.rs | 28 +++------------------------- src/serve_session.rs | 2 +- src/syncback/fs_snapshot.rs | 10 +++++----- src/syncback/mod.rs | 26 +++++++++++++------------- 6 files changed, 28 insertions(+), 59 deletions(-) diff --git a/src/cli/serve.rs b/src/cli/serve.rs index eb4933c9..dc812327 100644 --- a/src/cli/serve.rs +++ b/src/cli/serve.rs @@ -145,8 +145,6 @@ pub(crate) fn run_live_syncback( removed ); - crate::git::refresh_git_index(base_path); - drop(session_old); Ok(SyncbackStats { added, removed }) diff --git a/src/cli/syncback.rs b/src/cli/syncback.rs index 1de59e06..656fa25e 100644 --- a/src/cli/syncback.rs +++ b/src/cli/syncback.rs @@ -159,14 +159,14 @@ impl SyncbackCommand { let dom_start_timer = Instant::now(); let dom_new = read_dom(&path_new, input_kind)?; let dom_elapsed = dom_start_timer.elapsed(); - log::info!("[PERF] parse rbxl: {:.3}s", dom_elapsed.as_secs_f64()); + log::debug!("[PERF] parse rbxl: {:.3}s", dom_elapsed.as_secs_f64()); let vfs = Vfs::new_oneshot(); let project_start_timer = Instant::now(); let mut session_old = ServeSession::new_oneshot(vfs, path_old.clone())?; let project_elapsed = project_start_timer.elapsed(); - log::info!( + log::debug!( "[PERF] init old tree (prefetch+snapshot+patch): {:.3}s", project_elapsed.as_secs_f64() ); @@ -205,7 +205,7 @@ impl SyncbackCommand { pre_walked_paths, )?; let syncback_elapsed = syncback_timer.elapsed(); - log::info!( + log::debug!( "[PERF] syncback_loop total: {:.3}s", syncback_elapsed.as_secs_f64() ); @@ -239,7 +239,7 @@ impl SyncbackCommand { let git_cache_timer = Instant::now(); let git_cache = crate::git::GitIndexCache::new(base_path); - log::info!( + log::debug!( "[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()), @@ -286,7 +286,7 @@ impl SyncbackCommand { git_cache.as_ref(), )?; } - log::info!( + log::debug!( "[PERF] write_to_vfs_parallel: {:.3}s", write_timer.elapsed().as_secs_f64() ); @@ -297,13 +297,6 @@ 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 { match std::fs::remove_file(input_path) { @@ -324,7 +317,7 @@ impl SyncbackCommand { log::info!("Aborting before writing to file system due to `--dry-run`"); } - log::info!( + log::debug!( "[PERF] TOTAL syncback command: {:.3}s", total_timer.elapsed().as_secs_f64() ); diff --git a/src/git.rs b/src/git.rs index 29e5286e..ce8e4351 100644 --- a/src/git.rs +++ b/src/git.rs @@ -674,31 +674,9 @@ pub fn compute_git_metadata( /// Refreshes the git index if the project is in a git repository. /// -/// This is useful because syncback may rewrite files with identical content, -/// which can cause git to report them as modified due to timestamp changes. -pub fn refresh_git_index(project_dir: &Path) { - log::info!("Refreshing git index..."); - let output = match Command::new("git") - .args(["update-index", "--refresh"]) - .current_dir(project_dir) - .output() - { - Ok(o) => o, - Err(e) => { - log::debug!("Failed to run git update-index --refresh: {}", e); - return; - } - }; - - if output.status.success() { - log::info!("Git index refreshed."); - } else { - log::warn!( - "git update-index --refresh failed: {}", - String::from_utf8_lossy(&output.stderr) - ); - } -} +/// Currently a no-op -- `git update-index --refresh` adds latency without +/// meaningful benefit since we already skip unchanged files via hash comparison. +pub fn refresh_git_index(_project_dir: &Path) {} #[cfg(test)] mod tests { diff --git a/src/serve_session.rs b/src/serve_session.rs index 2b5adfe0..50212629 100644 --- a/src/serve_session.rs +++ b/src/serve_session.rs @@ -382,7 +382,7 @@ impl ServeSession { }) .cloned() .collect(); - log::info!( + log::debug!( "[PERF] captured {} walked paths from prefetch ({} roots) for orphan reuse", paths.len(), roots.len() diff --git a/src/syncback/fs_snapshot.rs b/src/syncback/fs_snapshot.rs index ed23e3de..daa1524d 100644 --- a/src/syncback/fs_snapshot.rs +++ b/src/syncback/fs_snapshot.rs @@ -291,7 +291,7 @@ impl FsSnapshot { ) -> io::Result<()> { let base_path = base.as_ref(); - log::info!( + log::debug!( "[PERF] write_to_vfs_parallel: {} files, {} dirs to add; {} files, {} dirs to remove", self.added_files.len(), self.added_dirs.len(), @@ -318,7 +318,7 @@ impl FsSnapshot { }; } } // Release lock before parallel phase - log::info!( + log::debug!( "[PERF] phase1 create dirs: {:.3}s", phase1_timer.elapsed().as_secs_f64() ); @@ -369,7 +369,7 @@ impl FsSnapshot { } }); - log::info!( + log::debug!( "[PERF] phase2 write files: {:.3}s (git_skip={}, byte_skip={}, size_diff={})", phase2_timer.elapsed().as_secs_f64(), git_skipped.load(Ordering::Relaxed), @@ -409,7 +409,7 @@ impl FsSnapshot { } }); - log::info!( + log::debug!( "[PERF] phase3 remove files: {:.3}s", phase3_timer.elapsed().as_secs_f64() ); @@ -446,7 +446,7 @@ impl FsSnapshot { } } - log::info!( + log::debug!( "[PERF] phase4 remove dirs: {:.3}s", phase4_timer.elapsed().as_secs_f64() ); diff --git a/src/syncback/mod.rs b/src/syncback/mod.rs index bf872421..51c7e63e 100644 --- a/src/syncback/mod.rs +++ b/src/syncback/mod.rs @@ -154,9 +154,9 @@ 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::info!("[PERF] syncback_loop entered"); + log::debug!("[PERF] syncback_loop entered"); let pre_prune_paths = collect_all_paths(&new_tree); - log::info!( + log::debug!( "[PERF] collect_all_paths: {:.3}s", phase_timer.elapsed().as_secs_f64() ); @@ -195,7 +195,7 @@ pub fn syncback_loop_with_stats( if ignore_hidden { strip_hidden_services(&mut new_tree); } - log::info!( + log::debug!( "[PERF] prune + filter: {:.3}s", phase_timer.elapsed().as_secs_f64() ); @@ -203,7 +203,7 @@ pub fn syncback_loop_with_stats( 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::info!( + log::debug!( "[PERF] collect_referents: {:.3}s", phase_timer.elapsed().as_secs_f64() ); @@ -262,7 +262,7 @@ pub fn syncback_loop_with_stats( if !ignore_referents { link_referents(deferred_referents, &mut new_tree)?; } - log::info!( + log::debug!( "[PERF] filter props + link refs: {:.3}s", phase_timer.elapsed().as_secs_f64() ); @@ -275,13 +275,13 @@ pub fn syncback_loop_with_stats( || hash_tree(project, old_tree.inner(), old_tree.get_root_id()), || hash_tree(project, &new_tree, new_tree.root_ref()), ); - log::info!( + log::debug!( "[PERF] hash both trees (parallel): {:.3}s", phase_timer.elapsed().as_secs_f64() ); result } else { - log::info!("[PERF] hash skipped (clean mode)"); + log::debug!("[PERF] hash skipped (clean mode)"); (HashMap::new(), HashMap::new()) }; @@ -295,7 +295,7 @@ pub fn syncback_loop_with_stats( .into_iter() .filter(|p| is_valid_path(&ignore_patterns, project_path, p)) .collect(); - log::info!( + log::debug!( "[PERF] orphan scan: reusing pre-walked paths ({} -> {} after syncback filters)", before, filtered.len() @@ -465,7 +465,7 @@ pub fn syncback_loop_with_stats( } else { HashSet::new() }; - log::info!( + log::debug!( "[PERF] orphan scan: {:.3}s ({} paths)", phase_timer.elapsed().as_secs_f64(), existing_paths.len() @@ -649,7 +649,7 @@ pub fn syncback_loop_with_stats( snapshots.extend(syncback.children); } - log::info!( + log::debug!( "[PERF] main walk loop: {:.3}s ({} instances, syncback={:.3}s, merge={:.3}s, path={:.3}s)", phase_timer.elapsed().as_secs_f64(), walk_count, @@ -676,7 +676,7 @@ pub fn syncback_loop_with_stats( let relative = crate::compute_relative_ref_path(&source_abs, &target_abs); substitutions.push((placeholder.clone(), relative)); } - log::info!( + log::debug!( "[PERF] build ref substitutions: {:.3}s (count={})", phase_timer.elapsed().as_secs_f64(), substitutions.len() @@ -686,7 +686,7 @@ pub fn syncback_loop_with_stats( if !substitutions.is_empty() { fs_snapshot.fix_ref_paths(&substitutions); } - log::info!( + log::debug!( "[PERF] apply ref substitutions: {:.3}s", sub_timer.elapsed().as_secs_f64() ); @@ -917,7 +917,7 @@ pub fn syncback_loop_with_stats( } } - log::info!( + log::debug!( "[PERF] orphan removal: {:.3}s", phase_timer.elapsed().as_secs_f64() );