diff --git a/Cargo.lock b/Cargo.lock index 18fd268..7be745d 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -24,6 +24,65 @@ dependencies = [ "zerocopy", ] +[[package]] +name = "aho-corasick" +version = "1.1.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c982642fa9e8606056828ee9a8505737230110bb1099153c79efe865c59d12ba" +dependencies = [ + "memchr", +] + +[[package]] +name = "anstream" +version = "1.0.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "824a212faf96e9acacdbd09febd34438f8f711fb84e09a8916013cd7815ca28d" +dependencies = [ + "anstyle", + "anstyle-parse", + "anstyle-query", + "anstyle-wincon", + "colorchoice", + "is_terminal_polyfill", + "utf8parse", +] + +[[package]] +name = "anstyle" +version = "1.0.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "940b3a0ca603d1eade50a4846a2afffd5ef57a9feac2c0e2ec2e14f9ead76000" + +[[package]] +name = "anstyle-parse" +version = "1.0.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "52ce7f38b242319f7cabaa6813055467063ecdc9d355bbb4ce0c68908cd8130e" +dependencies = [ + "utf8parse", +] + +[[package]] +name = "anstyle-query" +version = "1.1.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "40c48f72fd53cd289104fc64099abca73db4166ad86ea0b4341abe65af83dadc" +dependencies = [ + "windows-sys", +] + +[[package]] +name = "anstyle-wincon" +version = "3.0.11" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "291e6a250ff86cd4a820112fb8898808a366d8f9f58ce16d1f538353ad55747d" +dependencies = [ + "anstyle", + "once_cell_polyfill", + "windows-sys", +] + [[package]] name = "anyhow" version = "1.0.104" @@ -103,6 +162,12 @@ version = "1.8.3" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "2af50177e190e07a26ab74f8b1efbfe2ef87da2116221318cb1c2e82baf7de06" +[[package]] +name = "bitflags" +version = "1.3.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bef38d45163c2f1dde094a7dfd33ccf595c92905c8f8f4fdc18d06fb1037718a" + [[package]] name = "bitflags" version = "2.13.1" @@ -204,6 +269,12 @@ version = "0.5.4" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "0c9ea0ac24bc397ab3c98583a3c9ba74fa56b09a4449bbe172b9b1ddb016027a" +[[package]] +name = "colorchoice" +version = "1.0.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1d07550c9036bf2ae0c684c4297d503f838287c83c53686d05370d0e139ae570" + [[package]] name = "const-oid" version = "0.9.6" @@ -312,6 +383,37 @@ version = "2.11.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "4583a4551df46e2792f82ceeac45e850d2e2d5debba0b91f102385cda5b11f06" +[[package]] +name = "defmt" +version = "1.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e2953bfe4f93bbd20cc71198842756f77d161884c99ebbabc41d80231ded88d1" +dependencies = [ + "bitflags 1.3.2", + "defmt-macros", +] + +[[package]] +name = "defmt-macros" +version = "1.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bad9c72e7ca2137e0dc3813245a0d282fd6daad32fd800af018306a9169b5fe8" +dependencies = [ + "defmt-parser", + "proc-macro2", + "quote", + "syn 2.0.119", +] + +[[package]] +name = "defmt-parser" +version = "1.0.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "10d60334b3b2e7c9d91ef8150abfb6fa4c1c39ebbcf4a81c2e346aad939fee3e" +dependencies = [ + "thiserror", +] + [[package]] name = "der" version = "0.7.10" @@ -378,7 +480,9 @@ dependencies = [ "chacha20poly1305", "curve25519-dalek 5.0.0", "ed25519-dalek", + "env_logger", "futures-util", + "log", "rand 0.8.7", "rusqlite", "serde", @@ -390,6 +494,29 @@ dependencies = [ "x25519-dalek", ] +[[package]] +name = "env_filter" +version = "2.0.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "900d271a03799a1ee8d1ca9b19893b48ca674a9284fefcfb85f05e74ed314217" +dependencies = [ + "log", + "regex", +] + +[[package]] +name = "env_logger" +version = "0.11.11" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "de671bd27a75a797dc9ae289ba1e77276e75e2026408aab65185384e2d5cd3f6" +dependencies = [ + "anstream", + "anstyle", + "env_filter", + "jiff", + "log", +] + [[package]] name = "fallible-iterator" version = "0.3.0" @@ -648,12 +775,54 @@ dependencies = [ "hybrid-array", ] +[[package]] +name = "is_terminal_polyfill" +version = "1.70.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a6cb138bb79a146c1bd460005623e142ef0181e3d0219cb493e02f7d08a35695" + [[package]] name = "itoa" version = "1.0.18" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "8f42a60cbdf9a97f5d2305f08a87dc4e09308d1276d28c869c684d7777685682" +[[package]] +name = "jiff" +version = "0.2.35" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "668b7183bd07af9a4885f5c35b0cc5c83c4607a913c16b7e17291832910d2dcc" +dependencies = [ + "defmt", + "jiff-core", + "jiff-static", + "log", + "portable-atomic", + "portable-atomic-util", + "serde_core", +] + +[[package]] +name = "jiff-core" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7feca88439efe53da3754500c1851dedf3cb36c524dd5cf8225cc0794de95d09" +dependencies = [ + "defmt", +] + +[[package]] +name = "jiff-static" +version = "0.2.35" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3a69dcb3a21cfb32ce1cd056169337ca284af0766dd766e7878819b251a49204" +dependencies = [ + "jiff-core", + "proc-macro2", + "quote", + "syn 2.0.119", +] + [[package]] name = "js-sys" version = "0.3.104" @@ -733,6 +902,12 @@ version = "1.21.4" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9f7c3e4beb33f85d45ae3e3a1792185706c8e16d043238c593331cc7cd313b50" +[[package]] +name = "once_cell_polyfill" +version = "1.70.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "384b8ab6d37215f3c5301a95a4accb5d64aa607f1fcb26a11b5303878451b4fe" + [[package]] name = "percent-encoding" version = "2.3.2" @@ -771,6 +946,21 @@ dependencies = [ "universal-hash", ] +[[package]] +name = "portable-atomic" +version = "1.15.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "05c8b63e8d9609db387f0324918f81d68fe27748f084ef092fb35954d0539a85" + +[[package]] +name = "portable-atomic-util" +version = "0.2.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c2a106d1259c23fac8e543272398ae0e3c0b8d33c88ed73d0cc71b0f1d902618" +dependencies = [ + "portable-atomic", +] + [[package]] name = "ppv-lite86" version = "0.2.21" @@ -875,13 +1065,42 @@ version = "0.10.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "63b8176103e19a2643978565ca18b50549f6101881c443590420e4dc998a3c69" +[[package]] +name = "regex" +version = "1.13.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f020237b6c8eed93db2e2cb53c00c60a8e1bc73da7d073199a1180401450218d" +dependencies = [ + "aho-corasick", + "memchr", + "regex-automata", + "regex-syntax", +] + +[[package]] +name = "regex-automata" +version = "0.4.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ad8553b9b26413251cbf30e620595c7a41b3887f03da04579c0e6b0d6a06b4b2" +dependencies = [ + "aho-corasick", + "memchr", + "regex-syntax", +] + +[[package]] +name = "regex-syntax" +version = "0.8.11" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d6f6ff9a378485b298a5286656da665ba74413d36db0979633275d2e708145d4" + [[package]] name = "rusqlite" version = "0.31.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "b838eba278d213a8beaf485bd313fd580ca4505a00d5871caeb1457c55322cae" dependencies = [ - "bitflags", + "bitflags 2.13.1", "fallible-iterator", "fallible-streaming-iterator", "hashlink", @@ -1204,7 +1423,7 @@ version = "0.7.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "b11f75e912b0c2be01b63d8cf8057b8c3f97cf34abb3d431a3a4c8675498e233" dependencies = [ - "bitflags", + "bitflags 2.13.1", "bytes", "futures-core", "futures-util", @@ -1299,6 +1518,12 @@ dependencies = [ "ctutils", ] +[[package]] +name = "utf8parse" +version = "0.2.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "06abde3611657adf66d383f00b093d7faecc7fa57071cce2578660c9f1010821" + [[package]] name = "uuid" version = "1.24.1" diff --git a/Cargo.toml b/Cargo.toml index 4b8d01a..ae279b1 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -10,6 +10,8 @@ serde = { version = "1.0.229", features = ["serde_derive"] } serde_json = "1.0.151" tokio = { version = "1.53.1", features = ["rt", "rt-multi-thread", "macros", "sync", "fs"] } ed25519-dalek = { version = "2", features = ["rand_core"] } +env_logger = "0.11" +log = "0.4" rand = "0.8" bs58 = "0.5.1" tower-http = { version = "0.7.0", features = ["fs", "cors"] } diff --git a/src/crypto.rs b/src/crypto.rs index d0caaa2..abc0ed8 100644 --- a/src/crypto.rs +++ b/src/crypto.rs @@ -20,8 +20,10 @@ pub async fn get() -> anyhow::Result { if !private_key_path.exists() { let key = SigningKey::generate(&mut OsRng); tokio::fs::write(private_key_path, &key.to_bytes()).await?; + log::info!("Generated new server signing key at private.key"); Ok(key) } else { + log::debug!("Loaded existing server signing key from private.key"); Ok(SigningKey::from_bytes( &tokio::fs::read(private_key_path) .await? @@ -140,6 +142,8 @@ pub async fn crypto_handshake( server: &Arc, mut socket: WebSocket, ) -> anyhow::Result { + log::info!("Handshake: sending server x25519 public key"); + socket .send(axum::extract::ws::Message::Binary( server.identity.x25519.public.to_bytes().to_vec().into(), @@ -159,9 +163,13 @@ pub async fn crypto_handshake( "Failed to get proper length of client x key" ))?); + log::debug!("Handshake: received client x25519 public key"); + let shared_secret = server.identity.x25519.secret.diffie_hellman(&client_pubkey); let cipher = Arc::new(Mutex::new(SessionCipher::new(&shared_secret)?)); + log::info!("Handshake: session cipher established with client"); + Ok(EnclaveWebSocket::new(socket, cipher)) } diff --git a/src/data/config.rs b/src/data/config.rs index af358f8..c6eaa25 100644 --- a/src/data/config.rs +++ b/src/data/config.rs @@ -58,11 +58,17 @@ impl Config { if !config_path.exists() { let config = Config::new(); tokio::fs::write(config_path, &serde_json::to_string_pretty(&config)?).await?; + log::info!("No config.json found, wrote default config"); Ok(config) } else { - Ok(serde_json::from_str( - &tokio::fs::read_to_string(config_path).await?, - )?) + let config: Config = + serde_json::from_str(&tokio::fs::read_to_string(config_path).await?)?; + log::info!( + "Loaded config: {} (port {})", + config.meta.name, + config.port + ); + Ok(config) } } } diff --git a/src/main.rs b/src/main.rs index 7f5b833..90f3eff 100644 --- a/src/main.rs +++ b/src/main.rs @@ -25,6 +25,12 @@ use crate::server::Server; #[tokio::main] async fn main() -> anyhow::Result<()> { + env_logger::Builder::from_env(env_logger::Env::default().default_filter_or("info")) + .format_timestamp_millis() + .init(); + + log::info!("Starting enclave-server v{}", env!("CARGO_PKG_VERSION")); + let server = Server::new().await?; let udp_server = tokio::spawn(server.voice.clone().run(server.config.port)); @@ -47,8 +53,12 @@ async fn main() -> anyhow::Result<()> { )) .await?; + log::info!("HTTP/WS server listening on 0.0.0.0:{}", server.config.port); + axum::serve(listener, app).await?; + log::info!("Shutting down UDP voice server"); + udp_server.abort(); Ok(()) diff --git a/src/protocol/initialize.rs b/src/protocol/initialize.rs index 59452c7..8e0052c 100644 --- a/src/protocol/initialize.rs +++ b/src/protocol/initialize.rs @@ -25,6 +25,8 @@ pub async fn initialize( hostname, }) = socket.read().await? else { + log::warn!("Client sent the wrong method during initialization"); + socket .send(&ClientMethod::Error { error: Cow::Borrowed("Initialization required"), @@ -39,6 +41,8 @@ pub async fn initialize( let server_timestamp = SystemTime::now().duration_since(UNIX_EPOCH)?.as_millis() as u64; if server_timestamp.saturating_sub(timestamp) > 2000 { + log::warn!("Client timestamp wasn't correct (server {server_timestamp}, client {timestamp})"); + socket .send(&ClientMethod::Error { error: Cow::Borrowed( @@ -51,6 +55,8 @@ pub async fn initialize( } if !server.config.hostnames.contains(&hostname) { + log::warn!("Client sent invalid hostname: {hostname}"); + socket.send( &ClientMethod::Error { error: Cow::Owned(format!("Invalid Hostname, to avoid man-in-the-middle attacks, please use the correct hostname(s): {}", server.config.hostnames.clone().into_iter().collect::>().join(", "))), @@ -62,6 +68,8 @@ pub async fn initialize( } let Ok(public_key) = crate::crypto::from_string(&public_key_string) else { + log::warn!("Client sent an invalid public key: {public_key_string}"); + socket .send(&ClientMethod::Error { error: Cow::Borrowed("Invalid public key"), @@ -78,6 +86,8 @@ pub async fn initialize( ) .is_err() { + log::warn!("Client signature verification failed for {public_key_string}"); + socket .send(&ClientMethod::Error { error: Cow::Borrowed("Invalid signature"), @@ -87,6 +97,8 @@ pub async fn initialize( return Err(anyhow::anyhow!("Invalid signature")); } + log::info!("Client authenticated: {public_key_string} (hostname: {hostname})"); + { socket .send(&ClientMethod::Initialized { @@ -102,6 +114,8 @@ pub async fn initialize( } let Some(ServerMethod::Meta(meta)) = socket.read().await? else { + log::warn!("Client {public_key_string} didn't send meta during initialization"); + socket .send(&ClientMethod::Error { error: Cow::Borrowed("Expected meta"), diff --git a/src/protocol/message.rs b/src/protocol/message.rs index c6776e7..ee5b5f9 100644 --- a/src/protocol/message.rs +++ b/src/protocol/message.rs @@ -44,9 +44,15 @@ pub async fn send_message( server.store.messages.insert_message(&channel_id, &stored)?; -server - .sessions - .broadcast(&ClientMethod::Messages { + log::info!( + "Message sent by {} in channel {channel_id} (id {})", + stored.author, + stored.id + ); + + server + .sessions + .broadcast(&ClientMethod::Messages { messages: HashMap::from([(channel_id, vec![stored])]), }) .await?; @@ -68,6 +74,8 @@ pub async fn get_messages( .messages .get_recent_messages(&channel_id, CHUNK_SIZE, chunk)?; + log::debug!("Serving {} messages for {channel_id} (chunk {chunk})", messages.len()); + socket .send(&ClientMethod::Messages { messages: HashMap::from([(channel_id, messages)]), @@ -114,6 +122,8 @@ pub async fn edit_message( .messages .update_message(&channel_id, &message_id, &new_content, &new_signature)?; + log::info!("Message {message_id} edited in channel {channel_id}"); + let updated = StoredMessage { id: message_id, author: author_pubkey, @@ -125,9 +135,9 @@ pub async fn edit_message( }, }; -server - .sessions - .broadcast(&ClientMethod::MessageEdited { + server + .sessions + .broadcast(&ClientMethod::MessageEdited { channel_id: channel_id.clone(), message: updated, }) @@ -158,9 +168,11 @@ pub async fn delete_message( .messages .delete_message(&channel_id, &message_id)?; -server - .sessions - .broadcast(&ClientMethod::MessageDeleted { + log::info!("Message {message_id} deleted in channel {channel_id}"); + + server + .sessions + .broadcast(&ClientMethod::MessageDeleted { channel_id: channel_id.clone(), message_id, }) diff --git a/src/protocol/mod.rs b/src/protocol/mod.rs index 9cb3a1b..6ab76fe 100644 --- a/src/protocol/mod.rs +++ b/src/protocol/mod.rs @@ -118,9 +118,13 @@ pub async fn read_loop( verifying_key: VerifyingKey, socket: &Arc, ) -> anyhow::Result<()> { + let pubkey_string = crate::crypto::to_string(&verifying_key); + while let Some(message) = socket.read().await? { match message { ServerMethod::Initialize { .. } => { + log::warn!("Client {pubkey_string} sent Initialize after already initializing"); + socket .send(&ClientMethod::Error { error: Cow::Borrowed("Already initialized"), @@ -132,7 +136,7 @@ pub async fn read_loop( ServerMethod::Meta(meta) => {} ServerMethod::Error { error } => { - eprintln!("Client error: {error}"); + log::warn!("Client error (client {pubkey_string}): {error}"); } ServerMethod::SendMessage { channel_id, data } => { diff --git a/src/protocol/user.rs b/src/protocol/user.rs index 1295aa8..bcc1020 100644 --- a/src/protocol/user.rs +++ b/src/protocol/user.rs @@ -12,6 +12,8 @@ pub async fn get_users( ) -> anyhow::Result<()> { let users = server.store.users.get_users(&pubkeys).await?; + log::debug!("Serving {} user infos", users.len()); + socket.send(&ClientMethod::Users { users }).await?; Ok(()) diff --git a/src/protocol/voice.rs b/src/protocol/voice.rs index d4f60c4..1590189 100644 --- a/src/protocol/voice.rs +++ b/src/protocol/voice.rs @@ -18,6 +18,11 @@ pub async fn join( let pin = server.voice.join(verifying_key, user, &channel_id).await; + log::info!( + "User {} joining voice channel {channel_id}", + crate::crypto::to_string(&verifying_key) + ); + socket .send(&ClientMethod::JoinVoice { channel_id: channel_id.clone(), @@ -38,6 +43,10 @@ pub async fn join( pub async fn leave(server: &Arc, verifying_key: VerifyingKey) -> anyhow::Result<()> { let Some(channel_id) = server.voice.remove(verifying_key).await else { + log::debug!( + "User {} requested LeaveVoice but wasn't in any channel", + crate::crypto::to_string(&verifying_key) + ); return Ok(()); }; diff --git a/src/server/mod.rs b/src/server/mod.rs index fe9bfbb..efcfbcf 100644 --- a/src/server/mod.rs +++ b/src/server/mod.rs @@ -46,7 +46,7 @@ impl Server { let client = match crate::crypto::crypto_handshake(&s, socket).await { Ok(client) => client, Err(err) => { - eprintln!("Failed to initialize crypto: {err}"); + log::error!("Failed to initialize crypto: {err}"); return; } }; @@ -59,30 +59,42 @@ impl Server { .upsert_user(&crate::crypto::to_string(&public_key), &meta) .await { - eprintln!("Failed to upsert client: {e}"); + log::error!("Failed to upsert client: {e}"); } + let pubkey_string = crate::crypto::to_string(&public_key); + + log::info!("Client connected: {pubkey_string}"); + let (client, conid) = s.sessions.register(public_key, meta, client).await; if let Err(e) = read_loop(&s, public_key, &client).await { - eprintln!("Failed to handle client: {e}"); + log::warn!("Client read loop errored: {e}"); } - if s.sessions.deregister(public_key, conid).await - && let Some(channel_id) = s.voice.remove(public_key).await - { - s.sessions - .broadcast(&ClientMethod::UserLeftVoice { - channel_id, - pubkey: crate::crypto::to_string(&public_key), - }) - .await - .ok(); + if s.sessions.deregister(public_key, conid).await { + log::debug!("Deregistered last connection for {pubkey_string}"); + + if let Some(channel_id) = s.voice.remove(public_key).await { + log::info!( + "User left voice after disconnect: {pubkey_string} ({channel_id})" + ); + + s.sessions + .broadcast(&ClientMethod::UserLeftVoice { + channel_id, + pubkey: pubkey_string.clone(), + }) + .await + .ok(); + } } + + log::info!("Client disconnected: {pubkey_string}"); } Err(e) => { - eprintln!("Failed to initialize client: {e}") + log::warn!("Failed to initialize client: {e}") } } }) diff --git a/src/server/session.rs b/src/server/session.rs index da0d153..9a58de3 100644 --- a/src/server/session.rs +++ b/src/server/session.rs @@ -75,6 +75,11 @@ impl SessionRegistry { user.connections.lock().await.insert(conid, client.clone()); + log::debug!( + "Registered connection {conid} for user {}", + crate::crypto::to_string(&public_key) + ); + (client, conid) } @@ -91,6 +96,11 @@ impl SessionRegistry { let mut connections = user.connections.lock().await; connections.remove(&conid); + log::debug!( + "Deregistered connection {conid} for user {}", + crate::crypto::to_string(&public_key) + ); + if connections.is_empty() { clients.remove(&public_key); true @@ -104,7 +114,7 @@ impl SessionRegistry { for user in users { if let Err(e) = user.send(message).await { - eprintln!("Failed to send to a client: {:?}", e); + log::warn!("Failed to send to a client: {e:?}"); } } diff --git a/src/server/store.rs b/src/server/store.rs index d3465ab..1585a64 100644 --- a/src/server/store.rs +++ b/src/server/store.rs @@ -9,9 +9,13 @@ pub struct DataStore { impl DataStore { pub fn new() -> anyhow::Result { - Ok(Self { + let store = Self { messages: MessageStore::new(PathBuf::from("messages"))?, users: UserMetaStore::new(PathBuf::from("users.db"))?, - }) + }; + + log::debug!("Opened data store (messages/, users.db)"); + + Ok(store) } } \ No newline at end of file diff --git a/src/server/vc_server.rs b/src/server/vc_server.rs index ed43c23..3a627c1 100644 --- a/src/server/vc_server.rs +++ b/src/server/vc_server.rs @@ -79,6 +79,11 @@ impl VoiceServer { }, ); + log::debug!( + "User {} joined voice channel {channel_id} (pin allocated)", + crate::crypto::to_string(&public_key) + ); + pin } @@ -94,6 +99,11 @@ impl VoiceServer { self.pins.lock().await.retain(|_, pin| pin.pubkey != public_key); + log::info!( + "User {} left voice channel {channel_id}", + crate::crypto::to_string(&public_key) + ); + Some(channel_id) } @@ -109,13 +119,13 @@ impl VoiceServer { let mut buf = [0u8; 4096]; - eprintln!("[vc] UDP server listening on port {port}"); + log::info!("UDP voice server listening on port {port}"); loop { let (len, addr) = self.get_voice_socket()?.recv_from(&mut buf).await?; if len < 8 { - eprintln!("[vc] dropping packet too short for pin"); + log::warn!("Dropping voice packet too short for pin from {addr}"); continue; } @@ -128,13 +138,17 @@ impl VoiceServer { let mut pins = self.pins.lock().await; if let Some(pin) = pins.remove(&pin) { + log::debug!("Voice address {addr} bound via pin for user {}", crate::crypto::to_string(&pin.pubkey)); (pin.pubkey, pin.channel_id, &buf[8..len], true) } else { drop(pins); match self.find_sender(&addr).await { Some((pubkey, channel_id)) => (pubkey, channel_id, &buf[..len], false), - None => continue, + None => { + log::warn!("Voice packet from unknown address {addr}"); + continue; + } } } }; @@ -153,14 +167,14 @@ impl VoiceServer { let participants = self.participants.lock().await; participants.get(&sender_pubkey).map(|p| p.user.cipher.clone()) }) else { - eprintln!("[vc] sender pubkey not found in participants, dropping"); + log::warn!("Voice packet from user not in any channel, dropping"); continue; }; let decrypted_payload = match cipher.lock().await.decrypt(payload) { Ok(pt) => pt, Err(e) => { - eprintln!("[vc] dropping packet: decryption failed: {e}"); + log::warn!("Dropping voice packet: decryption failed: {e}"); continue; } }; @@ -172,7 +186,7 @@ impl VoiceServer { .relay_voice(&sender_pubkey, &channel_id, &decrypted_payload) .await { - eprintln!("{e}"); + log::warn!("Voice relay error: {e}"); } }); } diff --git a/src/ws.rs b/src/ws.rs index efae90e..95668b9 100644 --- a/src/ws.rs +++ b/src/ws.rs @@ -31,26 +31,37 @@ impl EnclaveWebSocket { pub async fn read(&self) -> anyhow::Result> { match self.rx.lock().await.next().await.transpose()? { - Some(Message::Text(text)) => match serde_json::from_str(&text.to_string()) { - Ok(msg) => Ok(Some(msg)), + Some(Message::Text(text)) => { + let text = text.to_string(); + match serde_json::from_str::(&text) { + Ok(msg) => { + log::debug!("Received message: {msg:?}"); + Ok(Some(msg)) + } - Err(e) => { - self.send(&ClientMethod::Error { - error: Cow::Owned(format!("Unable to parse message: {e}")), - }) - .await?; + Err(e) => { + log::warn!("Failed to parse client message: {e}"); + self.send(&ClientMethod::Error { + error: Cow::Owned(format!("Unable to parse message: {e}")), + }) + .await?; - Ok(None) + Ok(None) + } } - }, + } Some(Message::Binary(encrypted)) => { let text = String::from_utf8(self.cipher.lock().await.decrypt(&encrypted)?)?; - match serde_json::from_str(&text.to_string()) { - Ok(msg) => Ok(Some(msg)), + match serde_json::from_str::(&text) { + Ok(msg) => { + log::debug!("Received message: {msg:?}"); + Ok(Some(msg)) + } Err(e) => { + log::warn!("Failed to parse client message: {e}"); self.send(&ClientMethod::Error { error: Cow::Owned(format!("Unable to parse message: {e}")), }) @@ -67,7 +78,10 @@ impl EnclaveWebSocket { Ok(None) } - Some(_) => Ok(None), + Some(other) => { + log::debug!("Ignoring websocket message: {other:?}"); + Ok(None) + } None => Ok(None), } @@ -76,6 +90,8 @@ impl EnclaveWebSocket { pub async fn send(&self, message: &ClientMethod) -> anyhow::Result<()> { let text = serde_json::to_string(message)?; + log::debug!("Sending message: {message:?}"); + let encrypted = self.cipher.lock().await.encrypt(text.as_bytes())?; self.tx