improved logging

main
Kyle Johnsen 2022-02-13 14:33:47 -05:00
parent 39d7359475
commit 7f94b70c4e
3 changed files with 119 additions and 35 deletions

86
Cargo.lock generated
View File

@ -5,3 +5,89 @@ version = 3
[[package]] [[package]]
name = "VelNetServerRust" name = "VelNetServerRust"
version = "0.1.0" version = "0.1.0"
dependencies = [
"chrono",
]
[[package]]
name = "autocfg"
version = "1.1.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "d468802bab17cbc0cc575e9b053f41e72aa36bfa6b7f55e3529ffa43161b97fa"
[[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",
]
[[package]]
name = "libc"
version = "0.2.117"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "e74d72e0f9b65b5b4ca49a346af3976df0f9c61d550727f349ecd559f251a26c"
[[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"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "9a64b1ec5cda2586e284722486d802acf1f7dbdc623e2bfc57e65ca1cd099290"
dependencies = [
"autocfg",
]
[[package]]
name = "time"
version = "0.1.44"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "6db9e6914ab8b1ae1c260a4ae7a49b6c5611b40328a735b21862567685e73255"
dependencies = [
"libc",
"wasi",
"winapi",
]
[[package]]
name = "wasi"
version = "0.10.0+wasi-snapshot-preview1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "1a143597ca7c7793eff794def352d41792a93c481eb1042423ff7ff72ba2c31f"
[[package]]
name = "winapi"
version = "0.3.9"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "5c839a674fcd7a98952e593242ea400abe93992746761e38641405d28b00f419"
dependencies = [
"winapi-i686-pc-windows-gnu",
"winapi-x86_64-pc-windows-gnu",
]
[[package]]
name = "winapi-i686-pc-windows-gnu"
version = "0.4.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6"
[[package]]
name = "winapi-x86_64-pc-windows-gnu"
version = "0.4.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f"

View File

@ -6,3 +6,4 @@ edition = "2021"
# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html # See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html
[dependencies] [dependencies]
chrono = "*"

View File

@ -1,3 +1,5 @@
extern crate chrono;
use std::io::prelude::*; use std::io::prelude::*;
use std::thread; use std::thread;
use std::net::{TcpListener, TcpStream,UdpSocket,IpAddr,SocketAddr}; use std::net::{TcpListener, TcpStream,UdpSocket,IpAddr,SocketAddr};
@ -5,7 +7,7 @@ use std::collections::HashMap;
use std::sync::{Arc,RwLock}; use std::sync::{Arc,RwLock};
use std::sync::mpsc; use std::sync::mpsc;
use std::sync::mpsc::{SyncSender,Receiver}; use std::sync::mpsc::{SyncSender,Receiver};
use chrono::Local;
enum ToClientTCPMessageType { enum ToClientTCPMessageType {
LoggedIn = 0, LoggedIn = 0,
RoomList = 1, RoomList = 1,
@ -101,7 +103,7 @@ fn read_login_message(stream: &mut TcpStream, client: &Arc<Client>) {
let username = read_short_string(stream); let username = read_short_string(stream);
let application = read_short_string(stream); let application = read_short_string(stream);
println!("Got application {} and userid {}",application,username); println!("{}: Got application {} and userid {}",Local::now().format("%Y-%m-%d %H:%M:%S"),application,username);
let mut client_user = client.username.write().unwrap(); let mut client_user = client.username.write().unwrap();
*client_user = username; *client_user = username;
let mut client_application = client.application.write().unwrap(); let mut client_application = client.application.write().unwrap();
@ -117,7 +119,6 @@ fn read_login_message(stream: &mut TcpStream, client: &Arc<Client>) {
//this is in response to a request for rooms. //this is in response to a request for rooms.
fn read_rooms_message(_stream: &mut TcpStream, client: &Arc<Client>){ fn read_rooms_message(_stream: &mut TcpStream, client: &Arc<Client>){
println!("Got rooms message");
let mut write_buf = vec![]; let mut write_buf = vec![];
write_buf.push(ToClientTCPMessageType::RoomList as u8); write_buf.push(ToClientTCPMessageType::RoomList as u8);
@ -153,18 +154,17 @@ fn read_rooms_message(_stream: &mut TcpStream, client: &Arc<Client>){
fn read_roomdata_message(stream: &mut TcpStream, client: &Arc<Client>){ fn read_roomdata_message(stream: &mut TcpStream, client: &Arc<Client>){
//type, room_name //type, room_name
//will respond with type, numclients u32, id1 u32, name_len u8, name_bytes ... //will respond with type, numclients u32, id1 u32, name_len u8, name_bytes ...
println!("Got room data message");
//read the room name and append the client application //read the room name and append the client application
let short_room_name = read_short_string(stream); let short_room_name = read_short_string(stream);
let application = client.application.read().unwrap().to_string(); let application = client.application.read().unwrap().to_string();
let room_name = format!("{}_{}", application, short_room_name); let room_name = format!("{}_{}", application, short_room_name);
println!("{}",&room_name);
//we need to access the rooms list //we need to access the rooms list
let rooms = client.rooms_mutex.read().unwrap(); let rooms = client.rooms_mutex.read().unwrap();
if rooms.contains_key(&room_name) { if rooms.contains_key(&room_name) {
println!("the room exists");
let room = rooms.get(&room_name).unwrap(); let room = rooms.get(&room_name).unwrap();
//form and send the message //form and send the message
let mut write_buf = vec![]; let mut write_buf = vec![];
@ -270,7 +270,9 @@ fn client_leave_room(client: &Arc<Client>, send_to_client: bool){
{ {
let mut change_master = false; let mut change_master = false;
let mut new_master_id = 0; let mut new_master_id = 0;
println!("Client in room, leaving"); {
println!("{}: {}: Client {} in room, leaving",Local::now().format("%Y-%m-%d %H:%M:%S"), client.application.read().unwrap().to_string(),client.id);
}
let room = room.as_ref().unwrap(); let room = room.as_ref().unwrap();
//may have to choose a new master //may have to choose a new master
@ -280,14 +282,11 @@ fn client_leave_room(client: &Arc<Client>, send_to_client: bool){
let clients = room.clients.read().unwrap(); let clients = room.clients.read().unwrap();
let master_client = room.master_client.read().unwrap(); let master_client = room.master_client.read().unwrap();
if master_client.id == client.id { if master_client.id == client.id {
println!("Will change master");
//change the master //change the master
change_master = true; change_master = true;
} }
println!("Client leaving current room {}",&room.name);
for (_k,v) in clients.iter() { for (_k,v) in clients.iter() {
if !send_to_client && v.id == client.id{ if !send_to_client && v.id == client.id{
continue; continue;
@ -311,7 +310,9 @@ fn client_leave_room(client: &Arc<Client>, send_to_client: bool){
if clients.len() == 0 { if clients.len() == 0 {
let mut rooms = client.rooms_mutex.write().unwrap(); let mut rooms = client.rooms_mutex.write().unwrap();
rooms.remove(&room.name); rooms.remove(&room.name);
println!("Destroyed room {}",&room.name) {
println!("{}: {}: Destroyed room {}",Local::now().format("%Y-%m-%d %H:%M:%S"), client.application.read().unwrap().to_string(), &room.name)
}
}else if change_master{ }else if change_master{
for (_k,v) in clients.iter() { for (_k,v) in clients.iter() {
@ -321,7 +322,9 @@ fn client_leave_room(client: &Arc<Client>, send_to_client: bool){
} }
} }
println!("Changing master to {}",new_master_id); {
println!("{}: Changing master to {}",client.application.read().unwrap().to_string(), new_master_id);
}
for (_k,v) in clients.iter() { for (_k,v) in clients.iter() {
send_client_master_message(&v, new_master_id); send_client_master_message(&v, new_master_id);
} }
@ -332,8 +335,6 @@ fn client_leave_room(client: &Arc<Client>, send_to_client: bool){
} }
} }
} else{
println!("Client not in room");
} }
} }
{ {
@ -351,15 +352,11 @@ fn read_join_message(stream: &mut TcpStream, client: &Arc<Client>){
let extended_room_name = format!("{}_{}", application, short_room_name); let extended_room_name = format!("{}_{}", application, short_room_name);
println!("Got room message {}",short_room_name);
//if the client is in a room, leave it //if the client is in a room, leave it
let mut leave_room = false; let mut leave_room = false;
{ {
let room = client.room.read().unwrap(); //must release this mutex before calling into a function that uses it let room = client.room.read().unwrap(); //must release this mutex before calling into a function that uses it
if room.as_ref().is_some(){ if room.as_ref().is_some(){
println!("Leaving the current room ");
leave_room = true; leave_room = true;
} }
} }
@ -368,12 +365,10 @@ fn read_join_message(stream: &mut TcpStream, client: &Arc<Client>){
} }
if short_room_name.trim() == "" || short_room_name == "-1" { if short_room_name.trim() == "" || short_room_name == "-1" {
println!("Empty room, leaving");
return; return;
} }
//join room_name //join room_name
{ {
{ {
@ -387,13 +382,13 @@ fn read_join_message(stream: &mut TcpStream, client: &Arc<Client>){
}); });
rooms.insert(String::from(&extended_room_name),r); rooms.insert(String::from(&extended_room_name),r);
println!("New room {} created",&extended_room_name); println!("{}: {}: New room {} created",Local::now().format("%Y-%m-%d %H:%M:%S"), application,&extended_room_name);
} }
//the room is guaranteed to exist now, so this call can't fail //the room is guaranteed to exist now, so this call can't fail
let room_to_join = &rooms[&extended_room_name]; let room_to_join = &rooms[&extended_room_name];
let mut clients = room_to_join.clients.write().unwrap(); let mut clients = room_to_join.clients.write().unwrap();
clients.insert(client.id,client.clone()); clients.insert(client.id,client.clone());
println!("Client {} joined {}",client.id,&extended_room_name); println!("{}: {}: Client {} joined {}",Local::now().format("%Y-%m-%d %H:%M:%S"), application, client.id,&extended_room_name);
let mut room = client.room.write().unwrap(); let mut room = client.room.write().unwrap();
*room = Some(room_to_join.clone()); //we create an option and assign it back to the room *room = Some(room_to_join.clone()); //we create an option and assign it back to the room
} }
@ -458,7 +453,7 @@ fn send_room_message(sender: &Arc<Client>, message: &Vec<u8>, include_sender: bo
} }
match v.sender.send(write_buf.clone()){ match v.sender.send(write_buf.clone()){
Ok(_) => (), Ok(_) => (),
Err(x) => println!("Error sending to client {}: {}",v.id,x) Err(x) => println!("{}: {}: Error sending to client {}: {}",Local::now().format("%Y-%m-%d %H:%M:%S"), v.application.read().unwrap().to_string(),v.id,x)
} //this sometimes fails. } //this sometimes fails.
} }
@ -475,7 +470,7 @@ fn send_room_message(sender: &Arc<Client>, message: &Vec<u8>, include_sender: bo
} }
match v.sender.send(write_buf.clone()){ match v.sender.send(write_buf.clone()){
Ok(_) => (), Ok(_) => (),
Err(x) => println!("Error sending to client {}: {}",v.id,x) Err(x) => println!("{}: {}: Error sending to client {}: {}",Local::now().format("%Y-%m-%d %H:%M:%S"),v.application.read().unwrap().to_string(),v.id,x)
} //this sometimes fails. } //this sometimes fails.
} }
@ -499,7 +494,7 @@ fn send_group_message(sender: &Arc<Client>, message: &Vec<u8>, group: &String){
match c.sender.send(write_buf.clone()) { match c.sender.send(write_buf.clone()) {
Ok(_) => (), Ok(_) => (),
Err(_) => println!("no client in group") Err(_) => ()
} }
} }
} }
@ -526,7 +521,6 @@ fn read_send_message(stream: &mut TcpStream, client: &Arc<Client>, message_type:
fn read_group_message(stream: &mut TcpStream, client: &Arc<Client>){ fn read_group_message(stream: &mut TcpStream, client: &Arc<Client>){
let group = read_short_string(stream); let group = read_short_string(stream);
println!("Got group message {}",&group);
let id_bytes = read_vec(stream); let id_bytes = read_vec(stream);
let num = id_bytes.len(); let num = id_bytes.len();
@ -613,7 +607,7 @@ fn client_write_thread(mut stream: TcpStream, rx: Receiver<Vec<u8>> ) {
fn handle_client(stream: TcpStream, client_id: u32, clients_mutex: Arc<RwLock<HashMap<u32,Arc<Client>>>>, rooms_mutex: Arc<RwLock<HashMap<String,Arc<Room>>>>){ fn handle_client(stream: TcpStream, client_id: u32, clients_mutex: Arc<RwLock<HashMap<u32,Arc<Client>>>>, rooms_mutex: Arc<RwLock<HashMap<String,Arc<Room>>>>){
stream.set_nodelay(true).unwrap(); stream.set_nodelay(true).unwrap();
println!("Accepted new connection"); println!("{}: Accepted new connection, assigned client id {}",Local::now().format("%Y-%m-%d %H:%M:%S"),client_id);
let (tx, rx) = mpsc::sync_channel(10000); let (tx, rx) = mpsc::sync_channel(10000);
//create a new client structure and add it to the list of clients //create a new client structure and add it to the list of clients
@ -658,7 +652,7 @@ fn handle_client(stream: TcpStream, client_id: u32, clients_mutex: Arc<RwLock<Ha
Ok(_)=>(), Ok(_)=>(),
Err(_)=>() Err(_)=>()
} }
println!("Client {} left",client_id); println!("{}: {}: Client {} left",Local::now().format("%Y-%m-%d %H:%M:%S"),client.application.read().unwrap().to_string(),client_id);
//now we can kill the client. //now we can kill the client.
{ {
//make sure we remove the client from all rooms //make sure we remove the client from all rooms
@ -670,7 +664,7 @@ fn handle_client(stream: TcpStream, client_id: u32, clients_mutex: Arc<RwLock<Ha
} }
fn tcp_listen(client_mutex: Arc<RwLock<HashMap<u32, Arc<Client>>>>, room_mutex: Arc<RwLock<HashMap<String,Arc<Room>>>>){ fn tcp_listen(client_mutex: Arc<RwLock<HashMap<u32, Arc<Client>>>>, room_mutex: Arc<RwLock<HashMap<String,Arc<Room>>>>){
println!("Started TCP Listener"); println!("{}: Started TCP Listener",Local::now().format("%Y-%m-%d %H:%M:%S"));
let listener = TcpListener::bind("0.0.0.0:80").expect("could not bind port"); let listener = TcpListener::bind("0.0.0.0:80").expect("could not bind port");
let mut next_client_id = 0; let mut next_client_id = 0;
@ -681,12 +675,13 @@ fn tcp_listen(client_mutex: Arc<RwLock<HashMap<u32, Arc<Client>>>>, room_mutex:
thread::spawn(move || {handle_client(stream.unwrap(), next_client_id, client_mutex, room_mutex)}); thread::spawn(move || {handle_client(stream.unwrap(), next_client_id, client_mutex, room_mutex)});
next_client_id+=1; next_client_id+=1;
} }
println!("{}: Ended TCP Listener",Local::now().format("%Y-%m-%d %H:%M:%S"));
} }
fn udp_listen(client_mutex: Arc<RwLock<HashMap<u32, Arc<Client>>>>, _room_mutex: Arc<RwLock<HashMap<String,Arc<Room>>>>){ fn udp_listen(client_mutex: Arc<RwLock<HashMap<u32, Arc<Client>>>>, _room_mutex: Arc<RwLock<HashMap<String,Arc<Room>>>>){
let mut buf = [0u8;1024]; let mut buf = [0u8;1024];
let s = UdpSocket::bind("0.0.0.0:80").unwrap(); let s = UdpSocket::bind("0.0.0.0:80").unwrap();
println!("UDP Thread Started"); println!("{}: UDP Thread Started",Local::now().format("%Y-%m-%d %H:%M:%S"));
loop { loop {
let res = s.recv_from(&mut buf); let res = s.recv_from(&mut buf);
match res { match res {
@ -807,12 +802,14 @@ fn udp_listen(client_mutex: Arc<RwLock<HashMap<u32, Arc<Client>>>>, _room_mutex:
} }
println!("{}: UDP Thread Ended",Local::now().format("%Y-%m-%d %H:%M:%S"));
} }
fn main() { fn main() {
println!("VelNet Server Starting"); println!("{}: VelNet Server Starting",Local::now().format("%Y-%m-%d %H:%M:%S"));
let clients: HashMap<u32, Arc<Client>> = HashMap::new(); let clients: HashMap<u32, Arc<Client>> = HashMap::new();
let rooms: HashMap<String, Arc<Room>> = HashMap::new(); let rooms: HashMap<String, Arc<Room>> = HashMap::new();
@ -826,5 +823,5 @@ fn main() {
//start the TCP thread //start the TCP thread
tcp_listen(client_mutex, room_mutex); tcp_listen(client_mutex, room_mutex);
udp_handle.join().unwrap(); udp_handle.join().unwrap();
println!("VelNet Ended"); println!("{}: VelNet Ended", Local::now().format("%Y-%m-%d %H:%M:%S"));
} }