From b63179c699e0569d45826bccb4b9f2f1bc53c30e Mon Sep 17 00:00:00 2001 From: Alex Auvolat Date: Fri, 4 Dec 2020 13:58:34 +0100 Subject: [PATCH] Logging --- Cargo.lock | 69 ++++++++++++++++++++++++++++--------------- Cargo.toml | 5 ++-- Dockerfile | 2 +- examples/basalt.rs | 28 +++++++++++++----- examples/fullmesh.rs | 12 +++++++- src/peering/basalt.rs | 9 ++++-- 6 files changed, 87 insertions(+), 38 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 56121f9..7f65bd7 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -246,6 +246,19 @@ version = "1.0.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "baf1de4339761588bc0619e3cbc0120ee582ebb74b53b4efbf79117bd2da40fd" +[[package]] +name = "chrono" +version = "0.4.19" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "670ad68c9088c2a963aaa298cb369688cf3f9465ce5e2d4ca10e6e0098a1ce73" +dependencies = [ + "libc", + "num-integer", + "num-traits", + "time", + "winapi 0.3.9", +] + [[package]] name = "clap" version = "2.33.3" @@ -297,9 +310,9 @@ dependencies = [ [[package]] name = "env_logger" -version = "0.7.1" +version = "0.8.2" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "44533bbbb3bb3c1fa17d9f2e4e38bbbaf8396ba82193c4cb1b6445d711445d36" +checksum = "f26ecb66b4bdca6c1409b40fb255eefc2bd4f6d135dab3c3124f80ffa2a9661e" dependencies = [ "atty", "humantime", @@ -535,12 +548,9 @@ checksum = "644f9158b2f133fd50f5fb3242878846d9eb792e445c893805ff0e3824006e35" [[package]] name = "humantime" -version = "1.3.0" +version = "2.0.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "df004cfca50ef23c36850aaaa59ad52cc70d0e90243c3c7737a4dd32dc7a3c4f" -dependencies = [ - "quick-error", -] +checksum = "3c1ad908cc71012b7bea4d0c53ba96a8cba9962f048fa68d143376143d863b7a" [[package]] name = "instant" @@ -757,13 +767,13 @@ dependencies = [ "async-trait", "base64", "bytes 0.6.0", + "chrono", "env_logger", "err-derive", "hex", "kuska-handshake", "log", "lru", - "pretty_env_logger", "rand", "rmp-serde", "serde", @@ -772,6 +782,16 @@ dependencies = [ "tokio", ] +[[package]] +name = "num-integer" +version = "0.1.44" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d2cc698a63b549a70bc047073d2949cce27cd1c7b0a4a862d08a8031bc2801db" +dependencies = [ + "autocfg", + "num-traits", +] + [[package]] name = "num-traits" version = "0.2.14" @@ -854,16 +874,6 @@ dependencies = [ "winapi 0.3.9", ] -[[package]] -name = "pretty_env_logger" -version = "0.4.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "926d36b9553851b8b0005f1275891b392ee4d2d833852c417ed025477350fb9d" -dependencies = [ - "env_logger", - "log", -] - [[package]] name = "proc-macro-error" version = "1.0.4" @@ -909,12 +919,6 @@ dependencies = [ "unicode-xid", ] -[[package]] -name = "quick-error" -version = "1.2.3" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a1d01941d82fa2ab50be1e79e6714289dd7cde78eba4c074bc5a4374f650dfe0" - [[package]] name = "quote" version = "1.0.7" @@ -1178,6 +1182,17 @@ dependencies = [ "lazy_static", ] +[[package]] +name = "time" +version = "0.1.44" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6db9e6914ab8b1ae1c260a4ae7a49b6c5611b40328a735b21862567685e73255" +dependencies = [ + "libc", + "wasi", + "winapi 0.3.9", +] + [[package]] name = "tokio" version = "0.2.23" @@ -1255,6 +1270,12 @@ version = "1.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9d5b2c62b4012a3e1eca5a7e077d13b3bf498c4073e33ccd58626607748ceeca" +[[package]] +name = "wasi" +version = "0.10.0+wasi-snapshot-preview1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1a143597ca7c7793eff794def352d41792a93c481eb1042423ff7ff72ba2c31f" + [[package]] name = "wasm-bindgen" version = "0.2.69" diff --git a/Cargo.toml b/Cargo.toml index 4877b79..e018af7 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -17,10 +17,10 @@ base64 = "0.12.1" structopt = { version = "0.3", default-features = false } rand = "0.5.5" +chrono = "0.4" log = "0.4.8" -pretty_env_logger = "0.4" -env_logger = "0.7.1" +env_logger = "0.8" arc-swap = "1.0" async-trait = "0.1.7" err-derive = "0.2.3" @@ -30,3 +30,4 @@ lru = "0.6" sodiumoxide = { git = "https://github.com/Dhole/sodiumoxidez", branch = "extra" } #kuska-handshake = { path = "../handshake", features = ["default", "tokio_compat"] } kuska-handshake = { git = "https://github.com/kuska-ssb/handshake", branch = "master", features = ["default", "tokio_compat"] } + diff --git a/Dockerfile b/Dockerfile index a179597..ea676ac 100644 --- a/Dockerfile +++ b/Dockerfile @@ -4,6 +4,6 @@ COPY target/release/examples/basalt /root/basalt CMD /root/basalt ENV RUST_BACKTRACE=1 -ENV RUST_LOG=netapp=debug,basalt=debug +ENV RUST_LOG=netapp=info,netapp::peering=debug,basalt=info CMD /garage/garage server -c /garage/config.toml diff --git a/examples/basalt.rs b/examples/basalt.rs index e09f627..141069a 100644 --- a/examples/basalt.rs +++ b/examples/basalt.rs @@ -1,8 +1,9 @@ use std::net::SocketAddr; use std::sync::Arc; use std::time::Duration; +use std::io::Write; -use log::{info, warn}; +use log::{debug, info, warn}; use structopt::StructOpt; use serde::{Deserialize, Serialize}; @@ -48,7 +49,18 @@ pub struct Opt { #[tokio::main] async fn main() { - pretty_env_logger::init(); + env_logger::Builder::new() + .parse_env("RUST_LOG") + .format(|buf, record| { + writeln!(buf, + "{} {} {}", + chrono::Local::now().format("%s%.6f"), + record.level(), + record.args() + ) + }) + .init(); + let opt = Opt::from_args(); @@ -56,7 +68,7 @@ async fn main() { Some(k) => auth::Key::from_slice(&hex::decode(k).unwrap()).unwrap(), None => auth::gen_key(), }; - info!("Network key: {}", hex::encode(&netid)); + info!("KYEV NK {}", hex::encode(&netid)); let privkey = match &opt.private_key { Some(k) => ed25519::SecretKey::from_slice(&hex::decode(k).unwrap()).unwrap(), @@ -66,8 +78,8 @@ async fn main() { } }; - info!("Node private key: {}", hex::encode(&privkey)); - info!("Node public key: {}", hex::encode(&privkey.public_key())); + info!("KYEV SK {}", hex::encode(&privkey)); + info!("KYEV PK {}", hex::encode(&privkey.public_key())); let listen_addr = opt.listen_addr.parse().unwrap(); let netapp = NetApp::new(listen_addr, netid, privkey); @@ -93,7 +105,7 @@ async fn main() { netapp.add_msg_handler::( |_from: ed25519::PublicKey, msg: ExampleMessage| { - info!("Got example message: {:?}, sending example response", msg); + debug!("Got example message: {:?}, sending example response", msg); async { ExampleResponse{example_field: false} } @@ -115,14 +127,14 @@ async fn sampling_loop(netapp: Arc, basalt: Arc) { let peers = basalt.sample(10); for p in peers { - info!("Sampled: {}", hex::encode(p)); + info!("KYEV S {}", hex::encode(p)); let netapp2 = netapp.clone(); tokio::spawn(async move { match netapp2.request(&p, ExampleMessage{ example_field: 42, }, PRIO_NORMAL).await { - Ok(resp) => info!("Got example response: {:?}", resp), + Ok(resp) => debug!("Got example response: {:?}", resp), Err(e) => warn!("Error with example request: {}", e), } }); diff --git a/examples/fullmesh.rs b/examples/fullmesh.rs index af315fb..a61ab3d 100644 --- a/examples/fullmesh.rs +++ b/examples/fullmesh.rs @@ -28,7 +28,17 @@ pub struct Opt { #[tokio::main] async fn main() { - pretty_env_logger::init(); + env_logger::Builder::new() + .parse_env("RUST_LOG") + .format(|buf, record| { + writeln!(buf, + "{} {} {}", + chrono::Local::now().format("%s%.6f"), + record.level(), + record.args() + ) + }) + .init(); let opt = Opt::from_args(); diff --git a/src/peering/basalt.rs b/src/peering/basalt.rs index 5da65e0..00cfd60 100644 --- a/src/peering/basalt.rs +++ b/src/peering/basalt.rs @@ -3,7 +3,7 @@ use std::net::SocketAddr; use std::sync::{Arc, RwLock}; use std::time::Duration; -use log::{debug, warn}; +use log::{debug, info, warn}; use lru::LruCache; use rand::{thread_rng, Rng}; use serde::{Deserialize, Serialize}; @@ -302,7 +302,10 @@ impl Basalt { .unwrap() .sample(count) .iter() - .map(|p| p.id) + .map(|p| { + info!("KYEV S {}", hex::encode(p.id)); + p.id + }) .collect::>() } @@ -421,6 +424,7 @@ impl Basalt { if is_incoming { self.handle_peer_list(&[Peer { id: pk, addr }][..]); } else { + info!("KYEV C {}", hex::encode(pk)); let peer = Peer { id: pk, addr }; let mut backlog = self.backlog.write().unwrap(); @@ -443,6 +447,7 @@ impl Basalt { fn on_disconnected(&self, pk: ed25519::PublicKey, is_incoming: bool) { if !is_incoming { + info!("KYEV D {}", hex::encode(pk)); self.view.write().unwrap().disconnected(pk); } }