From fa007970c36aac38eef069228e09f6712bc08578 Mon Sep 17 00:00:00 2001 From: Evie Viau Date: Sun, 20 Feb 2022 14:53:43 -0500 Subject: [PATCH] Use log and pretty_env_logger for better logging --- Cargo.lock | 95 ++++++++++++++++++++++++++++++++++++++++++++++++++ Cargo.toml | 5 ++- src/infoops.rs | 9 +++-- src/main.rs | 38 ++++++++++---------- src/opcodes.rs | 6 +++- 5 files changed, 130 insertions(+), 23 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 2adb9dd..85e50f3 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2,6 +2,15 @@ # It is not intended for manual editing. version = 3 +[[package]] +name = "aho-corasick" +version = "0.7.15" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7404febffaa47dac81aa44dba71523c9d069b1bdc50a77db41195149e17f68e5" +dependencies = [ + "memchr", +] + [[package]] name = "async-trait" version = "0.1.52" @@ -13,6 +22,17 @@ dependencies = [ "syn", ] +[[package]] +name = "atty" +version = "0.2.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d9b39be18770d11421cdb1b9947a45dd3f37e93092cbf377614828a319d5fee8" +dependencies = [ + "hermit-abi", + "libc", + "winapi", +] + [[package]] name = "autocfg" version = "1.1.0" @@ -27,9 +47,11 @@ dependencies = [ "futures-util", "hex", "hmac", + "log", "num", "num-derive", "num-traits", + "pretty_env_logger", "rand", "redis", "serde", @@ -149,6 +171,19 @@ version = "0.4.8" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "56899898ce76aaf4a0f24d914c97ea6ed976d42fec6ad33fcbb0a1103e07b2b0" +[[package]] +name = "env_logger" +version = "0.7.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "44533bbbb3bb3c1fa17d9f2e4e38bbbaf8396ba82193c4cb1b6445d711445d36" +dependencies = [ + "atty", + "humantime", + "log", + "regex", + "termcolor", +] + [[package]] name = "fnv" version = "1.0.7" @@ -271,6 +306,15 @@ version = "1.6.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9100414882e15fb7feccb4897e5f0ff0ff1ca7d1a86a23208ada4d7a18e6c6c4" +[[package]] +name = "humantime" +version = "1.3.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "df004cfca50ef23c36850aaaa59ad52cc70d0e90243c3c7737a4dd32dc7a3c4f" +dependencies = [ + "quick-error", +] + [[package]] name = "idna" version = "0.2.3" @@ -517,6 +561,16 @@ version = "0.2.16" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "eb9f9e6e233e5c4a35559a617bf40a4ec447db2e84c20b55a6f83167b7e57872" +[[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-macro2" version = "1.0.36" @@ -526,6 +580,12 @@ 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.15" @@ -589,6 +649,23 @@ dependencies = [ "bitflags", ] +[[package]] +name = "regex" +version = "1.4.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2a26af418b574bd56588335b3a3659a65725d4e636eb1016c2f9e3b38c7cc759" +dependencies = [ + "aho-corasick", + "memchr", + "regex-syntax", +] + +[[package]] +name = "regex-syntax" +version = "0.6.25" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f497285884f3fcff424ffc933e56d7cbca511def0c9831a7f9b5f6153e3cc89b" + [[package]] name = "ryu" version = "1.0.9" @@ -730,6 +807,15 @@ dependencies = [ "unicode-xid", ] +[[package]] +name = "termcolor" +version = "1.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2dfed899f0eb03f32ee8c6a0aabdb8a7949659e3466561fc0adf54e26d88c5f4" +dependencies = [ + "winapi-util", +] + [[package]] name = "thiserror" version = "1.0.30" @@ -900,6 +986,15 @@ version = "0.4.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6" +[[package]] +name = "winapi-util" +version = "0.1.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "70ec6ce85bb158151cae5e5c87f95a8e97d2c0c4b001223f33a334e3ce5de178" +dependencies = [ + "winapi", +] + [[package]] name = "winapi-x86_64-pc-windows-gnu" version = "0.4.0" diff --git a/Cargo.toml b/Cargo.toml index eeb78d8..d6dc78c 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -26,4 +26,7 @@ hmac = "0.12.1" sha2 = "0.10.2" hex = "0.4.3" -redis = "0.21.5" \ No newline at end of file +redis = "0.21.5" + +log = "0.4.14" +pretty_env_logger = "0.4.0" \ No newline at end of file diff --git a/src/infoops.rs b/src/infoops.rs index f56af69..3f9fbfa 100644 --- a/src/infoops.rs +++ b/src/infoops.rs @@ -140,9 +140,10 @@ pub enum InfoData { } pub async fn get_infotype(msg: Message) -> Result<(InfoType, InfoData), ()> { - let message_json: Result = serde_json::from_str( - msg.to_text().expect("Failed to convert message to str!") - ); + let msg = msg.to_text().unwrap(); + trace!(target: "infoops", "Decoding message: {}", &msg); + + let message_json: Result = serde_json::from_str(msg); if message_json.is_ok() { // TODO: Maybe find a better way? @@ -150,6 +151,8 @@ pub async fn get_infotype(msg: Message) -> Result<(InfoType, InfoData), ()> { message_json.unwrap().get("d").unwrap().clone() ).expect("Failed to get inner data for InfoData!"); + trace!(target: "infoops", "Decoded as Op: {:?} Data: {:?}", &info_data._type, &info_data.data); + Ok((info_data._type, info_data.data)) } else { Err(()) diff --git a/src/main.rs b/src/main.rs index 763d387..fea7539 100644 --- a/src/main.rs +++ b/src/main.rs @@ -1,5 +1,6 @@ -#[macro_use] -extern crate num_derive; +#[macro_use]extern crate num_derive; + +#[macro_use] extern crate log; use std::collections::HashSet; use std::io::Error; @@ -33,6 +34,7 @@ mod util; #[tokio::main] async fn main() -> Result<(), Error> { dotenv().ok(); + pretty_env_logger::init(); let shared_secret = env::var("SECRET").expect("No secret present in environment!"); @@ -41,11 +43,11 @@ async fn main() -> Result<(), Error> { let redis_client = redis::Client::open(env::var("REDIS_HOST").unwrap_or("redis://127.0.0.1:6379".to_string())).expect("Failed to connect to Redis server!"); let socket = TcpListener::bind(&addr).await.expect("Failed to bind to address!"); - println!("Listening on {}!", &addr); + info!("Listening on {}!", &addr); while let Ok((stream, _)) = socket.accept().await { let peer = stream.peer_addr().expect("Failed to connect to peer, missing address?"); - println!("Connecting to peer {}...", &peer); + info!(target: "initial", "Connecting to peer {}...", &peer); tokio::spawn(accept_conn(peer, stream, redis_client.clone(), shared_secret.clone())); } @@ -57,7 +59,7 @@ async fn accept_conn(peer: SocketAddr, stream: TcpStream, redis_client: Client, if let Err(e) = handle_conn(peer, stream, redis_client, shared_secret).await { match e { tokio_tungstenite::tungstenite::Error::ConnectionClosed | tokio_tungstenite::tungstenite::Error::Protocol(_) | tokio_tungstenite::tungstenite::Error::Utf8 => (), - err => eprintln!("Error accepting connection from {}!", &peer), + err => error!(target: "initial", "Error accepting connection from {}!", &peer), } } } @@ -67,14 +69,14 @@ async fn handle_conn(peer: SocketAddr, stream: TcpStream, redis_client: Client, .await; if ws_stream.is_err() { - println!("Failed to complete the websocket handshake! Dropping {}!", peer); + warn!(target: "initial", "Failed to complete the websocket handshake! Dropping {}!", peer); return Ok(()); } let ws_stream = ws_stream.unwrap(); - println!("Connected to peer: {}!", &peer); + info!(target: "socket", "Connected to peer: {}!", &peer); let (mut ws_sender, mut ws_receiver) = ws_stream.split(); let mut heartbeat = tokio::time::interval(Duration::from_millis(1000)); @@ -89,7 +91,7 @@ async fn handle_conn(peer: SocketAddr, stream: TcpStream, redis_client: Client, let _: () = redis.set(format!("{}_nonce", peer), &nonce).expect("Failed to insert nonce!"); - println!("HELLO to {}", &peer); + debug!(target: "socket", "HELLO to {}", &peer); ws_sender.send(Message::Text( serde_json::to_string( &SocketMessage { @@ -129,12 +131,12 @@ async fn handle_conn(peer: SocketAddr, stream: TcpStream, redis_client: Client, match op.0 { OpCode::IDENTIFY => { if let MessageData::IDENTIFY(dn) = op.1 { - println!("IDENTIFY from {}", &peer); + debug!(target: "socket", "IDENTIFY from {}", &peer); let nonce: Option = redis.get(format!("{}_nonce", peer)).expect("Failed to get nonce from Redis!"); if verify_token(shared_secret.clone(), nonce, dn.token).await { - println!("READY to {}", &peer); + debug!(target: "socket", "READY to {}", &peer); ws_sender.send(Message::Text( serde_json::to_string( &SocketMessage { @@ -156,13 +158,13 @@ async fn handle_conn(peer: SocketAddr, stream: TcpStream, redis_client: Client, } OpCode::RESUME => { - println!("RESUME from {}", &peer); + debug!(target: "socket", "RESUME from {}", &peer); unimplemented!() } OpCode::HEARTBEAT => { - println!("HEARTBEAT from {}", &peer); - println!("HEARTBEAT_ACK to {}", &peer); + debug!(target: "socket", "HEARTBEAT from {}", &peer); + debug!(target: "socket", "HEARTBEAT_ACK to {}", &peer); ws_sender.send(Message::Text( serde_json::to_string( &SocketMessage { @@ -181,13 +183,13 @@ async fn handle_conn(peer: SocketAddr, stream: TcpStream, redis_client: Client, if info_data.is_ok() { let info = info_data.unwrap(); - println!("INFO from {} with type {:?}", &peer, &info.0); + debug!(target: "socket", "INFO from {} with type {:?}", &peer, &info.0); match info.0 { InfoType::CHANNEL_REQ => { if let InfoData::CHANNEL_REQ(dn) = info.1 { let guild_id = dn.clone().guild_id.unwrap_or("dm".to_string()); - println!("Creating voice channel for {} in {}", &dn.channel_id, &guild_id); + debug!(target: "socket", "Creating voice channel for {} in {}", &dn.channel_id, &guild_id); let token: String = rand::thread_rng() .sample_iter(&Alphanumeric) @@ -201,7 +203,7 @@ async fn handle_conn(peer: SocketAddr, stream: TcpStream, redis_client: Client, let _: () = redis.sadd(format!("{}_{}_voice", guild_id, &dn.channel_id), channel_set) .expect("Failed to insert into Redis!"); - println!("CHANNEL_ASSIGN to {}", &peer); + debug!(target: "socket", "CHANNEL_ASSIGN to {}", &peer); ws_sender.send(Message::Text( serde_json::to_string( @@ -230,7 +232,7 @@ async fn handle_conn(peer: SocketAddr, stream: TcpStream, redis_client: Client, InfoType::VST_CREATE => { if let InfoData::VST_CREATE(dn) = info.1 { let guild_id = dn.clone().guild_id.unwrap_or("dm".to_string()); - println!("Creating voice state for {} in {}", &dn.channel_id, &guild_id); + debug!(target: "socket", "Creating voice state for {} in {}", &dn.channel_id, &guild_id); let session_id: String = rand::thread_rng() .sample_iter(&Alphanumeric) @@ -244,7 +246,7 @@ async fn handle_conn(peer: SocketAddr, stream: TcpStream, redis_client: Client, let _: () = redis.sadd(format!("{}_{}_voice", guild_id, &dn.channel_id), channel_set) .expect("Failed to insert into Redis!"); - println!("VOICE_STATE_DONE to {}", &peer); + debug!(target: "socket", "VOICE_STATE_DONE to {}", &peer); ws_sender.send(Message::Text( serde_json::to_string( diff --git a/src/opcodes.rs b/src/opcodes.rs index 996ab83..ebf302a 100644 --- a/src/opcodes.rs +++ b/src/opcodes.rs @@ -147,11 +147,15 @@ pub struct SocketMessage { pub fn get_opcode(msg: Message) -> Result<(OpCode, MessageData), ()> { - let message_json: Result = serde_json::from_str(msg.to_text().expect("Failed to convert message to str!")); + let msg = msg.to_text().unwrap(); + trace!(target: "opcodes", "Decoding message: {}", &msg); + let message_json: Result = serde_json::from_str(msg); if message_json.is_ok() { let output = message_json.unwrap(); + trace!(target: "opcodes", "Decoded as Op: {:?} Data: {:?}", &output.op, &output.d); + Ok((output.op, output.d)) } else { Err(())