diff --git a/radicle-cli/src/commands/sync.rs b/radicle-cli/src/commands/sync.rs index bd1ea0cc6..9f9361b25 100644 --- a/radicle-cli/src/commands/sync.rs +++ b/radicle-cli/src/commands/sync.rs @@ -64,6 +64,7 @@ Options --seed Sync with the given node (may be specified multiple times) -r, --replicas Sync with a specific number of seeds -v, --verbose Verbose output + --debug Print debug information afer sync --help Print help "#, }; @@ -171,6 +172,7 @@ pub enum SyncDirection { #[derive(Default, Debug)] pub struct Options { pub rid: Option, + pub debug: bool, pub verbose: bool, pub timeout: time::Duration, pub sort_by: SortBy, @@ -188,6 +190,7 @@ impl Args for Options { let mut fetch = false; let mut announce = false; let mut inventory = false; + let mut debug = false; let mut replicas = None; let mut seeds = BTreeSet::new(); let mut sort_by = SortBy::default(); @@ -195,6 +198,9 @@ impl Args for Options { while let Some(arg) = parser.next()? { match arg { + Long("debug") => { + debug = true; + } Long("verbose") | Short('v') => { verbose = true; } @@ -279,6 +285,7 @@ impl Args for Options { Ok(( Options { rid, + debug, verbose, timeout, sort_by, @@ -334,7 +341,14 @@ pub fn run(options: Options, ctx: impl term::Context) -> anyhow::Result<()> { } } if [SyncDirection::Announce, SyncDirection::Both].contains(&direction) { - announce_refs(rid, settings, options.timeout, &mut node, &profile)?; + announce_refs( + rid, + settings, + options.timeout, + options.debug, + &mut node, + &profile, + )?; } } Operation::Synchronize(SyncMode::Inventory) => { @@ -417,6 +431,7 @@ fn announce_refs( rid: RepoId, settings: RepoSync, timeout: time::Duration, + debug: bool, node: &mut Node, profile: &Profile, ) -> anyhow::Result<()> { @@ -469,18 +484,18 @@ fn announce_refs( return Ok(()); } - let mut spinner = term::spinner(format!("Syncing with {} node(s)..", unsynced.len())); + let mut spinner = term::spinner(format!("Found {} seed(s)..", unsynced.len())); let result = node.announce(rid, unsynced, timeout, |event, replicas| match event { node::AnnounceEvent::Announced => ControlFlow::Continue(()), - node::AnnounceEvent::RefsSynced { remote } => { - spinner.message(format!("Synced with {remote}..")); + node::AnnounceEvent::RefsSynced { remote, time } => { + spinner.message(format!("Synced with {remote} in {time:?}..")); // We're done syncing when both of these conditions are met: // // 1. We've matched or exceeded our target replica count. // 2. We've synced with the seeds specified manually. if replicas.len() >= settings.replicas - && settings.seeds.iter().all(|s| replicas.contains(s)) + && settings.seeds.iter().all(|s| replicas.contains_key(s)) { ControlFlow::Break(()) } else { @@ -494,6 +509,14 @@ fn announce_refs( } else { spinner.message(format!("Synced with {} node(s)", result.synced.len())); spinner.finish(); + if debug { + for (seed, time) in &result.synced { + term::println( + " ", + term::format::dim(format!("Synced with {seed} in {time:?}")), + ); + } + } } for seed in result.timeout { term::notice!("Seed {seed} timed out.."); diff --git a/radicle-cli/src/node.rs b/radicle-cli/src/node.rs index d5aef0ce5..e50c03d5b 100644 --- a/radicle-cli/src/node.rs +++ b/radicle-cli/src/node.rs @@ -36,8 +36,8 @@ fn announce_(rid: RepoId, node: &mut Node) -> Result<(), radicle::node::Error> { Duration::from_secs(9), |event, _| match event { node::AnnounceEvent::Announced => ControlFlow::Continue(()), - node::AnnounceEvent::RefsSynced { remote } => { - spinner.message(format!("Synced with {remote}..")); + node::AnnounceEvent::RefsSynced { remote, time } => { + spinner.message(format!("Synced with {remote} in {time:?}..")); ControlFlow::Continue(()) } }, diff --git a/radicle-remote-helper/src/push.rs b/radicle-remote-helper/src/push.rs index 48ff27f8a..54634dda7 100644 --- a/radicle-remote-helper/src/push.rs +++ b/radicle-remote-helper/src/push.rs @@ -706,9 +706,12 @@ fn sync( DEFAULT_SYNC_TIMEOUT, |event, _| match event { node::AnnounceEvent::Announced => ControlFlow::Continue(()), - node::AnnounceEvent::RefsSynced { remote } => { + node::AnnounceEvent::RefsSynced { remote, time } => { replicated.insert(remote); - spinner.message(format!("Synced with {}..", cli::format::dim(remote))); + spinner.message(format!( + "Synced with {} in {time:?}..", + cli::format::dim(remote) + )); ControlFlow::Continue(()) } }, diff --git a/radicle/src/node.rs b/radicle/src/node.rs index 96d476aff..ce6884802 100644 --- a/radicle/src/node.rs +++ b/radicle/src/node.rs @@ -633,14 +633,17 @@ pub struct AnnounceResult { /// Nodes that timed out. pub timeout: Vec, /// Nodes that synced. - pub synced: Vec, + pub synced: Vec<(NodeId, time::Duration)>, } /// A sync event, emitted by [`Node::announce`]. #[derive(Debug)] pub enum AnnounceEvent { /// Refs were synced with the given node. - RefsSynced { remote: NodeId }, + RefsSynced { + remote: NodeId, + time: time::Duration, + }, /// Refs were announced to all given nodes. Announced, } @@ -914,14 +917,15 @@ impl Node { rid: RepoId, seeds: impl IntoIterator, timeout: time::Duration, - mut callback: impl FnMut(AnnounceEvent, &HashSet) -> ControlFlow<()>, + mut callback: impl FnMut(AnnounceEvent, &HashMap) -> ControlFlow<()>, ) -> Result { let events = self.subscribe(timeout)?; let refs = self.announce_refs(rid)?; let mut unsynced = seeds.into_iter().collect::>(); - let mut synced = HashSet::new(); + let mut synced = HashMap::new(); let mut timeout: Vec = Vec::new(); + let started = time::Instant::now(); callback(AnnounceEvent::Announced, &synced); @@ -932,13 +936,22 @@ impl Node { rid: rid_, at, }) if rid == rid_ && refs.at == at => { + let elapsed = started.elapsed(); log::debug!(target: "radicle", "Received {e:?}"); unsynced.remove(&remote); // We can receive synced events from nodes we didn't directly announce to, // and it's possible to receive duplicates as well. - if synced.insert(remote) { - if callback(AnnounceEvent::RefsSynced { remote }, &synced).is_break() { + if synced.insert(remote, elapsed).is_none() { + if callback( + AnnounceEvent::RefsSynced { + remote, + time: elapsed, + }, + &synced, + ) + .is_break() + { break; } }