add top-level --verbose flag with debug output across all commands and internal components

the credential callback had no attempt counter, causing libgit2 to
retry indefinitely when ssh-agent auth failed (hanging on clone).
it also had no fallback to key files on disk, failing when the agent
wasn't running.

replace the stateless cred_callback with make_cred_callback() which
caps retries at 4, tries ssh-agent first then falls back to reading
~/.ssh/id_ed25519, id_rsa, id_ecdsa directly, and returns an error
instead of sending empty credentials for plaintext auth.

src/bridge.rs

@@ -60,18 +60,46 @@ fn save_git_map(path: &std::path::Path, map: &GitMap) -> Result<()> {
     Ok(())
 }
 
-fn cred_callback(
+fn make_cred_callback()
-    _url: &str,
+-> impl FnMut(&str, Option<&str>, git2::CredentialType) -> std::result::Result<git2::Cred, git2::Error>
-    username: Option<&str>,
+{
-    allowed: git2::CredentialType,
+    let mut attempts = 0u32;
-) -> std::result::Result<git2::Cred, git2::Error> {
+    move |_url, username, allowed| {
-    if allowed.contains(git2::CredentialType::SSH_KEY) {
+        attempts += 1;
-        let user = username.unwrap_or("git");
+        if attempts > 4 {
-        git2::Cred::ssh_key_from_agent(user)
+            return Err(git2::Error::from_str("authentication failed"));
-    } else if allowed.contains(git2::CredentialType::USER_PASS_PLAINTEXT) {
+        }
-        git2::Cred::userpass_plaintext("", "")
+
-    } else {
+        if allowed.contains(git2::CredentialType::SSH_KEY) {
-        git2::Cred::default()
+            let user = username.unwrap_or("git");
+
+            if attempts <= 1
+                && let Ok(cred) = git2::Cred::ssh_key_from_agent(user)
+            {
+                return Ok(cred);
+            }
+
+            let home = std::env::var("HOME").unwrap_or_default();
+            let ssh_dir = std::path::Path::new(&home).join(".ssh");
+            for key_name in &["id_ed25519", "id_rsa", "id_ecdsa"] {
+                let key_path = ssh_dir.join(key_name);
+                if key_path.exists() {
+                    let pub_path = ssh_dir.join(format!("{key_name}.pub"));
+                    let pub_key = pub_path.exists().then_some(pub_path.as_path());
+                    if let Ok(cred) = git2::Cred::ssh_key(user, pub_key, &key_path, None) {
+                        return Ok(cred);
+                    }
+                }
+            }
+
+            Err(git2::Error::from_str("no SSH key found"))
+        } else if allowed.contains(git2::CredentialType::USER_PASS_PLAINTEXT) {
+            Err(git2::Error::from_str(
+                "interactive authentication not supported",
+            ))
+        } else {
+            git2::Cred::default()
+        }
     }
 }
 
@@ -79,6 +107,7 @@ impl GitBridge {
     /// Open (or initialise) the shadow git repository and load the mapping cache.
     pub fn open(repo: &Repository) -> Result<Self> {
         let git_dir = shadow_git_dir(repo);
+        debug!("opening git bridge at {}", git_dir.display());
         let git_repo = if git_dir.exists() {
             git2::Repository::open_bare(&git_dir)?
         } else {
@@ -86,6 +115,7 @@ impl GitBridge {
         };
         let map_path = git_map_path(repo);
         let map = load_git_map(&map_path)?;
+        debug!("loaded git map with {} entries", map.arc_to_git.len());
         Ok(Self {
             git_repo,
             map,
@@ -102,7 +132,15 @@ impl GitBridge {
     ///
     /// Returns the git OID for the newly created (or cached) git commit.
     pub fn arc_to_git(&mut self, arc_repo: &Repository, arc_id: &CommitId) -> Result<git2::Oid> {
+        debug!(
+            "converting arc commit {} to git",
+            &arc_id.0[..12.min(arc_id.0.len())]
+        );
         if let Some(hex) = self.map.arc_to_git.get(&arc_id.0) {
+            debug!(
+                "arc commit {} already mapped to git",
+                &arc_id.0[..12.min(arc_id.0.len())]
+            );
             let oid = git2::Oid::from_str(hex)?;
             return Ok(oid);
         }
@@ -131,6 +169,11 @@ impl GitBridge {
             .git_repo
             .commit(None, &sig, &sig, &c.message, &git_tree, &parent_refs)?;
 
+        debug!(
+            "created git commit {} for arc {}",
+            oid,
+            &arc_id.0[..12.min(arc_id.0.len())]
+        );
         self.map
             .arc_to_git
             .insert(arc_id.0.clone(), oid.to_string());
@@ -146,7 +189,15 @@ impl GitBridge {
     /// Returns the arc `CommitId` for the newly created (or cached) commit.
     pub fn git_to_arc(&mut self, arc_repo: &Repository, git_oid: git2::Oid) -> Result<CommitId> {
         let oid_hex = git_oid.to_string();
+        debug!(
+            "converting git commit {} to arc",
+            &oid_hex[..12.min(oid_hex.len())]
+        );
         if let Some(arc_id) = self.map.git_to_arc.get(&oid_hex) {
+            debug!(
+                "git commit {} already mapped to arc",
+                &oid_hex[..12.min(oid_hex.len())]
+            );
             return Ok(CommitId(arc_id.clone()));
         }
 
@@ -208,6 +259,11 @@ impl GitBridge {
         };
         store::write_commit_object(arc_repo, &obj)?;
 
+        debug!(
+            "created arc commit {} for git {}",
+            &commit_id.0[..12.min(commit_id.0.len())],
+            &oid_hex[..12.min(oid_hex.len())]
+        );
         self.map
             .arc_to_git
             .insert(commit_id.0.clone(), oid_hex.clone());
@@ -325,6 +381,7 @@ impl GitBridge {
 ///
 /// Converts all reachable commits, updates shadow refs, and pushes.
 pub fn push(arc_repo: &Repository, remote_name: &str) -> Result<String> {
+    debug!("pushing to remote '{}'", remote_name);
     let remotes = remote::load(arc_repo)?;
     let entry = remotes
         .remotes
@@ -397,7 +454,7 @@ pub fn push(arc_repo: &Repository, remote_name: &str) -> Result<String> {
         let mut git_remote = bridge.git_repo.remote_anonymous(url)?;
         let mut opts = git2::PushOptions::new();
         let mut callbacks = git2::RemoteCallbacks::new();
-        callbacks.credentials(cred_callback);
+        callbacks.credentials(make_cred_callback());
         opts.remote_callbacks(callbacks);
         git_remote.push(&spec_strs, Some(&mut opts))?;
     }
@@ -405,6 +462,7 @@ pub fn push(arc_repo: &Repository, remote_name: &str) -> Result<String> {
     bridge.save_map()?;
 
     let count = ref_specs.len();
+    debug!("pushed {} ref(s)", count);
     Ok(format!("pushed {count} ref(s) to {remote_name}"))
 }
 
@@ -413,6 +471,7 @@ pub fn push(arc_repo: &Repository, remote_name: &str) -> Result<String> {
 /// Fetches, then imports reachable commits for each remote branch
 /// and updates local bookmarks that can be fast-forwarded.
 pub fn pull(arc_repo: &Repository, remote_name: &str) -> Result<String> {
+    debug!("pulling from remote '{}'", remote_name);
     let remotes = remote::load(arc_repo)?;
     let entry = remotes
         .remotes
@@ -426,7 +485,7 @@ pub fn pull(arc_repo: &Repository, remote_name: &str) -> Result<String> {
         let mut git_remote = bridge.git_repo.remote_anonymous(url)?;
         let mut opts = git2::FetchOptions::new();
         let mut callbacks = git2::RemoteCallbacks::new();
-        callbacks.credentials(cred_callback);
+        callbacks.credentials(make_cred_callback());
         opts.remote_callbacks(callbacks);
         git_remote.fetch::<&str>(&[], Some(&mut opts), None)?;
 
@@ -472,6 +531,7 @@ pub fn pull(arc_repo: &Repository, remote_name: &str) -> Result<String> {
         }
         result
     };
+    debug!("fetched {} new ref(s)", refs.len());
 
     for (_refname, oid) in &refs {
         if bridge.map.git_to_arc.contains_key(&oid.to_string()) {
@@ -566,6 +626,7 @@ pub fn pull(arc_repo: &Repository, remote_name: &str) -> Result<String> {
 /// Creates the target directory, initialises an arc repo, imports all
 /// git history, and sets up the worktree at the specified branch.
 pub fn clone(url: &str, path: &str, branch: &str) -> Result<String> {
+    debug!("cloning from '{}'", url);
     let target = std::path::Path::new(path);
     let created_dir = !target.exists();
     if created_dir {
@@ -590,7 +651,7 @@ fn clone_inner(url: &str, target: &std::path::Path, branch: &str) -> Result<Stri
 
     let git_dir = shadow_git_dir(&arc_repo);
     let mut callbacks = git2::RemoteCallbacks::new();
-    callbacks.credentials(cred_callback);
+    callbacks.credentials(make_cred_callback());
     let mut opts = git2::FetchOptions::new();
     opts.remote_callbacks(callbacks);
     let git_repo = git2::build::RepoBuilder::new()
@@ -686,6 +747,11 @@ fn clone_inner(url: &str, target: &std::path::Path, branch: &str) -> Result<Stri
 
     bridge.save_map()?;
 
+    debug!(
+        "cloned {} commit(s) on branch '{}'",
+        bridge.map.arc_to_git.len(),
+        branch
+    );
     Ok(format!(
         "cloned into {} on bookmark '{branch}'",
         target.display()
@@ -697,6 +763,7 @@ fn clone_inner(url: &str, target: &std::path::Path, branch: &str) -> Result<Stri
 /// Creates `.arc/` alongside the existing `.git/`, imports all branches
 /// and tags from git history as arc commits.
 pub fn migrate(path: &std::path::Path) -> Result<String> {
+    debug!("migrating git repository at {}", path.display());
     let git_repo = git2::Repository::discover(path).map_err(|_| ArcError::NotAGitRepo)?;
 
     let workdir = git_repo.workdir().ok_or(ArcError::NotAGitRepo)?;
@@ -735,6 +802,7 @@ pub fn migrate(path: &std::path::Path) -> Result<String> {
         }
         result
     };
+    debug!("found {} git ref(s) to import", refs.len());
 
     let mut bridge = GitBridge {
         git_repo,
@@ -799,6 +867,12 @@ pub fn migrate(path: &std::path::Path) -> Result<String> {
 
     bridge.save_map()?;
 
+    debug!(
+        "migration complete: {} commit(s), {} bookmark(s), {} tag(s)",
+        imported,
+        bookmarks.len(),
+        tags.len()
+    );
     Ok(format!(
         "migrated {imported} commit(s), {} bookmark(s), {} tag(s)",
         bookmarks.len(),
@@ -811,6 +885,7 @@ pub fn migrate(path: &std::path::Path) -> Result<String> {
 /// Without `--push`, this ensures the shadow git repo mirrors arc state.
 /// With `--push`, it also pushes all refs to the default remote.
 pub fn sync(arc_repo: &Repository, do_push: bool) -> Result<String> {
+    debug!("syncing refs to shadow git");
     let mut bridge = GitBridge::open(arc_repo)?;
     let mut synced = 0usize;
 
@@ -855,6 +930,7 @@ pub fn sync(arc_repo: &Repository, do_push: bool) -> Result<String> {
     }
 
     bridge.save_map()?;
+    debug!("synced {} ref(s)", synced);
 
     if do_push {
         let config = crate::config::load_effective(arc_repo);
@@ -869,6 +945,11 @@ pub fn sync(arc_repo: &Repository, do_push: bool) -> Result<String> {
 /// Check whether `ancestor` is an ancestor of `descendant` by walking
 /// the first-parent chain from `descendant`.
 fn is_ancestor(repo: &Repository, ancestor: &CommitId, descendant: &CommitId) -> bool {
+    debug!(
+        "checking if {} is ancestor of {}",
+        &ancestor.0[..12.min(ancestor.0.len())],
+        &descendant.0[..12.min(descendant.0.len())]
+    );
     let mut current = descendant.clone();
     loop {
         if current == *ancestor {

src/cli.rs

@@ -1,5 +1,6 @@
 use std::collections::BTreeMap;
 use std::path::Path;
+use std::sync::atomic::{AtomicBool, Ordering};
 
 use clap::{Parser, Subcommand};
 
@@ -16,9 +17,21 @@ use crate::stash;
 use crate::tracking;
 use crate::ui;
 
+static VERBOSE: AtomicBool = AtomicBool::new(false);
+
+/// Returns whether verbose/debug output is enabled.
+#[allow(dead_code)]
+pub fn verbose() -> bool {
+    VERBOSE.load(Ordering::Relaxed)
+}
+
 #[derive(Parser)]
 #[command(name = "arc", about = "A delta-based version control system", version)]
 pub struct Cli {
+    /// Enable verbose/debug output
+    #[arg(short, long, global = true)]
+    pub verbose: bool,
+
     #[command(subcommand)]
     pub command: Command,
 }
@@ -354,8 +367,11 @@ pub fn parse() -> Cli {
 }
 
 pub fn dispatch(cli: Cli) {
+    VERBOSE.store(cli.verbose, Ordering::Relaxed);
+    debug!("dispatching command");
     match cli.command {
         Command::Init { path } => {
+            debug!("command: init (path: {:?})", path);
             let target = path.as_deref().unwrap_or(".");
             let target_path = Path::new(target);
             if !target_path.exists()
@@ -381,6 +397,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Commit { message } => {
+            debug!("command: commit (message: {})", message);
             let repo = open_repo_or_exit();
             match tracking::commit(&repo, &message) {
                 Ok(id) => {
@@ -396,6 +413,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Log { range } => {
+            debug!("command: log (range: {:?})", range);
             let repo = open_repo_or_exit();
             match inspect::log(&repo, range.as_deref()) {
                 Ok(output) => print!("{output}"),
@@ -406,6 +424,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Status => {
+            debug!("command: status");
             let repo = open_repo_or_exit();
             match tracking::status(&repo) {
                 Ok((report, _)) => {
@@ -418,6 +437,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Diff { range: _range } => {
+            debug!("command: diff (range: {:?})", _range);
             let repo = open_repo_or_exit();
             match run_diff(&repo) {
                 Ok(output) => {
@@ -434,6 +454,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Switch { target } => {
+            debug!("command: switch (target: {})", target);
             let repo = open_repo_or_exit();
             match refs::switch(&repo, &target) {
                 Ok(msg) => println!("{msg}"),
@@ -444,6 +465,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Merge { target } => {
+            debug!("command: merge (target: {})", target);
             let repo = open_repo_or_exit();
             match modify::merge_branch(&repo, &target) {
                 Ok(id) => println!(
@@ -461,6 +483,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Show { target } => {
+            debug!("command: show (target: {})", target);
             let repo = open_repo_or_exit();
             match inspect::show(&repo, &target) {
                 Ok(output) => print!("{output}"),
@@ -471,6 +494,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::History { file, range } => {
+            debug!("command: history (file: {}, range: {:?})", file, range);
             let repo = open_repo_or_exit();
             match inspect::history(&repo, &file, range.as_deref()) {
                 Ok(output) => print!("{output}"),
@@ -481,6 +505,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Revert { target } => {
+            debug!("command: revert (target: {})", target);
             let repo = open_repo_or_exit();
             match modify::revert(&repo, &target) {
                 Ok(id) => println!(
@@ -494,6 +519,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Reset { files } => {
+            debug!("command: reset (files: {:?})", files);
             let repo = open_repo_or_exit();
             match modify::reset(&repo, &files) {
                 Ok(msg) => println!("{msg}"),
@@ -504,6 +530,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Push { remote } => {
+            debug!("command: push (remote: {:?})", remote);
             let repo = open_repo_or_exit();
             let config = config::load_effective(&repo);
             let r = remote.as_deref().unwrap_or(&config.default_remote);
@@ -516,6 +543,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Pull { remote } => {
+            debug!("command: pull (remote: {:?})", remote);
             let repo = open_repo_or_exit();
             let config = config::load_effective(&repo);
             let r = remote.as_deref().unwrap_or(&config.default_remote);
@@ -528,6 +556,10 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Clone { url, path, branch } => {
+            debug!(
+                "command: clone (url: {}, path: {:?}, branch: {:?})",
+                url, path, branch
+            );
             let p = path.as_deref().unwrap_or(".");
             let b = branch.as_deref().unwrap_or("main");
             match bridge::clone(&url, p, b) {
@@ -538,14 +570,18 @@ pub fn dispatch(cli: Cli) {
                 }
             }
         }
-        Command::Migrate => match bridge::migrate(Path::new(".")) {
+        Command::Migrate => {
-            Ok(msg) => println!("{msg}"),
+            debug!("command: migrate");
-            Err(e) => {
+            match bridge::migrate(Path::new(".")) {
-                eprintln!("{}", ui::error(&e.to_string()));
+                Ok(msg) => println!("{msg}"),
-                std::process::exit(1);
+                Err(e) => {
+                    eprintln!("{}", ui::error(&e.to_string()));
+                    std::process::exit(1);
+                }
             }
-        },
+        }
         Command::Mark { command } => {
+            debug!("command: mark");
             let repo = open_repo_or_exit();
             match command {
                 MarkCommand::Add { name, commit } => {
@@ -600,6 +636,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Tag { command } => {
+            debug!("command: tag");
             let repo = open_repo_or_exit();
             match command {
                 TagCommand::Add { name, commit } => {
@@ -638,6 +675,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Stash { command } => {
+            debug!("command: stash");
             let repo = open_repo_or_exit();
             match command {
                 StashCommand::Create { name } => match stash::create(&repo, &name) {
@@ -685,6 +723,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Graft { target, onto } => {
+            debug!("command: graft (target: {}, onto: {})", target, onto);
             let repo = open_repo_or_exit();
             match modify::graft(&repo, &target, &onto) {
                 Ok(ids) => {
@@ -701,66 +740,70 @@ pub fn dispatch(cli: Cli) {
                 }
             }
         }
-        Command::Config { command } => match command {
+        Command::Config { command } => {
-            ConfigCommand::Set { global, key, value } => {
+            debug!("command: config");
-                let repo = if global {
+            match command {
-                    None
+                ConfigCommand::Set { global, key, value } => {
-                } else {
+                    let repo = if global {
-                    Some(open_repo_or_exit())
+                        None
-                };
+                    } else {
-                match config::config_set(repo.as_ref(), global, &key, &value) {
+                        Some(open_repo_or_exit())
-                    Ok(()) => println!("{}", ui::success(&format!("{key} = {value}"))),
+                    };
-                    Err(e) => {
+                    match config::config_set(repo.as_ref(), global, &key, &value) {
-                        eprintln!("{}", ui::error(&e.to_string()));
+                        Ok(()) => println!("{}", ui::success(&format!("{key} = {value}"))),
-                        std::process::exit(1);
+                        Err(e) => {
+                            eprintln!("{}", ui::error(&e.to_string()));
+                            std::process::exit(1);
+                        }
+                    }
+                }
+                ConfigCommand::Get { global, key } => {
+                    let repo = if global {
+                        None
+                    } else {
+                        Repository::discover(Path::new(".")).ok()
+                    };
+                    match config::config_get(repo.as_ref(), global, &key) {
+                        Ok(Some(value)) => println!("{value}"),
+                        Ok(None) => println!("{}", ui::info(&format!("{key} is not set"))),
+                        Err(e) => {
+                            eprintln!("{}", ui::error(&e.to_string()));
+                            std::process::exit(1);
+                        }
+                    }
+                }
+                ConfigCommand::Show { global } => {
+                    let repo = if global {
+                        None
+                    } else {
+                        Repository::discover(Path::new(".")).ok()
+                    };
+                    match config::config_show(repo.as_ref(), global) {
+                        Ok(yaml) => print!("{yaml}"),
+                        Err(e) => {
+                            eprintln!("{}", ui::error(&e.to_string()));
+                            std::process::exit(1);
+                        }
+                    }
+                }
+                ConfigCommand::Unset { global, key } => {
+                    let repo = if global {
+                        None
+                    } else {
+                        Some(open_repo_or_exit())
+                    };
+                    match config::config_unset(repo.as_ref(), global, &key) {
+                        Ok(()) => println!("{}", ui::success(&format!("unset {key}"))),
+                        Err(e) => {
+                            eprintln!("{}", ui::error(&e.to_string()));
+                            std::process::exit(1);
+                        }
                     }
                 }
             }
-            ConfigCommand::Get { global, key } => {
+        }
-                let repo = if global {
-                    None
-                } else {
-                    Repository::discover(Path::new(".")).ok()
-                };
-                match config::config_get(repo.as_ref(), global, &key) {
-                    Ok(Some(value)) => println!("{value}"),
-                    Ok(None) => println!("{}", ui::info(&format!("{key} is not set"))),
-                    Err(e) => {
-                        eprintln!("{}", ui::error(&e.to_string()));
-                        std::process::exit(1);
-                    }
-                }
-            }
-            ConfigCommand::Show { global } => {
-                let repo = if global {
-                    None
-                } else {
-                    Repository::discover(Path::new(".")).ok()
-                };
-                match config::config_show(repo.as_ref(), global) {
-                    Ok(yaml) => print!("{yaml}"),
-                    Err(e) => {
-                        eprintln!("{}", ui::error(&e.to_string()));
-                        std::process::exit(1);
-                    }
-                }
-            }
-            ConfigCommand::Unset { global, key } => {
-                let repo = if global {
-                    None
-                } else {
-                    Some(open_repo_or_exit())
-                };
-                match config::config_unset(repo.as_ref(), global, &key) {
-                    Ok(()) => println!("{}", ui::success(&format!("unset {key}"))),
-                    Err(e) => {
-                        eprintln!("{}", ui::error(&e.to_string()));
-                        std::process::exit(1);
-                    }
-                }
-            }
-        },
         Command::Sync { push } => {
+            debug!("command: sync (push: {})", push);
             let repo = open_repo_or_exit();
             match bridge::sync(&repo, push) {
                 Ok(msg) => println!("{msg}"),
@@ -771,6 +814,7 @@ pub fn dispatch(cli: Cli) {
             }
         }
         Command::Remote { command } => {
+            debug!("command: remote");
             let repo = open_repo_or_exit();
             match command {
                 RemoteCommand::Add { name, url } => match remote::add(&repo, &name, &url) {
@@ -809,6 +853,7 @@ pub fn dispatch(cli: Cli) {
 }
 
 fn open_repo_or_exit() -> Repository {
+    debug!("discovering repository from current directory");
     match Repository::discover(Path::new(".")) {
         Ok(repo) => repo,
         Err(e) => {
@@ -819,6 +864,7 @@ fn open_repo_or_exit() -> Repository {
 }
 
 fn run_diff(repo: &Repository) -> crate::error::Result<String> {
+    debug!("computing diff");
     let ignore = IgnoreRules::load(&repo.workdir);
     let head_commit = tracking::resolve_head_commit(repo)?;
 

src/config.rs

@@ -46,11 +46,19 @@ pub struct EffectiveConfig {
 
 impl Config {
     pub fn load_local(repo: &Repository) -> Result<Option<Config>> {
+        debug!(
+            "loading local config from {}",
+            repo.local_config_path().display()
+        );
         let path = repo.local_config_path();
         Self::load_from(&path)
     }
 
     pub fn load_global() -> Result<Option<Config>> {
+        debug!(
+            "loading global config from {}",
+            Self::global_config_path().display()
+        );
         let path = Self::global_config_path();
         Self::load_from(&path)
     }
@@ -130,6 +138,7 @@ impl Config {
 }
 
 pub fn load_effective(repo: &crate::repo::Repository) -> EffectiveConfig {
+    debug!("loading effective config");
     let local = Config::load_local(repo).ok().flatten();
     let global = Config::load_global().ok().flatten();
     Config::effective(local, global)
@@ -230,6 +239,7 @@ fn unset_field(config: &mut Config, section: &str, field: &str) -> Result<()> {
 
 /// Set a configuration value in the local or global config file.
 pub fn config_set(repo: Option<&Repository>, global: bool, key: &str, value: &str) -> Result<()> {
+    debug!("setting config {key} = {value} (global: {global})");
     let (section, field) = parse_key(key)?;
     if global {
         let path = Config::global_config_path();
@@ -247,6 +257,7 @@ pub fn config_set(repo: Option<&Repository>, global: bool, key: &str, value: &st
 
 /// Get a configuration value, resolving local-first then global.
 pub fn config_get(repo: Option<&Repository>, global: bool, key: &str) -> Result<Option<String>> {
+    debug!("getting config {key} (global: {global})");
     let (section, field) = parse_key(key)?;
     if global {
         let config = Config::load_global()?.unwrap_or_default();
@@ -282,6 +293,7 @@ pub fn config_show(repo: Option<&Repository>, global: bool) -> Result<String> {
 
 /// Remove a configuration key from the local or global config file.
 pub fn config_unset(repo: Option<&Repository>, global: bool, key: &str) -> Result<()> {
+    debug!("unsetting config {key} (global: {global})");
     let (section, field) = parse_key(key)?;
     if global {
         let path = Config::global_config_path();

src/diff.rs

@@ -3,6 +3,7 @@ use crate::tracking::FileTree;
 use crate::ui;
 
 pub fn render_diff(committed: &FileTree, changes: &[FileChange]) -> String {
+    debug!("rendering diff for {} change(s)", changes.len());
     let mut output = String::new();
 
     for change in changes {

src/ignore.rs

@@ -12,6 +12,7 @@ pub struct IgnorePattern {
 
 impl IgnoreRules {
     pub fn load(workdir: &Path) -> Self {
+        debug!("loading ignore rules from {}", workdir.display());
         let arcignore = workdir.join(".arcignore");
         let ignore = workdir.join(".ignore");
 
@@ -23,12 +24,14 @@ impl IgnoreRules {
             None
         };
 
-        match path {
+        let rules = match path {
             Some(p) => Self::parse_file(&p),
             None => Self {
                 patterns: Vec::new(),
             },
-        }
+        };
+        debug!("loaded {} ignore pattern(s)", rules.patterns.len());
+        rules
     }
 
     fn parse_file(path: &Path) -> Self {

src/inspect.rs

@@ -13,6 +13,7 @@ use crate::tracking;
 use crate::ui;
 
 pub fn log(repo: &Repository, range: Option<&str>) -> Result<String> {
+    debug!("showing log (range: {:?})", range);
     let resolved = resolve::parse_and_resolve_range(repo, range)?;
     let chain = &resolved.chain[resolved.start_idx..];
 
@@ -51,6 +52,7 @@ pub fn log(repo: &Repository, range: Option<&str>) -> Result<String> {
 }
 
 pub fn show(repo: &Repository, target: &str) -> Result<String> {
+    debug!("showing commit '{}'", target);
     let commit_id = resolve::resolve_target(repo, target)?;
     let obj = store::read_commit_object(repo, &commit_id)?;
     let c = &obj.commit;
@@ -117,6 +119,7 @@ pub fn show(repo: &Repository, target: &str) -> Result<String> {
 }
 
 pub fn history(repo: &Repository, file: &str, range: Option<&str>) -> Result<String> {
+    debug!("showing history for file '{}'", file);
     let resolved = resolve::parse_and_resolve_range(repo, range)?;
     let chain = &resolved.chain[resolved.start_idx..];
 

src/main.rs

@@ -1,3 +1,6 @@
+#[macro_use]
+pub mod ui;
+
 pub mod bridge;
 mod cli;
 pub mod config;
@@ -16,7 +19,6 @@ pub mod signing;
 pub mod stash;
 pub mod store;
 pub mod tracking;
-pub mod ui;
 
 fn main() {
     let cli = cli::parse();

src/merge.rs

@@ -15,6 +15,11 @@ pub fn three_way_merge(base: &FileTree, ours: &FileTree, theirs: &FileTree) -> M
         .chain(theirs.keys())
         .collect();
 
+    debug!(
+        "performing three-way merge across {} path(s)",
+        all_paths.len()
+    );
+
     let mut tree = FileTree::new();
     let mut conflicts = Vec::new();
 
@@ -71,6 +76,7 @@ pub fn three_way_merge(base: &FileTree, ours: &FileTree, theirs: &FileTree) -> M
         }
     }
 
+    debug!("merge result: {} conflict(s)", conflicts.len());
     MergeOutcome { tree, conflicts }
 }
 

src/modify.rs

@@ -12,6 +12,7 @@ use crate::store::{self, CommitObject};
 use crate::tracking::{self, FileTree};
 
 pub fn reset(repo: &Repository, files: &[String]) -> Result<String> {
+    debug!("resetting worktree");
     let head_commit = tracking::resolve_head_commit(repo)?;
     let ignore = IgnoreRules::load(&repo.workdir);
 
@@ -78,6 +79,7 @@ pub fn reset(repo: &Repository, files: &[String]) -> Result<String> {
 
     refs::remove_empty_dirs(&repo.workdir)?;
 
+    debug!("reset {} file(s)", reset_count);
     if reset_count == 0 {
         Ok("no matching files to reset".to_string())
     } else {
@@ -86,10 +88,12 @@ pub fn reset(repo: &Repository, files: &[String]) -> Result<String> {
 }
 
 pub fn revert(repo: &Repository, target: &str) -> Result<CommitId> {
+    debug!("reverting target '{}'", target);
     require_clean_worktree(repo)?;
 
     let head_id = tracking::resolve_head_commit(repo)?.ok_or(ArcError::NoCommitsYet)?;
     let commits = resolve_commit_or_range(repo, target)?;
+    debug!("processing revert for {} commit(s)", commits.len());
 
     let mut current_tree = tracking::materialize_committed_tree(repo, &head_id)?;
 
@@ -123,6 +127,7 @@ pub fn revert(repo: &Repository, target: &str) -> Result<CommitId> {
 }
 
 pub fn merge_branch(repo: &Repository, target: &str) -> Result<CommitId> {
+    debug!("merging target '{}'", target);
     require_clean_worktree(repo)?;
 
     let ours_id = tracking::resolve_head_commit(repo)?.ok_or(ArcError::NoCommitsYet)?;
@@ -133,6 +138,7 @@ pub fn merge_branch(repo: &Repository, target: &str) -> Result<CommitId> {
     }
 
     let base_id = find_merge_base(repo, &ours_id, &theirs_id)?;
+    debug!("merge base: {:?}", base_id);
 
     let base_tree = match &base_id {
         Some(id) => tracking::materialize_committed_tree(repo, id)?,
@@ -149,11 +155,13 @@ pub fn merge_branch(repo: &Repository, target: &str) -> Result<CommitId> {
         return Err(ArcError::MergeConflicts(outcome.conflicts));
     }
 
+    debug!("merge completed");
     let message = format!("merge {target}");
     commit_tree(repo, &message, vec![ours_id, theirs_id], &outcome.tree)
 }
 
 pub fn graft(repo: &Repository, target: &str, onto: &str) -> Result<Vec<CommitId>> {
+    debug!("grafting target '{}' onto '{}'", target, onto);
     require_clean_worktree(repo)?;
 
     let source_commits = resolve_commit_or_range(repo, target)?;
@@ -194,6 +202,7 @@ pub fn graft(repo: &Repository, target: &str, onto: &str) -> Result<Vec<CommitId
         new_ids.push(new_id);
     }
 
+    debug!("grafted {} commit(s)", new_ids.len());
     if is_bookmark {
         let bookmark_path = repo.bookmarks_dir().join(onto);
         let ref_target = RefTarget {
@@ -223,6 +232,7 @@ pub fn graft(repo: &Repository, target: &str, onto: &str) -> Result<Vec<CommitId
 }
 
 fn require_clean_worktree(repo: &Repository) -> Result<()> {
+    debug!("checking worktree is clean");
     let (report, _) = tracking::status(repo)?;
     if !report.is_clean() {
         return Err(ArcError::DirtyWorktree);
@@ -246,6 +256,11 @@ fn find_merge_base(
     ours: &CommitId,
     theirs: &CommitId,
 ) -> Result<Option<CommitId>> {
+    debug!(
+        "searching for merge base between {} and {}",
+        &ours.0[..12.min(ours.0.len())],
+        &theirs.0[..12.min(theirs.0.len())]
+    );
     let mut ours_ancestors = HashSet::new();
     collect_ancestors(repo, ours, &mut ours_ancestors)?;
     ours_ancestors.insert(ours.0.clone());

src/refs.rs

@@ -49,11 +49,13 @@ fn short_id(id: &CommitId) -> &str {
 pub fn mark_add(repo: &Repository, name: &str, commit: Option<&str>) -> Result<CommitId> {
     crate::repo::validate_ref_name(name)?;
     let id = resolve_commit_or_head(repo, commit)?;
+    debug!("adding bookmark '{}' at {id}", name);
     write_ref_target(&repo.bookmarks_dir().join(name), &id)?;
     Ok(id)
 }
 
 pub fn mark_rm(repo: &Repository, name: &str) -> Result<()> {
+    debug!("removing bookmark '{}'", name);
     crate::repo::validate_ref_name(name)?;
     let path = repo.bookmarks_dir().join(name);
     if !path.exists() {
@@ -69,6 +71,7 @@ pub fn mark_rm(repo: &Repository, name: &str) -> Result<()> {
 }
 
 pub fn mark_list(repo: &Repository) -> Result<String> {
+    debug!("listing bookmarks");
     let active = active_bookmark(repo)?;
     let dir = repo.bookmarks_dir();
     let mut entries: Vec<String> = Vec::new();
@@ -104,6 +107,7 @@ pub fn mark_list(repo: &Repository) -> Result<String> {
 }
 
 pub fn mark_rename(repo: &Repository, name: &str, new_name: &str) -> Result<()> {
+    debug!("renaming bookmark '{}' to '{}'", name, new_name);
     crate::repo::validate_ref_name(name)?;
     crate::repo::validate_ref_name(new_name)?;
     let old_path = repo.bookmarks_dir().join(name);
@@ -142,11 +146,13 @@ pub fn tag_add(repo: &Repository, name: &str, commit: Option<&str>) -> Result<Co
         return Err(ArcError::TagAlreadyExists(name.to_string()));
     }
     let id = resolve_commit_or_head(repo, commit)?;
+    debug!("adding tag '{}' at {id}", name);
     write_ref_target(&path, &id)?;
     Ok(id)
 }
 
 pub fn tag_rm(repo: &Repository, name: &str) -> Result<()> {
+    debug!("removing tag '{}'", name);
     crate::repo::validate_ref_name(name)?;
     let path = repo.tags_dir().join(name);
     if !path.exists() {
@@ -157,6 +163,7 @@ pub fn tag_rm(repo: &Repository, name: &str) -> Result<()> {
 }
 
 pub fn tag_list(repo: &Repository) -> Result<String> {
+    debug!("listing tags");
     let dir = repo.tags_dir();
     let mut names: Vec<String> = Vec::new();
     for entry in fs::read_dir(&dir)? {
@@ -185,6 +192,7 @@ pub fn tag_list(repo: &Repository) -> Result<String> {
 }
 
 pub fn switch(repo: &Repository, target: &str) -> Result<String> {
+    debug!("switching to target '{}'", target);
     let ignore = IgnoreRules::load(&repo.workdir);
     let head_commit = tracking::resolve_head_commit(repo)?;
 
@@ -230,6 +238,7 @@ pub fn switch(repo: &Repository, target: &str) -> Result<String> {
         Head::Unborn { .. } => unreachable!(),
     };
 
+    debug!("target resolved, writing new worktree");
     clean_tracked_files(repo, &committed)?;
 
     let new_tree = tracking::materialize_committed_tree(repo, &target_commit)?;
@@ -241,6 +250,7 @@ pub fn switch(repo: &Repository, target: &str) -> Result<String> {
 }
 
 pub fn clean_tracked_files(repo: &Repository, tree: &tracking::FileTree) -> Result<()> {
+    debug!("cleaning {} tracked file(s) from worktree", tree.len());
     for path in tree.keys() {
         crate::repo::validate_repo_path(path)?;
         let abs = repo.workdir.join(path);
@@ -278,6 +288,7 @@ pub fn remove_empty_dirs(dir: &std::path::Path) -> Result<()> {
 }
 
 pub fn write_tree(repo: &Repository, tree: &tracking::FileTree) -> Result<()> {
+    debug!("writing {} file(s) to worktree", tree.len());
     for (path, bytes) in tree {
         crate::repo::validate_repo_path(path)?;
         let abs = repo.workdir.join(path);
@@ -294,6 +305,7 @@ pub fn update_refs_after_commit(
     head: &Head,
     commit_id: &CommitId,
 ) -> Result<()> {
+    debug!("updating refs after commit {commit_id}");
     let ref_target = RefTarget {
         commit: Some(commit_id.clone()),
     };

src/remote.rs

@@ -26,6 +26,7 @@ fn remotes_path(repo: &Repository) -> std::path::PathBuf {
 ///
 /// Returns an empty `RemotesFile` if the file does not yet exist.
 pub fn load(repo: &Repository) -> Result<RemotesFile> {
+    debug!("loading remotes from {}", remotes_path(repo).display());
     let path = remotes_path(repo);
     if !path.exists() {
         return Ok(RemotesFile {
@@ -49,6 +50,7 @@ pub fn save(repo: &Repository, file: &RemotesFile) -> Result<()> {
 /// The name is validated as a ref name. Returns an error if the remote
 /// already exists.
 pub fn add(repo: &Repository, name: &str, url: &str) -> Result<()> {
+    debug!("adding remote '{}' at {}", name, url);
     crate::repo::validate_ref_name(name)?;
     let mut file = load(repo)?;
     if file.remotes.contains_key(name) {
@@ -67,6 +69,7 @@ pub fn add(repo: &Repository, name: &str, url: &str) -> Result<()> {
 ///
 /// Returns an error if the remote does not exist.
 pub fn rm(repo: &Repository, name: &str) -> Result<()> {
+    debug!("removing remote '{}'", name);
     let mut file = load(repo)?;
     if file.remotes.remove(name).is_none() {
         return Err(ArcError::RemoteNotFound(name.to_string()));
@@ -79,6 +82,7 @@ pub fn rm(repo: &Repository, name: &str) -> Result<()> {
 /// Each line has the form `  <name>\t<url>\n`.
 /// Returns an empty string if no remotes are configured.
 pub fn list(repo: &Repository) -> Result<String> {
+    debug!("listing remotes");
     let file = load(repo)?;
     let mut out = String::new();
     for (name, entry) in &file.remotes {

src/repo.rs

@@ -14,6 +14,7 @@ pub struct Repository {
 
 impl Repository {
     pub fn init(path: &Path) -> Result<Self> {
+        debug!("initializing repository at {}", path.display());
         let workdir = path.canonicalize().map_err(|_| {
             ArcError::invalid_path(format!("cannot resolve path: {}", path.display()))
         })?;
@@ -43,10 +44,12 @@ impl Repository {
         let ref_yaml = serde_yaml::to_string(&ref_target)?;
         fs::write(repo.bookmarks_dir().join("main"), ref_yaml)?;
 
+        debug!("created .arc directory structure");
         Ok(repo)
     }
 
     pub fn open(path: &Path) -> Result<Self> {
+        debug!("opening repository at {}", path.display());
         let workdir = path.canonicalize().map_err(|_| {
             ArcError::invalid_path(format!("cannot resolve path: {}", path.display()))
         })?;
@@ -60,12 +63,14 @@ impl Repository {
     }
 
     pub fn discover(from: &Path) -> Result<Self> {
+        debug!("discovering repository from {}", from.display());
         let mut current = from.canonicalize().map_err(|_| {
             ArcError::invalid_path(format!("cannot resolve path: {}", from.display()))
         })?;
 
         loop {
             if current.join(ARC_DIR).is_dir() {
+                debug!("found repository at {}", current.display());
                 return Self::open(&current);
             }
             if !current.pop() {
@@ -99,12 +104,14 @@ impl Repository {
     }
 
     pub fn load_head(&self) -> Result<Head> {
+        debug!("loading HEAD from {}", self.head_path().display());
         let contents = fs::read_to_string(self.head_path())?;
         let head: Head = serde_yaml::from_str(&contents)?;
         Ok(head)
     }
 
     pub fn save_head(&self, head: &Head) -> Result<()> {
+        debug!("saving HEAD: {:?}", head);
         let yaml = serde_yaml::to_string(head)?;
         fs::write(self.head_path(), yaml)?;
         Ok(())

src/resolve.rs

@@ -7,8 +7,11 @@ use crate::store::CommitObject;
 use crate::tracking;
 
 pub fn resolve_target(repo: &Repository, target: &str) -> Result<CommitId> {
+    debug!("resolving target '{}'", target);
     if target == "HEAD" {
-        return tracking::resolve_head_commit(repo)?.ok_or(ArcError::NoCommitsYet);
+        let id = tracking::resolve_head_commit(repo)?.ok_or(ArcError::NoCommitsYet)?;
+        debug!("resolved '{}' to {}", target, &id.0);
+        return Ok(id);
     }
 
     if crate::repo::validate_ref_name(target).is_ok() {
@@ -17,6 +20,7 @@ pub fn resolve_target(repo: &Repository, target: &str) -> Result<CommitId> {
             let contents = fs::read_to_string(&bookmark_path)?;
             let ref_target: RefTarget = serde_yaml::from_str(&contents)?;
             if let Some(id) = ref_target.commit {
+                debug!("resolved '{}' to {}", target, &id.0);
                 return Ok(id);
             }
         }
@@ -26,15 +30,19 @@ pub fn resolve_target(repo: &Repository, target: &str) -> Result<CommitId> {
             let contents = fs::read_to_string(&tag_path)?;
             let ref_target: RefTarget = serde_yaml::from_str(&contents)?;
             if let Some(id) = ref_target.commit {
+                debug!("resolved '{}' to {}", target, &id.0);
                 return Ok(id);
             }
         }
     }
 
-    resolve_commit_prefix(repo, target)
+    let id = resolve_commit_prefix(repo, target)?;
+    debug!("resolved '{}' to {}", target, &id.0);
+    Ok(id)
 }
 
 fn resolve_commit_prefix(repo: &Repository, prefix: &str) -> Result<CommitId> {
+    debug!("searching commits with prefix '{}'", prefix);
     let commits_dir = repo.commits_dir();
     let entries = match fs::read_dir(&commits_dir) {
         Ok(e) => e,
@@ -51,6 +59,7 @@ fn resolve_commit_prefix(repo: &Repository, prefix: &str) -> Result<CommitId> {
         }
     }
 
+    debug!("found {} match(es) for prefix '{}'", matches.len(), prefix);
     match matches.len() {
         0 => Err(ArcError::UnknownRevision(prefix.to_string())),
         1 => {
@@ -70,6 +79,7 @@ pub struct ResolvedRange {
 }
 
 pub fn parse_and_resolve_range(repo: &Repository, spec: Option<&str>) -> Result<ResolvedRange> {
+    debug!("parsing range: {:?}", spec);
     let (start, end) = parse_range_spec(spec)?;
 
     let end_target = end.as_deref().unwrap_or("HEAD");

src/signing.rs

@@ -10,6 +10,7 @@ const NAMESPACE: &str = "arc";
 ///
 /// Returns the signature as a PEM-encoded string.
 pub fn sign(key_path: &str, data: &[u8]) -> Result<String> {
+    debug!("signing with key {key_path}");
     let expanded = expand_path(key_path);
     let path = Path::new(&expanded);
 
@@ -27,6 +28,7 @@ pub fn sign(key_path: &str, data: &[u8]) -> Result<String> {
 ///
 /// The public key is extracted from the signature itself for verification.
 pub fn verify(signature_pem: &str, data: &[u8]) -> Result<bool> {
+    debug!("verifying signature");
     let sig: SshSig = signature_pem
         .parse()
         .map_err(|e| ArcError::SigningError(format!("invalid signature: {e}")))?;

src/stash.rs

@@ -93,6 +93,7 @@ fn save_stash_file(repo: &Repository, name: &str, file: &StashFile) -> Result<()
 
 /// Create a new named stash and set it as active.
 pub fn create(repo: &Repository, name: &str) -> Result<()> {
+    debug!("creating stash '{}'", name);
     repo::validate_ref_name(name)?;
     fs::create_dir_all(stash_named_dir(repo))?;
 
@@ -114,6 +115,7 @@ pub fn create(repo: &Repository, name: &str) -> Result<()> {
 
 /// Switch the active stash to an existing named stash.
 pub fn use_stash(repo: &Repository, name: &str) -> Result<()> {
+    debug!("switching to stash '{}'", name);
     repo::validate_ref_name(name)?;
 
     let path = stash_file_path(repo, name);
@@ -131,6 +133,7 @@ pub fn use_stash(repo: &Repository, name: &str) -> Result<()> {
 
 /// Push current dirty changes onto the active stash and reset the worktree.
 pub fn push(repo: &Repository) -> Result<String> {
+    debug!("pushing changes to active stash");
     let state = load_state(repo)?;
     let name = state.active.ok_or(ArcError::NoActiveStash)?;
     repo::validate_ref_name(&name)?;
@@ -210,11 +213,13 @@ pub fn push(repo: &Repository) -> Result<String> {
     refs::remove_empty_dirs(&repo.workdir)?;
 
     let n = changes.len();
+    debug!("pushed {} change(s) to stash '{}'", n, name);
     Ok(format!("pushed {n} change(s) to stash '{name}'"))
 }
 
 /// Pop the most recent entry from the active stash and apply it to the worktree.
 pub fn pop(repo: &Repository) -> Result<String> {
+    debug!("popping from active stash");
     let state = load_state(repo)?;
     let name = state.active.ok_or(ArcError::NoActiveStash)?;
     repo::validate_ref_name(&name)?;
@@ -233,6 +238,11 @@ pub fn pop(repo: &Repository) -> Result<String> {
         .entries
         .pop()
         .ok_or_else(|| ArcError::StashEmpty(name.clone()))?;
+    debug!(
+        "popping {} change(s) from stash '{}'",
+        entry.changes.len(),
+        name
+    );
     let head_commit = tracking::resolve_head_commit(repo)?;
 
     if entry.base != head_commit {
@@ -271,6 +281,7 @@ pub fn pop(repo: &Repository) -> Result<String> {
 
 /// Remove a named stash. If it was active, deactivate it.
 pub fn rm(repo: &Repository, name: &str) -> Result<()> {
+    debug!("removing stash '{}'", name);
     repo::validate_ref_name(name)?;
 
     let path = stash_file_path(repo, name);
@@ -291,6 +302,7 @@ pub fn rm(repo: &Repository, name: &str) -> Result<()> {
 
 /// List all named stashes, marking the active one.
 pub fn list(repo: &Repository) -> Result<String> {
+    debug!("listing stashes");
     let state = load_state(repo)?;
     let active = state.active.as_deref();
 

src/store.rs

@@ -20,6 +20,7 @@ pub fn commit_object_path(repo: &Repository, id: &CommitId) -> PathBuf {
 }
 
 pub fn write_commit_object(repo: &Repository, obj: &CommitObject) -> Result<()> {
+    debug!("writing commit object {}", obj.commit.id.0);
     let msgpack = rmp_serde::to_vec(obj)?;
     let compressed =
         zstd::stream::encode_all(Cursor::new(&msgpack), 3).map_err(std::io::Error::other)?;
@@ -34,6 +35,7 @@ pub fn write_commit_object(repo: &Repository, obj: &CommitObject) -> Result<()>
 }
 
 pub fn read_commit_object(repo: &Repository, id: &CommitId) -> Result<CommitObject> {
+    debug!("reading commit object {}", id.0);
     let path = commit_object_path(repo, id);
     let compressed = fs::read(&path)?;
     let mut decoder =
@@ -68,6 +70,7 @@ struct CommitForHash<'a> {
 }
 
 pub fn compute_delta_id(base: &Option<CommitId>, changes: &[FileChange]) -> Result<DeltaId> {
+    debug!("computing delta id (base: {:?})", base);
     let hashable = DeltaForHash { base, changes };
     let bytes = rmp_serde::to_vec(&hashable)
         .map_err(|e| crate::error::ArcError::HashError(e.to_string()))?;
@@ -81,6 +84,7 @@ pub fn compute_commit_id(
     author: &Option<Signature>,
     timestamp: i64,
 ) -> Result<CommitId> {
+    debug!("computing commit id for message: {}", message);
     let hashable = CommitForHash {
         parents,
         delta,

src/tracking.rs

@@ -14,8 +14,10 @@ use crate::ui;
 pub type FileTree = BTreeMap<String, Vec<u8>>;
 
 pub fn scan_worktree(repo: &Repository, ignore: &IgnoreRules) -> Result<FileTree> {
+    debug!("scanning worktree at {}", repo.workdir.display());
     let mut tree = BTreeMap::new();
     scan_dir(&repo.workdir, &repo.workdir, ignore, &mut tree)?;
+    debug!("found {} file(s) in worktree", tree.len());
     Ok(tree)
 }
 
@@ -61,15 +63,18 @@ fn to_rel_string(root: &Path, abs: &Path) -> String {
 }
 
 pub fn materialize_committed_tree(repo: &Repository, head: &CommitId) -> Result<FileTree> {
+    debug!("materializing tree at commit {}", head.0);
     let history = load_linear_history(repo, head)?;
     let mut tree = BTreeMap::new();
     for obj in &history {
         apply_delta(&mut tree, &obj.delta);
     }
+    debug!("materialized tree with {} file(s)", tree.len());
     Ok(tree)
 }
 
 pub fn load_linear_history(repo: &Repository, head: &CommitId) -> Result<Vec<CommitObject>> {
+    debug!("loading history from {}", head.0);
     let mut chain = Vec::new();
     let mut current = head.clone();
 
@@ -84,6 +89,7 @@ pub fn load_linear_history(repo: &Repository, head: &CommitId) -> Result<Vec<Com
     }
 
     chain.reverse();
+    debug!("loaded {} commit(s) in history chain", chain.len());
     Ok(chain)
 }
 
@@ -146,19 +152,31 @@ pub fn detect_changes(committed: &FileTree, worktree: &FileTree) -> Vec<FileChan
         }
     }
 
+    debug!("detected {} change(s)", changes.len());
     changes
 }
 
 pub fn resolve_head_commit(repo: &Repository) -> Result<Option<CommitId>> {
+    debug!("resolving HEAD commit");
     let head = repo.load_head()?;
     match head {
-        Head::Unborn { .. } => Ok(None),
+        Head::Unborn { .. } => {
-        Head::Attached { commit, .. } => Ok(Some(commit)),
+            debug!("HEAD is unborn");
-        Head::Detached { commit } => Ok(Some(commit)),
+            Ok(None)
+        }
+        Head::Attached { commit, .. } => {
+            debug!("HEAD at {}", commit.0);
+            Ok(Some(commit))
+        }
+        Head::Detached { commit } => {
+            debug!("HEAD at {}", commit.0);
+            Ok(Some(commit))
+        }
     }
 }
 
 pub fn commit(repo: &Repository, message: &str) -> Result<CommitId> {
+    debug!("committing with message: {}", message);
     let ignore = IgnoreRules::load(&repo.workdir);
     let head = repo.load_head()?;
     let head_commit = resolve_head_commit(repo)?;
@@ -170,6 +188,7 @@ pub fn commit(repo: &Repository, message: &str) -> Result<CommitId> {
 
     let worktree = scan_worktree(repo, &ignore)?;
     let changes = detect_changes(&committed, &worktree);
+    debug!("found {} change(s) to commit", changes.len());
 
     if changes.is_empty() {
         return Err(ArcError::NothingToCommit);
@@ -231,6 +250,7 @@ pub fn commit(repo: &Repository, message: &str) -> Result<CommitId> {
 
     crate::refs::update_refs_after_commit(repo, &head, &commit_id)?;
 
+    debug!("created commit {}", commit_id.0);
     Ok(commit_id)
 }
 
@@ -317,6 +337,7 @@ impl fmt::Display for StatusReport {
 }
 
 pub fn status(repo: &Repository) -> Result<(StatusReport, Vec<FileChange>)> {
+    debug!("computing status");
     let ignore = IgnoreRules::load(&repo.workdir);
     let head_commit = resolve_head_commit(repo)?;
 

src/ui.rs

@@ -1,5 +1,14 @@
 use colored::Colorize;
 
+#[macro_export]
+macro_rules! debug {
+    ($($arg:tt)*) => {
+        if $crate::cli::verbose() {
+            eprintln!("{} {}", $crate::ui::SYM_ARROW, format!($($arg)*));
+        }
+    };
+}
+
 pub const SYM_ARROW: &str = "▸";
 pub const SYM_CHECK: &str = "✓";
 pub const SYM_CROSS: &str = "✗";