Skip to content

Commit

Permalink
chore(test): use logs instead of println for small running tests
Browse files Browse the repository at this point in the history
  • Loading branch information
@RolandSherwin
RolandSherwin committed Jan 16, 2024
1 parent 1cd56f9 commit f7339b4
Show file tree
Hide file tree
Showing 9 changed files with 140 additions and 80 deletions.
13 changes: 13 additions & 0 deletions sn_node/tests/common/client.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -171,6 +171,7 @@ impl NonDroplet {
};

println!("Client bootstrap with peer {bootstrap_peers:?}");
info!("Client bootstrap with peer {bootstrap_peers:?}");
Client::new(secret_key, bootstrap_peers, true, None)
.await
.expect("Client shall be successfully created.")
Expand All @@ -186,13 +187,16 @@ impl NonDroplet {
let mut local_wallet = get_wallet(root_dir);

println!("Getting {wallet_balance} tokens from the faucet...");
info!("Getting {wallet_balance} tokens from the faucet...");
let tokens = send(from, wallet_balance, local_wallet.address(), client, true).await?;

println!("Verifying the transfer from faucet...");
info!("Verifying the transfer from faucet...");
client.verify_cashnote(&tokens).await?;
local_wallet.deposit_and_store_to_disk(&vec![tokens])?;
assert_eq!(local_wallet.balance(), wallet_balance);
println!("CashNotes deposited to the wallet that'll pay for storage: {wallet_balance}.");
info!("CashNotes deposited to the wallet that'll pay for storage: {wallet_balance}.");

Ok(local_wallet)
}
Expand Down Expand Up @@ -237,6 +241,7 @@ impl Droplet {
}

println!("Client bootstrap with peer {bootstrap_peers:?}");
info!("Client bootstrap with peer {bootstrap_peers:?}");
Client::new(secret_key, Some(bootstrap_peers), true, None)
.await
.expect("Client shall be successfully created.")
Expand All @@ -262,6 +267,10 @@ impl Droplet {
"Getting {} tokens from the faucet... num_requests:{num_requests}",
NanoTokens::from(num_requests * 100 * 1_000_000_000)
);
info!(
"Getting {} tokens from the faucet... num_requests:{num_requests}",

Check warning

Code scanning / devskim

An HTTP-based URL without TLS was detected. Warning test

Insecure URL
NanoTokens::from(num_requests * 100 * 1_000_000_000)
);
for _ in 0..num_requests {
let faucet_url = format!("http://{faucet_socket}/{address_hex}");

Expand All @@ -272,17 +281,21 @@ impl Droplet {
Err(err) => {
println!("Failed to parse transfer: {err:?}");
println!("Transfer: \"{transfer}\"");
error!("Failed to parse transfer: {err:?}");
error!("Transfer: \"{transfer}\"");
return Err(err.into());
}
};
let cashnotes = match client.receive(&transfer, &local_wallet).await {
Ok(cashnotes) => cashnotes,
Err(err) => {
println!("Failed to verify and redeem transfer: {err:?}");
error!("Failed to verify and redeem transfer: {err:?}");
return Err(err.into());
}
};
println!("Successfully verified transfer.");
info!("Successfully verified transfer.");
local_wallet.deposit_and_store_to_disk(&cashnotes)?;
}

Expand Down
5 changes: 3 additions & 2 deletions sn_node/tests/common/mod.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -30,7 +30,7 @@ use std::{
time::Duration,
};
use tonic::Request;
use tracing::error;
use tracing::{debug, error, info};
use xor_name::XorName;

