Improve the clarity of performance logs

Author: Byron

crates/gitbutler-branch-actions/src/actions.rs

@@ -570,6 +570,7 @@ impl VirtualBranchActions {
         branch::move_commit(&ctx, target_branch_id, commit_oid).map_err(Into::into)
     }
 
+    #[instrument(level = tracing::Level::DEBUG, skip(self, project), err(Debug))]
     pub fn create_virtual_branch_from_branch(
         &self,
         project: &Project,

crates/gitbutler-branch-actions/src/branch.rs

@@ -24,7 +24,9 @@ use std::{
     fmt::Debug,
     vec,
 };
+use tracing::instrument;
 
+#[instrument(level = tracing::Level::DEBUG, skip(ctx, _permission))]
 pub(crate) fn get_uncommited_files_raw(
     ctx: &CommandContext,
     _permission: &WorktreeReadPermission,

crates/gitbutler-branch-actions/src/branch_manager/branch_creation.rs

@@ -9,6 +9,7 @@ use gitbutler_project::access::WorktreeWritePermission;
 use gitbutler_reference::{Refname, RemoteRefname};
 use gitbutler_repo::{rebase::cherry_rebase, RepoActionsExt, RepositoryExt};
 use gitbutler_time::time::now_since_unix_epoch_ms;
+use tracing::instrument;
 
 use super::BranchManager;
 use crate::{
@@ -20,6 +21,7 @@ use crate::{
 };
 
 impl BranchManager<'_> {
+    #[instrument(level = tracing::Level::DEBUG, skip(self, perm), err(Debug))]
     pub fn create_virtual_branch(
         &self,
         create: &BranchCreateRequest,
@@ -281,6 +283,7 @@ impl BranchManager<'_> {
 
 /// Holding private methods associated to branch creation
 impl BranchManager<'_> {
+    #[instrument(level = tracing::Level::DEBUG, skip(self, perm), err(Debug))]
     fn apply_branch(
         &self,
         branch_id: BranchId,
@@ -310,6 +313,7 @@ impl BranchManager<'_> {
                 default_target.sha, branch.head
             ))?;
         if merge_base != default_target.sha {
+            let _span = tracing::debug_span!("merge-base isn't default-target").entered();
             // Branch is out of date, merge or rebase it
             let merge_base_tree = repo
                 .find_commit(merge_base)
@@ -454,6 +458,8 @@ impl BranchManager<'_> {
             vb_state.set_branch(branch.clone())?;
         }
 
+        let _span = tracing::debug_span!("finalize").entered();
+
         let wd_tree = self.ctx.repository().create_wd_tree()?;
 
         let branch_tree = repo

crates/gitbutler-branch-actions/src/branch_manager/branch_removal.rs

@@ -8,6 +8,7 @@ use gitbutler_oplog::SnapshotExt;
 use gitbutler_project::access::WorktreeWritePermission;
 use gitbutler_reference::{normalize_branch_name, ReferenceName, Refname};
 use gitbutler_repo::{RepoActionsExt, RepositoryExt};
+use tracing::instrument;
 
 use super::BranchManager;
 use crate::{
@@ -19,6 +20,7 @@ use crate::{
 
 impl BranchManager<'_> {
     // to unapply a branch, we need to write the current tree out, then remove those file changes from the wd
+    #[instrument(level = tracing::Level::DEBUG, skip(self, perm), err(Debug))]
     pub fn convert_to_real_branch(
         &self,
         branch_id: BranchId,
@@ -52,6 +54,7 @@ impl BranchManager<'_> {
         real_branch.reference_name()
     }
 
+    #[instrument(level = tracing::Level::DEBUG, skip(self, perm), err(Debug))]
     pub(crate) fn delete_branch(
         &self,
         branch_id: BranchId,
@@ -88,30 +91,38 @@ impl BranchManager<'_> {
 
         // go through the other applied branches and merge them into the final tree
         // then check that out into the working directory
-        let final_tree = applied_statuses
-            .into_iter()
-            .filter(|(branch, _)| branch.id != branch_id)
-            .fold(
-                target_commit.tree().context("failed to get target tree"),
-                |final_tree, status| {
-                    let final_tree = final_tree?;
-                    let branch = status.0;
-                    let files = status
-                        .1
-                        .into_iter()
-                        .map(|file| (file.path, file.hunks))
-                        .collect::<Vec<(PathBuf, Vec<VirtualBranchHunk>)>>();
-                    let tree_oid =
-                        gitbutler_diff::write::hunks_onto_oid(self.ctx, branch.head, files)?;
-                    let branch_tree = repo.find_tree(tree_oid)?;
-                    let mut result =
-                        repo.merge_trees(&base_tree, &final_tree, &branch_tree, None)?;
-                    let final_tree_oid = result.write_tree_to(repo)?;
-                    repo.find_tree(final_tree_oid)
-                        .context("failed to find tree")
-                },
-            )?;
+        let final_tree = {
+            let _span = tracing::debug_span!(
+                "new tree without deleted branch",
+                num_branches = applied_statuses.len() - 1
+            )
+            .entered();
+            applied_statuses
+                .into_iter()
+                .filter(|(branch, _)| branch.id != branch_id)
+                .fold(
+                    target_commit.tree().context("failed to get target tree"),
+                    |final_tree, status| {
+                        let final_tree = final_tree?;
+                        let branch = status.0;
+                        let files = status
+                            .1
+                            .into_iter()
+                            .map(|file| (file.path, file.hunks))
+                            .collect::<Vec<(PathBuf, Vec<VirtualBranchHunk>)>>();
+                        let tree_oid =
+                            gitbutler_diff::write::hunks_onto_oid(self.ctx, branch.head, files)?;
+                        let branch_tree = repo.find_tree(tree_oid)?;
+                        let mut result =
+                            repo.merge_trees(&base_tree, &final_tree, &branch_tree, None)?;
+                        let final_tree_oid = result.write_tree_to(repo)?;
+                        repo.find_tree(final_tree_oid)
+                            .context("failed to find tree")
+                    },
+                )?
+        };
 
+        let _span = tracing::debug_span!("checkout final tree").entered();
         // checkout final_tree into the working directory
         repo.checkout_tree_builder(&final_tree)
             .force()
@@ -128,6 +139,7 @@ impl BranchManager<'_> {
 }
 
 impl BranchManager<'_> {
+    #[instrument(level = tracing::Level::DEBUG, skip(self, vbranch), err(Debug))]
     fn build_real_branch(&self, vbranch: &mut Branch) -> Result<git2::Branch<'_>> {
         let repo = self.ctx.repository();
         let target_commit = repo.find_commit(vbranch.head)?;

crates/gitbutler-branch-actions/src/integration.rs

@@ -122,6 +122,7 @@ fn write_integration_file(head: &git2::Reference, path: PathBuf) -> Result<()> {
     std::fs::write(path, format!(":{}", sha))?;
     Ok(())
 }
+#[instrument(level = tracing::Level::DEBUG, skip(vb_state, ctx), err(Debug))]
 pub fn update_gitbutler_integration(
     vb_state: &VirtualBranchesHandle,
     ctx: &CommandContext,

crates/gitbutler-branch-actions/src/virtual.rs

@@ -232,9 +232,9 @@ fn find_base_tree<'a>(
 /// This should only ever be called by `list_virtual_branches
 ///
 /// This checks for the case where !branch.old_applied && branch.in_workspace
-/// If this is the case, we ought to unapply the branch as its been carried
+/// If this is the case, we ought to unapply the branch as it has been carried
 /// over from the old style of unapplying
-fn resolve_old_applied_state(
+fn fixup_old_applied_state(
     ctx: &CommandContext,
     vb_state: &VirtualBranchesHandle,
     perm: &mut WorktreeWritePermission,
@@ -278,7 +278,7 @@ pub fn list_virtual_branches_cached(
 
     let vb_state = ctx.project().virtual_branches();
 
-    resolve_old_applied_state(ctx, &vb_state, perm)?;
+    fixup_old_applied_state(ctx, &vb_state, perm)?;
 
     let default_target = vb_state
         .get_default_target()
@@ -292,6 +292,8 @@ pub fn list_virtual_branches_cached(
         .max()
         .unwrap_or(-1);
 
+    let branches_span =
+        tracing::debug_span!("handle branches", num_branches = status.branches.len()).entered();
     for (branch, mut files) in status.branches {
         let repo = ctx.repository();
         update_conflict_markers(ctx, files.clone())?;
@@ -331,23 +333,31 @@ pub fn list_virtual_branches_cached(
         // find all commits on head that are not on target.sha
         let commits = ctx.log(branch.head, LogUntil::Commit(default_target.sha))?;
         let check_commit = IsCommitIntegrated::new(ctx, &default_target)?;
-        let vbranch_commits = commits
-            .iter()
-            .map(|commit| {
-                is_remote = if is_remote {
-                    is_remote
-                } else {
-                    pushed_commits.contains_key(&commit.id())
-                };
-
-                // only check for integration if we haven't already found an integration
-                if !is_integrated {
-                    is_integrated = check_commit.is_integrated(commit)?
-                };
-
-                commit_to_vbranch_commit(ctx, &branch, commit, is_integrated, is_remote)
-            })
-            .collect::<Result<Vec<_>>>()?;
+        let vbranch_commits = {
+            let _span = tracing::debug_span!(
+                "is-commit-integrated",
+                given_name = branch.name,
+                commits_to_check = commits.len()
+            )
+            .entered();
+            commits
+                .iter()
+                .map(|commit| {
+                    is_remote = if is_remote {
+                        is_remote
+                    } else {
+                        pushed_commits.contains_key(&commit.id())
+                    };
+
+                    // only check for integration if we haven't already found an integration
+                    if !is_integrated {
+                        is_integrated = check_commit.is_integrated(commit)?
+                    };
+
+                    commit_to_vbranch_commit(ctx, &branch, commit, is_integrated, is_remote)
+                })
+                .collect::<Result<Vec<_>>>()?
+        };
 
         let merge_base = repo
             .merge_base(default_target.sha, branch.head)
@@ -409,6 +419,7 @@ pub fn list_virtual_branches_cached(
         };
         branches.push(branch);
     }
+    drop(branches_span);
 
     let mut branches = branches_with_large_files_abridged(branches);
     branches.sort_by(|a, b| a.order.cmp(&b.order));

crates/gitbutler-diff/src/diff.rs

@@ -162,7 +162,7 @@ pub fn workdir(repo: &git2::Repository, commit_oid: git2::Oid) -> Result<DiffByP
 }
 
 pub fn trees(
-    repository: &git2::Repository,
+    repo: &git2::Repository,
     old_tree: &git2::Tree,
     new_tree: &git2::Tree,
 ) -> Result<DiffByPathMap> {
@@ -175,10 +175,7 @@ pub fn trees(
         .context_lines(3)
         .show_untracked_content(true);
 
-    // This is not a content-based diff, but also considers modification times apparently,
-    // maybe related to racy-git. This is why empty diffs have ot be filtered.
-    let diff =
-        repository.diff_tree_to_tree(Some(old_tree), Some(new_tree), Some(&mut diff_opts))?;
+    let diff = repo.diff_tree_to_tree(Some(old_tree), Some(new_tree), Some(&mut diff_opts))?;
     hunks_by_filepath(None, &diff)
 }
 

crates/gitbutler-oplog/src/oplog.rs

@@ -148,7 +148,7 @@ impl OplogExt for Project {
         commit_snapshot(self, snapshot_tree_id, details, perm)
     }
 
-    #[instrument(skip(details, perm), err(Debug))]
+    #[instrument(skip(self, details, perm), err(Debug))]
     fn create_snapshot(
         &self,
         details: SnapshotDetails,
@@ -158,6 +158,7 @@ impl OplogExt for Project {
         commit_snapshot(self, tree_id, details, perm)
     }
 
+    #[instrument(skip(self), err(Debug))]
     fn list_snapshots(
         &self,
         limit: usize,