From fe330e8f5100d01ae8cb0c571dc4278ecc74cd02 Mon Sep 17 00:00:00 2001 From: Anatoly Yakovenko Date: Thu, 24 May 2018 04:45:40 +0000 Subject: [PATCH] logs and tps counting --- multinode-demo/leader.sh | 5 +++-- multinode-demo/validator.sh | 5 +++-- src/bin/multinode-demo.rs | 26 ++++++++++++++------------ src/crdt.rs | 10 ++++++++-- src/streamer.rs | 2 +- 5 files changed, 29 insertions(+), 19 deletions(-) diff --git a/multinode-demo/leader.sh b/multinode-demo/leader.sh index 15f2c293f3abed..45de6bf5b0cfe1 100755 --- a/multinode-demo/leader.sh +++ b/multinode-demo/leader.sh @@ -1,5 +1,6 @@ #!/bin/bash cd /home/ubuntu/solana git pull -export RUST_LOG=solana::crdt=trace -cat genesis.log | cargo run --release --features cuda --bin solana-testnode -- -s leader.json -b 8000 -d +export RUST_LOG=solana::crdt=info +cat genesis.log | cargo run --release --features cuda --bin solana-testnode -- -s leader.json -b 8000 -d | grep INFO +#cat genesis.log | cargo run --release --bin solana-testnode -- -s leader.json -b 8000 -d diff --git a/multinode-demo/validator.sh b/multinode-demo/validator.sh index b4f374747dfcd9..e21ca42eaa49dd 100755 --- a/multinode-demo/validator.sh +++ b/multinode-demo/validator.sh @@ -3,5 +3,6 @@ cd /home/ubuntu/solana git pull scp ubuntu@18.206.1.146:~/solana/leader.json . scp ubuntu@18.206.1.146:~/solana/genesis.log . -export RUST_LOG=solana::crdt=trace -cat genesis.log | cargo run --release --features cuda --bin solana-testnode -- -s replicator.json -r leader.json -b 9000 -d +scp ubuntu@18.206.1.146:~/solana/libcuda_verify_ed25519.a . +export RUST_LOG=solana=info +cat genesis.log | cargo run --release --features cuda --bin solana-testnode -- -s replicator.json -v leader.json -b 9000 -d | grep INFO diff --git a/src/bin/multinode-demo.rs b/src/bin/multinode-demo.rs index 679ac647583582..6a40329574a2a9 100644 --- a/src/bin/multinode-demo.rs +++ b/src/bin/multinode-demo.rs @@ -139,11 +139,12 @@ fn main() { nsps / 1_000_f64 ); - let initial_tx_count = client.transaction_count(); + let first_count = client.transaction_count(); + let mut initial_tx_count = first_count; println!("initial count {}", initial_tx_count); println!("Transfering {} transactions in {} batches", txs, threads); - let now = Instant::now(); + let mut now = Instant::now(); let sz = transactions.len() / threads; let chunks: Vec<_> = transactions.chunks(sz).collect(); chunks.into_par_iter().for_each(|trs| { @@ -154,11 +155,13 @@ fn main() { } }); - println!("Waiting for transactions to complete...",); - for _ in 0..10 { - let mut tx_count = client.transaction_count(); + println!("Sampling tps every second...",); + for _ in 0..20 { + let tx_count = client.transaction_count(); duration = now.elapsed(); + now = Instant::now(); let txs = tx_count - initial_tx_count; + initial_tx_count = tx_count; println!("Transactions processed {}", txs); let ns = duration.as_secs() * 1_000_000_000 + u64::from(duration.subsec_nanos()); let tps = (txs * 1_000_000_000) as f64 / ns as f64; @@ -171,13 +174,12 @@ fn main() { for val in validators { println!("Checking balance on {} ...", val.events_addr); let mut client = mk_client(&client_addr, &val); - let mut tx_count = client.transaction_count(); - duration = now.elapsed(); - let txs = tx_count - initial_tx_count; - println!("Transactions processed {} on {}", txs, val.events_addr); - let ns = duration.as_secs() * 1_000_000_000 + u64::from(duration.subsec_nanos()); - let tps = (txs * 1_000_000_000) as f64 / ns as f64; - println!("{} tps on {}", tps, val.events_addr); + let tx_count = client.transaction_count(); + let txs = tx_count - first_count; + println!( + "Total Transactions processed {} on {}", + txs, val.events_addr + ); } signal.store(true, Ordering::Relaxed); for t in c_threads { diff --git a/src/crdt.rs b/src/crdt.rs index 41bd8c62df0d51..fef31b359f88fb 100644 --- a/src/crdt.rs +++ b/src/crdt.rs @@ -348,7 +348,7 @@ impl Crdt { fn gossip_request(&self) -> Result<(SocketAddr, Protocol)> { let options: Vec<_> = self.table.values().filter(|v| v.id != self.me).collect(); if options.len() < 1 { - trace!("crdt too small for gossip"); + info!("crdt too small for gossip"); return Err(Error::CrdtTooSmall); } let n = (Self::random() as usize) % options.len(); @@ -497,7 +497,13 @@ impl Crdt { sock.set_read_timeout(Some(Duration::new(2, 0))) .expect("'sock.set_read_timeout' in crdt.rs"); spawn(move || loop { - let _ = Self::run_listen(&obj, &window, &sock); + let e = Self::run_listen(&obj, &window, &sock); + if e.is_err() { + info!( + "run_listen timeout, table size: {}", + obj.read().unwrap().table.len() + ); + } if exit.load(Ordering::Relaxed) { return; } diff --git a/src/streamer.rs b/src/streamer.rs index 7fc26df377fd4e..82da7a6c7c64ec 100644 --- a/src/streamer.rs +++ b/src/streamer.rs @@ -342,7 +342,7 @@ fn broadcast( let mut blobs = dq.into_iter().collect(); /// appends codes to the list of blobs allowing us to reconstruct the stream #[cfg(feature = "erasure")] - erasure::generate_codes(blobs); + erasure::generate_coding(re, blobs, consumed); Crdt::broadcast(crdt, &blobs, &sock, transmit_index)?; // keep the cache of blobs that are broadcast {