Use log and pretty_env_logger for better logging

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"

Cargo.toml

@@ -27,3 +27,6 @@ sha2 = "0.10.2"
 hex = "0.4.3"
 
 redis = "0.21.5"
+
+log = "0.4.14"
+pretty_env_logger = "0.4.0"

src/infoops.rs

@@ -140,9 +140,10 @@ pub enum InfoData {
 }
 
 pub async fn get_infotype(msg: Message) -> Result<(InfoType, InfoData), ()> {
-    let message_json: Result<Value, serde_json::Error> = 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<Value, serde_json::Error> = 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(())

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<String> = 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(

src/opcodes.rs

@@ -147,11 +147,15 @@ pub struct SocketMessage {
 
 
 pub fn get_opcode(msg: Message) -> Result<(OpCode, MessageData), ()> {
-    let message_json: Result<SocketMessage, serde_json::Error> = 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<SocketMessage, serde_json::Error> = 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(())