From 3c949d306efec2d5a801098eaad7af8ab14375a3 Mon Sep 17 00:00:00 2001
From: Anastasios Kichidis <akihidis@gmail.com>
Date: Fri, 21 Jun 2024 15:00:51 +0100
Subject: [PATCH] [Sync state] add debug/trace messages (#18340)

## Description

Describe the changes or additions included in this PR.

## Test plan

How did you test the new or updated feature?

---

## Release notes

Check each box that your changes affect. If none of the boxes relate to
your changes, release notes aren't required.

For each box you select, include information after the relevant heading
that describes the impact of your changes that a user might notice and
any actions they must take to implement updates.

- [ ] Protocol:
- [ ] Nodes (Validators and Full nodes):
- [ ] Indexer:
- [ ] JSON-RPC:
- [ ] GraphQL:
- [ ] CLI:
- [ ] Rust SDK:
---
 crates/sui-network/src/discovery/mod.rs  |  3 +++
 crates/sui-network/src/state_sync/mod.rs | 16 ++++++++++++++++
 2 files changed, 19 insertions(+)

diff --git a/crates/sui-network/src/discovery/mod.rs b/crates/sui-network/src/discovery/mod.rs
index 093bb2ffb49ac..b770ff691f435 100644
--- a/crates/sui-network/src/discovery/mod.rs
+++ b/crates/sui-network/src/discovery/mod.rs
@@ -187,6 +187,7 @@ impl DiscoveryEventLoop {
                 affinity: anemo::types::PeerAffinity::High,
                 address: anemo_address.into_iter().collect(),
             };
+            debug!(?peer_info, "Add configured preferred peer");
             self.network.known_peers().insert(peer_info);
         }
     }
@@ -324,6 +325,7 @@ impl DiscoveryEventLoop {
 }
 
 async fn try_to_connect_to_peer(network: Network, info: NodeInfo) {
+    debug!("Connecting to peer {info:?}");
     for multiaddr in &info.addresses {
         if let Ok(address) = multiaddr.to_anemo_address() {
             // Ignore the result and just log the error if there is one
@@ -350,6 +352,7 @@ async fn try_to_connect_to_seed_peers(
     config: Arc<DiscoveryConfig>,
     seed_peers: Vec<SeedPeer>,
 ) {
+    debug!(?seed_peers, "Connecting to seed peers");
     let network = &network;
 
     futures::stream::iter(seed_peers.into_iter().filter_map(|seed| {
diff --git a/crates/sui-network/src/state_sync/mod.rs b/crates/sui-network/src/state_sync/mod.rs
index 9bb36faa0bb84..0a29e219ebf5e 100644
--- a/crates/sui-network/src/state_sync/mod.rs
+++ b/crates/sui-network/src/state_sync/mod.rs
@@ -174,12 +174,15 @@ impl PeerHeights {
     //
     // This will return false if the given peer doesn't have an entry or is not on the same chain
     // as us
+    #[instrument(level = "debug", skip_all, fields(peer_id=?peer_id, checkpoint=?checkpoint.sequence_number()))]
     pub fn update_peer_info(
         &mut self,
         peer_id: PeerId,
         checkpoint: Checkpoint,
         low_watermark: Option<CheckpointSequenceNumber>,
     ) -> bool {
+        debug!("Update peer info");
+
         let info = match self.peers.get_mut(&peer_id) {
             Some(info) if info.on_same_chain_as_us => info,
             _ => return false,
@@ -194,8 +197,10 @@ impl PeerHeights {
         true
     }
 
+    #[instrument(level = "debug", skip_all, fields(peer_id=?peer_id, lowest = ?info.lowest, height = ?info.height))]
     pub fn insert_peer_info(&mut self, peer_id: PeerId, info: PeerStateSyncInfo) {
         use std::collections::hash_map::Entry;
+        debug!("Insert peer info");
 
         match self.peers.entry(peer_id) {
             Entry::Occupied(mut entry) => {
@@ -824,6 +829,7 @@ async fn get_latest_from_peer(
 
     // Bail early if this node isn't on the same chain as us
     if !info.on_same_chain_as_us {
+        trace!(?info, "Peer {peer_id} not on same chain as us");
         return;
     }
     let Some((highest_checkpoint, low_watermark)) =
@@ -880,6 +886,7 @@ async fn query_peer_for_latest_info(
     }
 }
 
+#[instrument(level = "debug", skip_all)]
 async fn query_peers_for_their_latest_checkpoint(
     network: anemo::Network,
     peer_heights: Arc<RwLock<PeerHeights>>,
@@ -911,6 +918,8 @@ async fn query_peers_for_their_latest_checkpoint(
         })
         .collect::<Vec<_>>();
 
+    debug!("Query {} peers for latest checkpoint", futs.len());
+
     let checkpoints = futures::future::join_all(futs).await.into_iter().flatten();
 
     let highest_checkpoint = checkpoints.max_by_key(|checkpoint| *checkpoint.sequence_number());
@@ -921,6 +930,12 @@ async fn query_peers_for_their_latest_checkpoint(
         .highest_known_checkpoint()
         .cloned();
 
+    debug!(
+        "Our highest checkpoint {:?}, peers highest checkpoint {:?}",
+        our_highest_checkpoint.as_ref().map(|c| c.sequence_number()),
+        highest_checkpoint.as_ref().map(|c| c.sequence_number())
+    );
+
     let _new_checkpoint = match (highest_checkpoint, our_highest_checkpoint) {
         (Some(theirs), None) => theirs,
         (Some(theirs), Some(ours)) if theirs.sequence_number() > ours.sequence_number() => theirs,
@@ -1123,6 +1138,7 @@ async fn sync_checkpoint_contents_from_archive<S>(
         } else {
             false
         };
+        debug!("Syncing checkpoint contents from archive: {sync_from_archive},  highest_synced: {highest_synced},  lowest_checkpoint_on_peers: {}", lowest_checkpoint_on_peers.map_or_else(|| "None".to_string(), |l| l.to_string()));
         if sync_from_archive {
             let start = highest_synced
                 .checked_add(1)