type ResultRandomContent = Result<(FilesApi, Bytes, ChunkAddress, Vec<(XorName, PathBuf)>)>;
Expand Down Expand Up @@ -99,7 +99,7 @@ pub async fn get_all_peer_ids(node_rpc_addresses: &Vec<SocketAddr>) -> Result<Ve
let peer_id = PeerId::from_bytes(&response.get_ref().peer_id)?;
all_peers.push(peer_id);
}
println!(
debug!(
"Obtained the PeerId list for the running network with a node count of {}",
node_rpc_addresses.len()
);
Expand All @@ -114,6 +114,7 @@ pub async fn node_restart(addr: &SocketAddr) -> Result<()> {
.await?;

println!("Node restart requested to RPC service at {addr}");
info!("Node restart requested to RPC service at {addr}");

Ok(())
}
40 changes: 30 additions & 10 deletions sn_node/tests/data_with_churn.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -38,7 +38,7 @@ use std::{
};
use tempfile::tempdir;
use tokio::{sync::RwLock, task::JoinHandle, time::sleep};
use tracing::{debug, trace};
use tracing::{debug, error, info, trace, warn};
use xor_name::XorName;

const EXTRA_CHURN_COUNT: u32 = 5;
Expand Down Expand Up @@ -92,6 +92,7 @@ async fn data_availability_during_churn() -> Result<()> {

let churn_period = if let Ok(str) = std::env::var("TEST_TOTAL_CHURN_CYCLES") {
println!("Using value set in 'TEST_TOTAL_CHURN_CYCLES' env var: {str}");
info!("Using value set in 'TEST_TOTAL_CHURN_CYCLES' env var: {str}");
let cycles = str.parse::<u32>()?;
test_duration / cycles
} else {
Expand All @@ -103,6 +104,7 @@ async fn data_availability_during_churn() -> Result<()> {
)
};
println!("Nodes will churn every {churn_period:?}");
info!("Nodes will churn every {churn_period:?}");

// Create a cross thread usize for tracking churned nodes
let churn_count = Arc::new(RwLock::new(0_usize));
Expand All @@ -115,12 +117,16 @@ async fn data_availability_during_churn() -> Result<()> {
"Running this test for {test_duration:?}{}...",
if chunks_only { " (Chunks only)" } else { "" }
);
info!(
"Running this test for {test_duration:?}{}...",
if chunks_only { " (Chunks only)" } else { "" }
);

// The testnet will create a `faucet` at last. To avoid mess up with that,
// wait for a while to ensure the spends of that got settled.
sleep(std::time::Duration::from_secs(10)).await;

println!("Creating a client and paying wallet...");
info!("Creating a client and paying wallet...");
let paying_wallet_dir = TempDir::new()?;
let (client, paying_wallet) =
get_gossip_client_and_wallet(paying_wallet_dir.path(), PAYING_WALLET_INITIAL_BALANCE)
Expand All @@ -129,7 +135,7 @@ async fn data_availability_during_churn() -> Result<()> {
// Waiting for the paying_wallet funded.
sleep(std::time::Duration::from_secs(10)).await;

println!(
info!(
"Client and paying_wallet created with signing key: {:?}",
client.signer_pk()
);
Expand All @@ -143,7 +149,7 @@ async fn data_availability_during_churn() -> Result<()> {
// Spawn a task to create Registers and CashNotes at random locations,
// at a higher frequency than the churning events
if !chunks_only {
println!("Creating transfer wallet taking balance from the payment wallet");
info!("Creating transfer wallet taking balance from the payment wallet");
let transfers_wallet_dir = TempDir::new()?;
let transfers_wallet = get_funded_wallet(
&client,
Expand All @@ -152,7 +158,7 @@ async fn data_availability_during_churn() -> Result<()> {
TRANSFERS_WALLET_INITIAL_BALANCE,
)
.await?;
println!("Transfer wallet created");
info!("Transfer wallet created");

// Waiting for the transfers_wallet funded.
sleep(std::time::Duration::from_secs(10)).await;
Expand All @@ -174,6 +180,7 @@ async fn data_availability_during_churn() -> Result<()> {
}

println!("Uploading some chunks before carry out node churning");
info!("Uploading some chunks before carry out node churning");

// Spawn a task to store Chunks at random locations, at a higher frequency than the churning events
store_chunks_task(
Expand Down Expand Up @@ -215,12 +222,13 @@ async fn data_availability_during_churn() -> Result<()> {
paying_wallet_dir.path().to_path_buf(),
);

info!("All tasks have been spawned. The test is now running...");
println!("All tasks have been spawned. The test is now running...");

let start_time = Instant::now();
while start_time.elapsed() < test_duration {
let failed = failures.read().await;
println!(
info!(
"Current failures after {:?} ({}): {:?}",
start_time.elapsed(),
failed.len(),
Expand All @@ -243,7 +251,7 @@ async fn data_availability_during_churn() -> Result<()> {
// i.e. the test may pass even without any replication
// Hence, we carry out a final round of query all data to confirm storage.
println!("Final querying confirmation of content");
debug!("Final querying confirmation of content");
info!("Final querying confirmation of content");

// take one read lock to avoid holding the lock for the whole loop
// prevent any late content uploads being added to the list
Expand Down Expand Up @@ -320,6 +328,7 @@ fn create_cash_note_task(
let cash_note_addr = SpendAddress::from_unique_pubkey(&cash_note.unique_pubkey());
let net_addr = NetworkAddress::SpendAddress(cash_note_addr);
println!("Created CashNote at {cash_note_addr:?} after {delay:?}");
debug!("Created CashNote at {cash_note_addr:?} after {delay:?}");
content.write().await.push_back(net_addr);
let _ = cash_notes.write().await.insert(cash_note_addr, cash_note);
}
Expand Down Expand Up @@ -347,6 +356,7 @@ fn create_registers_task(

let addr = RegisterAddress::new(meta, owner);
println!("Creating Register at {addr:?} in {delay:?}");
debug!("Creating Register at {addr:?} in {delay:?}");
sleep(delay).await;

match client
Expand Down Expand Up @@ -406,7 +416,7 @@ fn store_chunks_task(
let (addr, _data_map, _file_size, chunks) =
FilesApi::chunk_file(&file_path, &output_dir, true).expect("Failed to chunk bytes");

println!(
info!(
"Paying storage for ({}) new Chunk/s of file ({} bytes) at {addr:?} in {delay:?}",
chunks.len(),
chunk_size
Expand All @@ -429,6 +439,9 @@ fn store_chunks_task(
println!(
"Stored ({chunks_len}) Chunk/s at cost: {cost:?} of file ({chunk_size} bytes) at {addr:?} in {delay:?}"
);
info!(
"Stored ({chunks_len}) Chunk/s at cost: {cost:?} of file ({chunk_size} bytes) at {addr:?} in {delay:?}"
);
sleep(delay).await;

for chunk_name in chunks_name {
Expand Down Expand Up @@ -457,6 +470,7 @@ fn query_content_task(
let len = content.read().await.len();
if len == 0 {
println!("No content created/stored just yet, let's try in {delay:?} ...");
info!("No content created/stored just yet, let's try in {delay:?} ...");
sleep(delay).await;
continue;
}
Expand All @@ -475,6 +489,7 @@ fn query_content_task(
println!(
"Failed to query content (index: {index}) at {net_addr}: {last_err:?}"
);
error!("Failed to query content (index: {index}) at {net_addr}: {last_err:?}");
// mark it to try 'MAX_NUM_OF_QUERY_ATTEMPTS' times.
let _ = content_erred
.write()
Expand Down Expand Up @@ -508,14 +523,16 @@ fn churn_nodes_task(

// break out if we've run the duration of churn
if start.elapsed() > test_duration {
println!("Test duration reached, stopping churn nodes task");
debug!("Test duration reached, stopping churn nodes task");
break 'main;
}

println!("Restarting node through its RPC service at {rpc_address}");
info!("Restarting node through its RPC service at {rpc_address}");

if let Err(err) = node_restart(rpc_address).await {
println!("Failed to restart node with RPC endpoint {rpc_address}: {err}");
info!("Failed to restart node with RPC endpoint {rpc_address}: {err}");
continue;
}

Expand Down Expand Up @@ -547,10 +564,12 @@ fn retry_query_content_task(
let attempts = content_error.attempts + 1;

println!("Querying erred content at {net_addr}, attempt: #{attempts} ...");
info!("Querying erred content at {net_addr}, attempt: #{attempts} ...");
if let Err(last_err) =
query_content(&client, &wallet_dir, &net_addr, cash_notes.clone()).await
{
println!("Erred content is still not retrievable at {net_addr} after {attempts} attempts: {last_err:?}");
warn!("Erred content is still not retrievable at {net_addr} after {attempts} attempts: {last_err:?}");
// We only keep it to retry 'MAX_NUM_OF_QUERY_ATTEMPTS' times,
// otherwise report it effectivelly as failure.
content_error.attempts = attempts;
Expand Down Expand Up @@ -589,11 +608,12 @@ async fn final_retry_query_content(
{
if attempts == MAX_NUM_OF_QUERY_ATTEMPTS {
println!("Final check: Content is still not retrievable at {net_addr} after {attempts} attempts: {last_err:?}");
error!("Final check: Content is still not retrievable at {net_addr} after {attempts} attempts: {last_err:?}");
bail!("Final check: Content is still not retrievable at {net_addr} after {attempts} attempts: {last_err:?}");
} else {
attempts += 1;
let delay = 2 * churn_period;
println!("Delaying last check for {delay:?} ...");
debug!("Delaying last check for {delay:?} ...");
sleep(delay).await;
continue;
}
Expand Down
18 changes: 15 additions & 3 deletions sn_node/tests/msgs_over_gossipsub.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,10 @@

mod common;

use common::client::get_node_count;
use crate::common::{
client::{get_all_rpc_addresses, get_node_count},
get_safenode_rpc_client,
};
use eyre::Result;
use rand::seq::SliceRandom;
use sn_logging::LogBuilder;
Expand All @@ -21,8 +24,7 @@ use std::{net::SocketAddr, time::Duration};
use tokio::time::timeout;
use tokio_stream::StreamExt;
use tonic::Request;

use crate::common::{client::get_all_rpc_addresses, get_safenode_rpc_client};
use tracing::{error, info};

const TEST_CYCLES: u8 = 20;

Expand All @@ -42,6 +44,8 @@ async fn msgs_over_gossipsub() -> Result<()> {
let topic = format!("TestTopic-{}", rand::random::<u64>());
println!("Testing cicle {}/{TEST_CYCLES} - topic: {topic}", c + 1);
println!("============================================================");
info!("Testing cicle {}/{TEST_CYCLES} - topic: {topic}", c + 1);
info!("============================================================");

// get a random subset of `nodes_subscribed`` out of `node_count` nodes to subscribe to the topic
let mut rng = rand::thread_rng();
Expand All @@ -54,6 +58,7 @@ async fn msgs_over_gossipsub() -> Result<()> {
for (node_index, rpc_addr) in random_subs_nodes.clone() {
// request current node to subscribe to the topic
println!("Node #{node_index} ({rpc_addr}) subscribing to {topic} ...");
info!("Node #{node_index} ({rpc_addr}) subscribing to {topic} ...");
node_subscribe_to_topic(rpc_addr, topic.clone()).await?;

let handle = tokio::spawn(async move {
Expand All @@ -73,10 +78,15 @@ async fn msgs_over_gossipsub() -> Result<()> {
"Msg received on node #{node_index} '{topic}': {}",
String::from_utf8(msg.to_vec()).unwrap()
);
info!(
"Msg received on node #{node_index} '{topic}': {}",
String::from_utf8(msg.to_vec()).unwrap()
);
count += 1;
}
Ok(_) => { /* ignored */ }
Err(_) => {
error!("Error while parsing received NodeEvent");
println!("Error while parsing received NodeEvent");
}
}
Expand All @@ -101,6 +111,7 @@ async fn msgs_over_gossipsub() -> Result<()> {
for (node_index, addr, handle) in subs_handles.into_iter() {
let count = handle.await??;
println!("Messages received by node {node_index}: {count}");
info!("Messages received by node {node_index}: {count}");
assert_eq!(
count,
node_count - nodes_subscribed,
Expand Down Expand Up @@ -144,6 +155,7 @@ async fn other_nodes_to_publish_on_topic(

let mut rpc_client = get_safenode_rpc_client(addr).await?;
println!("Node {node_index} to publish on {topic} message: {msg}");
info!("Node {node_index} to publish on {topic} message: {msg}");

let _response = rpc_client
.publish_on_topic(Request::new(GossipsubPublishRequest {
Expand Down
Loading

0 comments on commit f7339b4

Please sign in to comment.