chore: improve test-utils and lower networking log level (#448)

blueprint-test-utils/src/lib.rs

@@ -471,10 +471,15 @@ pub async fn wait_for_completion_of_tangle_job(
     required_count: usize,
 ) -> Result<JobResultSubmitted, Box<dyn Error>> {
     let mut count = 0;
-    loop {
-        let events = client.events().at_latest().await?;
+    let mut blocks = client.blocks().subscribe_best().await?;
+    while let Some(Ok(block)) = blocks.next().await {
+        let events = block.events().await?;
         let results = events.find::<JobResultSubmitted>().collect::<Vec<_>>();
         info!(
+            %service_id,
+            %call_id,
+            %required_count,
+            %count,
             "Waiting for job completion. Found {} results ...",
             results.len()
         );
@@ -493,9 +498,8 @@ pub async fn wait_for_completion_of_tangle_job(
                 }
             }
         }
-
-        tokio::time::sleep(Duration::from_millis(4000)).await;
     }
+    Err("Failed to get job result".into())
 }
 
 pub async fn get_next_blueprint_id(client: &TestClient) -> Result<u64, Box<dyn Error>> {

sdk/src/network/gossip.rs

@@ -20,7 +20,7 @@ use std::sync::atomic::AtomicU32;
 use std::sync::Arc;
 
 use crate::error::Error;
-use crate::{debug, error, trace, warn};
+use crate::{error, trace, warn};
 
 use super::{Network, ParticipantInfo, ProtocolMessage};
 
@@ -157,7 +157,7 @@ impl NetworkService<'_> {
                 address,
                 listener_id,
             } => {
-                debug!("{listener_id} has a new address: {address}");
+                trace!("{listener_id} has a new address: {address}");
             }
             ConnectionEstablished {
                 peer_id,
@@ -226,7 +226,7 @@ impl NetworkService<'_> {
                 peer_id,
                 connection_id,
             } => {
-                debug!("Dialing peer: {peer_id:?} with connection_id: {connection_id}");
+                trace!("Dialing peer: {peer_id:?} with connection_id: {connection_id}");
             }
             NewExternalAddrCandidate { address } => {
                 trace!("New external address candidate: {address}");

sdk/src/network/handlers/connections.rs

@@ -1,7 +1,7 @@
 #![allow(unused_results, clippy::used_underscore_binding)]
 
 use crate::network::gossip::{MyBehaviourRequest, NetworkService};
-use crate::{debug, error};
+use crate::{error, trace};
 use libp2p::PeerId;
 use sp_core::{keccak_256, Pair};
 
@@ -12,7 +12,7 @@ impl NetworkService<'_> {
         peer_id: PeerId,
         num_established: u32,
     ) {
-        debug!("Connection established");
+        trace!("Connection established");
         if num_established == 1 {
             let my_peer_id = self.swarm.local_peer_id();
             let msg = my_peer_id.to_bytes();
@@ -40,7 +40,7 @@ impl NetworkService<'_> {
         num_established: u32,
         _cause: Option<libp2p::swarm::ConnectionError>,
     ) {
-        debug!("Connection closed");
+        trace!("Connection closed");
         if num_established == 0 {
             self.swarm
                 .behaviour_mut()
@@ -56,7 +56,7 @@ impl NetworkService<'_> {
         _local_addr: libp2p::Multiaddr,
         _send_back_addr: libp2p::Multiaddr,
     ) {
-        debug!("Incoming connection");
+        trace!("Incoming connection");
     }
 
     #[tracing::instrument(skip(self))]
@@ -65,7 +65,7 @@ impl NetworkService<'_> {
         peer_id: PeerId,
         _connection_id: libp2p::swarm::ConnectionId,
     ) {
-        debug!("Outgoing connection to peer: {peer_id}");
+        trace!("Outgoing connection to peer: {peer_id}");
     }
 
     #[tracing::instrument(skip(self, error))]

sdk/src/network/handlers/dcutr.rs

@@ -1,9 +1,9 @@
-use crate::debug;
 use crate::network::gossip::NetworkService;
+use crate::trace;
 
 impl NetworkService<'_> {
     #[tracing::instrument(skip(self, event))]
     pub async fn handle_dcutr_event(&mut self, event: libp2p::dcutr::Event) {
-        debug!("DCUTR event: {event:?}");
+        trace!("DCUTR event: {event:?}");
     }
 }

sdk/src/network/handlers/gossip.rs

@@ -2,7 +2,7 @@
 
 use crate::network::gossip::{GossipMessage, NetworkService};
 
-use crate::{debug, error, trace};
+use crate::{error, trace};
 use libp2p::gossipsub::TopicHash;
 use libp2p::{gossipsub, PeerId};
 use std::sync::atomic::AtomicU32;
@@ -78,7 +78,7 @@ impl NetworkService<'_> {
             error!("Got message from unknown peer");
             return;
         };
