From 4cafc909b0a4d4a9f55c40008ca755cceaf14220 Mon Sep 17 00:00:00 2001 From: Sebastian Thiel Date: Thu, 29 Aug 2024 14:46:58 +0200 Subject: [PATCH] Improve the clarity of performance logs --- .../gitbutler-branch-actions/src/actions.rs | 1 + crates/gitbutler-branch-actions/src/branch.rs | 2 + .../src/branch_manager/branch_creation.rs | 6 ++ .../src/branch_manager/branch_removal.rs | 58 +++++++++++-------- .../src/integration.rs | 1 + .../gitbutler-branch-actions/src/virtual.rs | 51 +++++++++------- crates/gitbutler-diff/src/diff.rs | 7 +-- crates/gitbutler-oplog/src/oplog.rs | 3 +- 8 files changed, 80 insertions(+), 49 deletions(-) diff --git a/crates/gitbutler-branch-actions/src/actions.rs b/crates/gitbutler-branch-actions/src/actions.rs index 801a7a4216..943286371e 100644 --- a/crates/gitbutler-branch-actions/src/actions.rs +++ b/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, diff --git a/crates/gitbutler-branch-actions/src/branch.rs b/crates/gitbutler-branch-actions/src/branch.rs index 67bd1b6512..b7d12c4e09 100644 --- a/crates/gitbutler-branch-actions/src/branch.rs +++ b/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, diff --git a/crates/gitbutler-branch-actions/src/branch_manager/branch_creation.rs b/crates/gitbutler-branch-actions/src/branch_manager/branch_creation.rs index ba491b9226..f588a51d89 100644 --- a/crates/gitbutler-branch-actions/src/branch_manager/branch_creation.rs +++ b/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 diff --git a/crates/gitbutler-branch-actions/src/branch_manager/branch_removal.rs b/crates/gitbutler-branch-actions/src/branch_manager/branch_removal.rs index bba1cb0ef7..3bc14859a8 100644 --- a/crates/gitbutler-branch-actions/src/branch_manager/branch_removal.rs +++ b/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::)>>(); - 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::)>>(); + 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> { let repo = self.ctx.repository(); let target_commit = repo.find_commit(vbranch.head)?; diff --git a/crates/gitbutler-branch-actions/src/integration.rs b/crates/gitbutler-branch-actions/src/integration.rs index d1d8f8f397..a507180826 100644 --- a/crates/gitbutler-branch-actions/src/integration.rs +++ b/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, diff --git a/crates/gitbutler-branch-actions/src/virtual.rs b/crates/gitbutler-branch-actions/src/virtual.rs index dd7beb5f35..02069ac12b 100644 --- a/crates/gitbutler-branch-actions/src/virtual.rs +++ b/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::>>()?; + 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::>>()? + }; 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)); diff --git a/crates/gitbutler-diff/src/diff.rs b/crates/gitbutler-diff/src/diff.rs index 2e9b4e4d34..dc36a1c23d 100644 --- a/crates/gitbutler-diff/src/diff.rs +++ b/crates/gitbutler-diff/src/diff.rs @@ -162,7 +162,7 @@ pub fn workdir(repo: &git2::Repository, commit_oid: git2::Oid) -> Result Result { @@ -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) } diff --git a/crates/gitbutler-oplog/src/oplog.rs b/crates/gitbutler-oplog/src/oplog.rs index 2a4050b96e..0bf35c3c84 100644 --- a/crates/gitbutler-oplog/src/oplog.rs +++ b/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,