add some tracking of time spent in git operations

2 files changed, 21 insertions, 0 deletions

diff --git a/Cargo.toml b/Cargo.toml
index b875d9b..50a3493 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -13,3 +13,6 @@ term = "0.4"
 term_size = "0.3"
 users = "0.6"
 walkdir = "2.1"
+
+[features]
+verbose = []
diff --git a/src/vcs/git.rs b/src/vcs/git.rs
index 05558af..26a64a9 100644
--- a/src/vcs/git.rs
+++ b/src/vcs/git.rs
@@ -16,6 +16,8 @@ pub struct GitInfo {
 
 impl GitInfo {
     pub fn new(git: &git2::Repository) -> GitInfo {
+        #[cfg(feature="verbose")] let now = std::time::Instant::now();
+
         let mut modified_statuses = git2::Status::empty();
         modified_statuses.insert(git2::STATUS_WT_DELETED);
         modified_statuses.insert(git2::STATUS_WT_MODIFIED);
@@ -31,6 +33,8 @@ impl GitInfo {
         let mut new_statuses = git2::Status::empty();
         new_statuses.insert(git2::STATUS_WT_NEW);
 
+        #[cfg(feature="verbose")] let now = talk_about_time(now, "status bitsets");
+
         let mut status_options = git2::StatusOptions::new();
         status_options.include_untracked(true);
         if true {
@@ -41,7 +45,9 @@ impl GitInfo {
             status_options.update_index(false);
             status_options.no_refresh(true);
         }
+        #[cfg(feature="verbose")] let now = talk_about_time(now, "status options");
         let status = git.statuses(Some(&mut status_options));
+        #[cfg(feature="verbose")] let now = talk_about_time(now, "statuses");
         let mut modified_files = false;
         let mut staged_files = false;
         let mut new_files = false;
@@ -58,8 +64,10 @@ impl GitInfo {
                 }
             }
         }
+        #[cfg(feature="verbose")] let now = talk_about_time(now, "status iteration");
 
         let head = git.head();
+        #[cfg(feature="verbose")] let now = talk_about_time(now, "head");
         let commits = head.is_ok();
         let branch = head.ok().and_then(|head| {
             if head.is_branch() {
@@ -78,6 +86,7 @@ impl GitInfo {
                 )
             }
         });
+        #[cfg(feature="verbose")] let now = talk_about_time(now, "branch");
 
         let active_operation = match git.state() {
             git2::RepositoryState::Merge => super::ActiveOperation::Merge,
@@ -97,6 +106,7 @@ impl GitInfo {
             }
             _ => super::ActiveOperation::None,
         };
+        #[cfg(feature="verbose")] let now = talk_about_time(now, "active operation");
 
         let remote_branch_diff = git.head()
             .ok()
@@ -125,6 +135,7 @@ impl GitInfo {
                     })
                 })
             });
+        #[cfg(feature="verbose")] let _ = talk_about_time(now, "remote branch diff");
 
         GitInfo {
             modified_files: modified_files,
@@ -138,6 +149,13 @@ impl GitInfo {
     }
 }
 
+#[cfg(feature="verbose")]
+fn talk_about_time(now: std::time::Instant, what: &str) -> std::time::Instant {
+    let elapsed = now.elapsed();
+    println!("calculating {} took {}.{:09}s", what, elapsed.as_secs(), elapsed.subsec_nanos());
+    std::time::Instant::now()
+}
+
 impl super::VcsInfo for GitInfo {
     fn vcs(&self) -> super::VcsType {
         super::VcsType::Git