-        debug!("Got message from peer: {origin}");
+        trace!("Got message from peer: {origin}");
         match bincode::deserialize::<GossipMessage>(&message.data) {
             Ok(GossipMessage { topic, raw_payload }) => {
                 if let Some((_, tx, _)) = self

sdk/src/network/handlers/identify.rs

@@ -1,5 +1,5 @@
 use crate::network::gossip::NetworkService;
-use crate::{debug, error, trace};
+use crate::{error, trace};
 
 impl NetworkService<'_> {
     #[tracing::instrument(skip(self, event))]
@@ -14,7 +14,7 @@ impl NetworkService<'_> {
                     format!("Supported Protocols: {:?}", info.protocols),
                 ];
                 let info_lines = info_lines.join(", ");
-                debug!("Received identify event from peer: {peer_id} with info: {info_lines}");
+                trace!("Received identify event from peer: {peer_id} with info: {info_lines}");
                 self.swarm.add_external_address(info.observed_addr);
             }
             Sent { peer_id, .. } => {
@@ -27,7 +27,7 @@ impl NetworkService<'_> {
                     format!("Supported Protocols: {:?}", info.protocols),
                 ];
                 let info_lines = info_lines.join(", ");
-                debug!("Pushed identify event to peer: {peer_id} with info: {info_lines}");
+                trace!("Pushed identify event to peer: {peer_id} with info: {info_lines}");
             }
             Error { peer_id, error, .. } => {
                 error!("Identify error from peer: {peer_id} with error: {error}");

sdk/src/network/handlers/mdns.rs

@@ -1,5 +1,5 @@
 use crate::network::gossip::NetworkService;
-use crate::{debug, error};
+use crate::{error, trace};
 use libp2p::mdns;
 
 impl NetworkService<'_> {
@@ -9,7 +9,7 @@ impl NetworkService<'_> {
         match event {
             Discovered(list) => {
                 for (peer_id, multiaddr) in list {
-                    debug!("discovered a new peer: {peer_id} on {multiaddr}");
+                    trace!("discovered a new peer: {peer_id} on {multiaddr}");
                     self.swarm
                         .behaviour_mut()
                         .gossipsub
@@ -21,7 +21,7 @@ impl NetworkService<'_> {
             }
             Expired(list) => {
                 for (peer_id, multiaddr) in list {
-                    debug!("discover peer has expired: {peer_id} with {multiaddr}");
+                    trace!("discover peer has expired: {peer_id} with {multiaddr}");
                     self.swarm
                         .behaviour_mut()
                         .gossipsub

sdk/src/network/handlers/p2p.rs

@@ -1,7 +1,7 @@
 #![allow(unused_results)]
 
 use crate::network::gossip::{MyBehaviourRequest, MyBehaviourResponse, NetworkService};
-use crate::{debug, error, warn};
+use crate::{debug, error, trace, warn};
 
 use libp2p::gossipsub::IdentTopic;
 use libp2p::{request_response, PeerId};
@@ -17,7 +17,7 @@ impl NetworkService<'_> {
         use request_response::Event::{InboundFailure, Message, OutboundFailure, ResponseSent};
         match event {
             Message { peer, message } => {
-                debug!("Received P2P message from: {peer}");
+                trace!("Received P2P message from: {peer}");
                 self.handle_p2p_message(peer, message).await;
             }
             OutboundFailure {
@@ -53,15 +53,15 @@ impl NetworkService<'_> {
                 channel,
                 request_id,
             } => {
-                debug!("Received request with request_id: {request_id} from peer: {peer}");
+                trace!("Received request with request_id: {request_id} from peer: {peer}");
                 self.handle_p2p_request(peer, request_id, request, channel)
                     .await;
             }
             Response {
                 response,
                 request_id,
             } => {
-                debug!("Received response from peer: {peer} with request_id: {request_id}");
+                trace!("Received response from peer: {peer} with request_id: {request_id}");
                 self.handle_p2p_response(peer, request_id, response).await;
             }
         }
@@ -116,7 +116,7 @@ impl NetworkService<'_> {
                 ecdsa_public_key,
                 signature,
             } => {
-                debug!("Received handshake from peer: {peer}");
+                trace!("Received handshake from peer: {peer}");
                 // Verify the signature
                 let msg = peer.to_bytes();
                 let hash = keccak_256(&msg);

sdk/src/network/handlers/ping.rs

@@ -1,9 +1,9 @@
-use crate::debug;
 use crate::network::gossip::NetworkService;
+use crate::trace;
 
 impl NetworkService<'_> {
     #[tracing::instrument(skip(self, event))]
     pub async fn handle_ping_event(&mut self, event: libp2p::ping::Event) {
-        debug!("Ping event: {event:?}")
+        trace!("Ping event: {event:?}")
     }
 }

sdk/src/network/handlers/relay.rs

@@ -1,14 +1,14 @@
-use crate::debug;
 use crate::network::gossip::NetworkService;
+use crate::trace;
 
 impl NetworkService<'_> {
     #[tracing::instrument(skip(self, event))]
     pub async fn handle_relay_event(&mut self, event: libp2p::relay::Event) {
-        debug!("Relay event: {event:?}");
+        trace!("Relay event: {event:?}");
     }
 
     #[tracing::instrument(skip(self, event))]
     pub async fn handle_relay_client_event(&mut self, event: libp2p::relay::client::Event) {
-        debug!("Relay client event: {event:?}");
+        trace!("Relay client event: {event:?}");
     }
 }