From bd61530b5faff05cd4a7721be0c3df425607d9eb Mon Sep 17 00:00:00 2001 From: Joscha Date: Mon, 14 Feb 2022 01:57:35 +0100 Subject: [PATCH] Add a few debug logs --- Cargo.lock | 76 +++++++++++++++++++++++++++++++++++++++++ cove-core/src/id.rs | 2 ++ cove-server/Cargo.toml | 2 ++ cove-server/src/conn.rs | 25 ++++++++++++-- cove-server/src/main.rs | 23 ++++++++++--- 5 files changed, 122 insertions(+), 6 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index a9b35e0..5737358 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2,12 +2,32 @@ # It is not intended for manual editing. version = 3 +[[package]] +name = "aho-corasick" +version = "0.7.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1e37cfd5e7657ada45f742d6e99ca5788580b5c529dc78faf11ece6dc702656f" +dependencies = [ + "memchr", +] + [[package]] name = "anyhow" version = "1.0.53" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "94a45b455c14666b85fc40a019e8ab9eb75e3a124e05494f5397122bc9eb06e0" +[[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 = "base64" version = "0.13.0" @@ -71,7 +91,9 @@ version = "0.1.0" dependencies = [ "anyhow", "cove-core", + "env_logger", "futures", + "log", "rand", "serde_json", "thiserror", @@ -121,6 +143,19 @@ dependencies = [ "crypto-common", ] +[[package]] +name = "env_logger" +version = "0.9.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0b2cf0344971ee6c64c31be0d530793fba457d322dfec2810c453d0ef228f9c3" +dependencies = [ + "atty", + "humantime", + "log", + "regex", + "termcolor", +] + [[package]] name = "fnv" version = "1.0.7" @@ -282,6 +317,12 @@ version = "1.5.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "acd94fdbe1d4ff688b67b04eee2e17bd50995534a61539e45adfefb45e5e5503" +[[package]] +name = "humantime" +version = "2.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9a3a5bfb195931eeb336b2a7b4d761daec841b97f947d34394601737a7bba5e4" + [[package]] name = "idna" version = "0.2.3" @@ -513,6 +554,23 @@ dependencies = [ "bitflags", ] +[[package]] +name = "regex" +version = "1.5.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d07a8629359eb56f1e2fb1652bb04212c072a87ba68546a04065d525673ac461" +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" @@ -612,6 +670,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" @@ -792,6 +859,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/cove-core/src/id.rs b/cove-core/src/id.rs index db51f32..87e7d41 100644 --- a/cove-core/src/id.rs +++ b/cove-core/src/id.rs @@ -19,6 +19,8 @@ impl Id { } } +// TODO Impl better fmt::Debug for Id and aliases + impl fmt::Display for Id { fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { write!(f, "{}", self.0.encode_hex::()) diff --git a/cove-server/Cargo.toml b/cove-server/Cargo.toml index 719a893..b37faa2 100644 --- a/cove-server/Cargo.toml +++ b/cove-server/Cargo.toml @@ -6,7 +6,9 @@ edition = "2021" [dependencies] anyhow = "1.0.53" cove-core = { path = "../cove-core" } +env_logger = "0.9.0" futures = "0.3.21" +log = "0.4.14" rand = "0.8.4" serde_json = "1.0.78" thiserror = "1.0.30" diff --git a/cove-server/src/conn.rs b/cove-server/src/conn.rs index 91e9f1e..7616cda 100644 --- a/cove-server/src/conn.rs +++ b/cove-server/src/conn.rs @@ -1,10 +1,12 @@ +use std::net::SocketAddr; use std::sync::Arc; use std::time::Duration; -use std::{fmt, result}; +use std::{fmt, io, result}; use cove_core::packets::Packet; use futures::stream::{SplitSink, SplitStream}; use futures::StreamExt; +use log::debug; use rand::Rng; use tokio::net::TcpStream; use tokio::sync::mpsc::{self, UnboundedReceiver, UnboundedSender}; @@ -15,6 +17,8 @@ use tokio_tungstenite::WebSocketStream; #[derive(Debug, thiserror::Error)] pub enum Error { + #[error("IO error: {0}")] + Io(#[from] io::Error), #[error("WS error: {0}")] Ws(#[from] tungstenite::Error), #[error("MPSC error: {0}")] @@ -31,6 +35,7 @@ pub type Result = result::Result; #[derive(Clone)] pub struct ConnTx { + peer_addr: SocketAddr, tx: UnboundedSender, } @@ -43,12 +48,15 @@ impl fmt::Debug for ConnTx { impl ConnTx { pub fn send(&self, packet: &Packet) -> Result<()> { let str = serde_json::to_string(packet).expect("unserializable packet"); + // TODO Format somewhat nicer? + debug!("<{}> ↑ {}", self.peer_addr, str.trim()); self.tx.send(Message::Text(str))?; Ok(()) } } pub struct ConnRx { + peer_addr: SocketAddr, ws_rx: SplitStream>, last_ping_payload: Arc>>, } @@ -66,6 +74,7 @@ impl ConnRx { None => return Ok(None), Some(msg) => msg?, }; + let str = match msg { Message::Text(str) => str, Message::Pong(payload) => { @@ -79,7 +88,12 @@ impl ConnRx { Message::Binary(_) => return Err(Error::IllegalBinaryPacket), Message::Close(_) => return Ok(None), }; + let packet = serde_json::from_str(&str)?; + + // TODO Format somewhat nicer? + debug!("<{}> ↓ {}", self.peer_addr, str.trim()); + return Ok(Some(packet)); } } @@ -142,6 +156,7 @@ impl ConnMaintenance { rand::thread_rng().fill(&mut payload); tx.send(Message::Ping(payload.to_vec()))?; + tokio::time::sleep(ping_delay).await; } } @@ -151,12 +166,18 @@ pub fn new( stream: WebSocketStream, ping_delay: Duration, ) -> Result<(ConnTx, ConnRx, ConnMaintenance)> { + let peer_addr = stream.get_ref().peer_addr()?; + let (ws_tx, ws_rx) = stream.split(); let (tx, rx) = mpsc::unbounded_channel(); let last_ping_payload = Arc::new(Mutex::new(vec![])); - let conn_tx = ConnTx { tx: tx.clone() }; + let conn_tx = ConnTx { + peer_addr, + tx: tx.clone(), + }; let conn_rx = ConnRx { + peer_addr, ws_rx, last_ping_payload: last_ping_payload.clone(), }; diff --git a/cove-server/src/main.rs b/cove-server/src/main.rs index f8a4a4f..ad10b7b 100644 --- a/cove-server/src/main.rs +++ b/cove-server/src/main.rs @@ -14,6 +14,7 @@ use cove_core::packets::{ SendRpl, WhoCmd, WhoRpl, }; use cove_core::{Identity, Message, MessageId, Session, SessionId}; +use log::{info, warn}; use rand::Rng; use tokio::net::{TcpListener, TcpStream}; use tokio::sync::Mutex; @@ -255,7 +256,8 @@ impl Server { id, cmd: Cmd::Hello(cmd), }) => (id, cmd), - _ => return Err(anyhow!("not a Hello command")), + Some(_) => return Err(anyhow!("not a Hello packet")), + None => return Err(anyhow!("connection closed during greeting")), }; if let Some((room, session)) = self.handle_hello(&tx, id, cmd).await? { @@ -312,17 +314,30 @@ impl Server { Ok(()) } - async fn on_conn(self, stream: TcpStream) -> anyhow::Result<()> { - println!("Connection from {}", stream.peer_addr().unwrap()); - let stream = tokio_tungstenite::accept_async(stream).await.unwrap(); + async fn handle_conn(&self, stream: TcpStream) -> anyhow::Result<()> { + let stream = tokio_tungstenite::accept_async(stream).await?; let (tx, rx, maintenance) = conn::new(stream, Duration::from_secs(10))?; tokio::try_join!(self.greet_and_run(tx, rx), Self::maintain(maintenance))?; Ok(()) } + + async fn on_conn(self, stream: TcpStream) -> anyhow::Result<()> { + let peer_addr = stream.peer_addr()?; + info!("<{peer_addr}> Connected"); + + if let Err(e) = self.handle_conn(stream).await { + warn!("<{peer_addr}> Err: {e}"); + } + + info!("<{peer_addr}> Disconnected"); + Ok(()) + } } #[tokio::main] async fn main() { + env_logger::init(); + let server = Server::new(); let listener = TcpListener::bind(("::0", 40080)).await.unwrap(); while let Ok((stream, _)) = listener.accept().await {