cli: Add timing information to `rad-sync` — heartwood

modified radicle-cli/src/commands/sync.rs

@@ -64,6 +64,7 @@ Options

         --seed      <nid>     Sync with the given node (may be specified multiple times)
     -r, --replicas  <count>   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<RepoId>,
     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..");

modified 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(())
             }
         },

modified 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(())
             }
         },

modified radicle/src/node.rs

@@ -633,14 +633,17 @@ pub struct AnnounceResult {

     /// Nodes that timed out.
     pub timeout: Vec<NodeId>,
     /// Nodes that synced.
     pub synced: Vec<NodeId>,
     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<Item = NodeId>,
         timeout: time::Duration,
         mut callback: impl FnMut(AnnounceEvent, &HashSet<PublicKey>) -> ControlFlow<()>,
         mut callback: impl FnMut(AnnounceEvent, &HashMap<PublicKey, time::Duration>) -> ControlFlow<()>,
     ) -> Result<AnnounceResult, Error> {
         let events = self.subscribe(timeout)?;
         let refs = self.announce_refs(rid)?;
         let mut unsynced = seeds.into_iter().collect::<BTreeSet<_>>();
         let mut synced = HashSet::new();
         let mut synced = HashMap::new();
         let mut timeout: Vec<NodeId> = 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;
                         }
                     }