logging

WORKLOG.md

@@ -12,12 +12,6 @@
   red + aggro green
   blue + defensive green
 
-- strike
-  - 110 -> 90
-
-- strangle
-  no immunity
-
 - purify
   - 1 effect from all cryps at level 2
   - removes all effects from all cryps at l3
@@ -44,6 +38,10 @@ var / skill info rpc
   etc
 
 *CLIENT*
+
+* animations
+* iconography
+
 * general
   * icons change with %
   * find new icons for colours / life
@@ -53,14 +51,11 @@ var / skill info rpc
 *SERVER*
 Base Items - Buff / Debuff / Stun should be equippable / usable skills
 
-put ticks on stack at start of phase
-
 push events
 
-## SOON
+logging
 
-* Add missing combo - (Red + Blue + Attack) - Duplicated ???
-* Client side confirmation that you've made all decisions
+## SOON
 
 * vbox drops chances
   * 50% spec, 25% colour etc
@@ -69,8 +64,6 @@ push events
   * draw big warning !
   * confirm all (turn timeouts) 10 - 15 seconds
 
-* iconography
-* combo skills
 
 * skills
     * private fields for opponents

client/src/components/instance.cryps.jsx

@@ -66,7 +66,7 @@ function Cryp(props) {
         const skill = cryp.skills[i];
         const s = skill
             ? skill.skill
-            : (<span>&nbsp;</span>);
+            : (<span className="gray">+</span>);
 
         function skillClick(e) {
             if (!skill) setHighlight('skill');
@@ -98,7 +98,7 @@ function Cryp(props) {
             return (
                 <figure key={i} className="gray" onClick={blankSpecClick}>
                     {shapes.diamond('stat-icon gray')}
-                    <figcaption>&nbsp;</figcaption>
+                    <figcaption>+</figcaption>
                 </figure>
             );
         }

server/.gitignore

@@ -1,2 +1,3 @@
 target/
 Cargo.lock
+log/

server/Cargo.toml

@@ -16,10 +16,12 @@ tungstenite = "0.6"
 bcrypt = "0.2"
 
 dotenv = "0.9.0"
-env_logger = "*"
 postgres = { version = "0.15", features = ["with-uuid"] }
 r2d2 = "*"
 r2d2_postgres = "*"
 
 failure = "0.1"
 
+log = "0.4"
+fern = "0.5"
+

server/src/account.rs

@@ -99,7 +99,7 @@ pub fn account_create(params: AccountCreateParams, tx: &mut Transaction) -> Resu
         token: returned.get(2),
     };
 
-    println!("{:?} registered", entry.name);
+    info!("{:?} registered", entry.name);
 
     return Ok(entry);
 }
@@ -132,7 +132,7 @@ pub fn account_login(params: AccountLoginParams, tx: &mut Transaction) -> Result
         return Err(err_msg("password does not match"));
     }
 
-    println!("{:?} logged in", entry.name);
+    info!("{:?} logged in", entry.name);
 
     // MAYBE
     // update token?

server/src/cryp.rs

@@ -411,7 +411,7 @@ impl Cryp {
                 return None;
             }
 
-            // println!("reduced effect {:?}", effect);
+            // info!("reduced effect {:?}", effect);
             return Some(effect);
         }).collect::<Vec<CrypEffect>>();
 
@@ -740,7 +740,7 @@ impl Cryp {
             skill,
         };
 
-        // println!("{:?} {:?} adding effect", self.name, effect.effect);
+        // info!("{:?} {:?} adding effect", self.name, effect.effect);
         self.effects.push(effect);
 
         return result;
@@ -755,7 +755,7 @@ impl Cryp {
         let green_life_pct = (self.green_life.value * 100) / self.green_life.value;
         let evasion_rating = (self.evasion.value * green_life_pct) / 100;
         let roll = rng.gen_range(0, 100);
-        println!("{:} < {:?}", roll, evasion_rating);
+        info!("{:} < {:?}", roll, evasion_rating);
 
         match roll < evasion_rating {
             true => Some(Event::Evasion {
@@ -803,7 +803,7 @@ pub fn cryp_spawn(params: CrypSpawnParams, tx: &mut Transaction, account: &Accou
 
     let _returned = result.iter().next().ok_or(err_msg("no row returned"))?;
 
-    // println!("{:?} spawned cryp {:}", account.id, cryp.id);
+    // info!("{:?} spawned cryp {:}", account.id, cryp.id);
 
     return Ok(cryp);
 }
@@ -823,7 +823,7 @@ pub fn cryp_write(cryp: Cryp, tx: &mut Transaction) -> Result<Cryp, Error> {
 
     let _returned = result.iter().next().expect("no row returned");
 
-    // println!("{:?} wrote cryp", cryp.id);
+    // info!("{:?} wrote cryp", cryp.id);
 
     return Ok(cryp);
 }
@@ -837,7 +837,7 @@ pub fn cryp_recover(cryp_bytes: Vec<u8>, tx: &mut Transaction) -> Result<Cryp, E
 
     cryp.id = c.id;
 
-    println!("recovered cryp {:?}", c.name);
+    info!("recovered cryp {:?}", c.name);
 
     return cryp_write(cryp, tx);
 }

server/src/game.rs

@@ -86,7 +86,7 @@ impl Game {
         }
 
         if player.cryps.iter().all(|c| c.skills.len() == 0) {
-            println!("WARNING: {:?} has no skills and has forfeited {:?}", player.name, self.id);
+            info!("WARNING: {:?} has no skills and has forfeited {:?}", player.name, self.id);
             player.forfeit();
         }
 
@@ -201,7 +201,7 @@ impl Game {
 
             for mob in mobs.cryps.iter() {
                 let skill = mob.mob_select_skill();
-                // println!("{:?} {:?}", mob.name, skill);
+                // info!("{:?} {:?}", mob.name, skill);
                 match skill {
                     Some(s) => {
                         let mut rng = thread_rng();
@@ -232,7 +232,7 @@ impl Game {
             match self.add_skill(player_id, mob_id, target_id, s) {
                 Ok(_) => (),
                 Err(e) => {
-                    println!("{:?}", self.cryp_by_id(mob_id));
+                    info!("{:?}", self.cryp_by_id(mob_id));
                     panic!("{:?} unable to add pve mob skill {:?}", e, s);
                 },
             }
@@ -412,7 +412,7 @@ impl Game {
         let mut casts = vec![];
 
         while let Some(cast) = self.stack.pop() {
-            // println!("{:} casts ", cast);
+            // info!("{:} casts ", cast);
 
             let mut resolutions = resolution_steps(&cast, &mut self);
             resolutions.reverse();
@@ -430,7 +430,7 @@ impl Game {
             self.stack_sort_speed();
         };
 
-        // println!("{:#?}", self.casts);
+        // info!("{:#?}", self.casts);
 
         // handle cooldowns and statuses
         self.progress_durations(&casts);
@@ -444,7 +444,7 @@ impl Game {
 
     fn progress_durations(&mut self, resolved: &Vec<Cast>) -> &mut Game {
         for mut cryp in self.all_cryps() {
-            // println!("progressing durations for {:}", cryp.name);
+            // info!("progressing durations for {:}", cryp.name);
 
             if cryp.is_ko() {
                 continue;
@@ -568,7 +568,7 @@ impl Game {
             return self;
         }
 
-        println!("upkeep beginning: {:} vs {:}", self.players[0].name, self.players[1].name);
+        info!("upkeep beginning: {:} vs {:}", self.players[0].name, self.players[1].name);
 
         if !self.phase_timed_out() {
             return self;
@@ -578,10 +578,10 @@ impl Game {
             if !player.ready {
                 player.set_ready(true);
                 player.add_warning();
-                println!("upkeep: {:} warned", player.name);
+                info!("upkeep: {:} warned", player.name);
                 if player.warnings >= 3 {
                     player.forfeit();
-                    println!("upkeep: {:} forfeited", player.name);
+                    info!("upkeep: {:} forfeited", player.name);
                     self.log.push(format!("{:} forfeited.", player.name));
                 }
             }
@@ -606,7 +606,7 @@ pub fn game_write(tx: &mut Transaction, game: &Game) -> Result<(), Error> {
 
     result.iter().next().ok_or(format_err!("no game written"))?;
 
-    // println!("{:} wrote game", game.id);
+    // info!("{:} wrote game", game.id);
 
     return Ok(());
 }
@@ -686,14 +686,14 @@ pub fn game_delete(tx: &mut Transaction, id: Uuid) -> Result<(), Error> {
         return Err(format_err!("unable to delete player {:?}", id));
     }
 
-    println!("game deleted {:?}", id);
+    info!("game deleted {:?}", id);
 
     return Ok(());
 }
 
 // pub fn game_global_startup(tx: &mut Transaction) -> Result<(), Error> {
 //     if game_global_get(tx).is_ok() {
-//         println!("global mm game exists");
+//         info!("global mm game exists");
 //         return Ok(());
 //     }
 
@@ -717,7 +717,7 @@ pub fn game_delete(tx: &mut Transaction, id: Uuid) -> Result<(), Error> {
 
 //     result.iter().next().ok_or(format_err!("no game written"))?;
 
-//     println!("{:} wrote global mm startup", game.id);
+//     info!("{:} wrote global mm startup", game.id);
 
 //     return Ok(());
 // }
@@ -915,7 +915,7 @@ pub fn game_instance_join(tx: &mut Transaction, player: Player, game_id: Uuid) -
         game = game.start();
     }
 
-    println!("{:?} game joined", game.id);
+    info!("{:?} game joined", game.id);
 
     game_update(tx, &game)?;
 
@@ -1280,7 +1280,7 @@ mod tests {
     //     game.player_ready(y_player.id).unwrap();
     //     game = game.resolve_phase_start();
 
-    //     println!("{:#?}", game);
+    //     info!("{:#?}", game);
     //     assert!(game.cryp_by_id(y_cryp.id).unwrap().affected(Effect::Hatred));
     // }
 

server/src/instance.rs

@@ -320,7 +320,7 @@ impl Instance {
             if game.finished() {
                 self.game_finished(&game).unwrap();
             } else {
-                println!("{:?} unfishededes", game);
+                info!("{:?} unfishededes", game);
             }
         }
 
@@ -519,7 +519,7 @@ pub fn instance_update(tx: &mut Transaction, instance: Instance) -> Result<Insta
 
     result.iter().next().ok_or(err_msg("no instance row returned"))?;
 
-    // println!("{:?} wrote instance", instance.id);
+    // info!("{:?} wrote instance", instance.id);
 
     return Ok(instance);
 }
@@ -560,7 +560,7 @@ pub fn instance_delete(tx: &mut Transaction, id: Uuid) -> Result<(), Error> {
         return Err(format_err!("unable to delete instance {:?}", id));
     }
 
-    println!("instance deleted {:?}", id);
+    info!("instance deleted {:?}", id);
 
     return Ok(());
 }
@@ -655,7 +655,7 @@ pub fn instance_join(params: InstanceJoinParams, tx: &mut Transaction, account:
 //     // get the game
 //     let game = match game_global_get(tx) {
 //         Ok(g) => {
-//             println!("received global game {:?}", g.id);
+//             info!("received global game {:?}", g.id);
 //             // if there is one try to join
 //             match game_instance_join(tx, player.clone(), g.id) {
 //                 Ok(g) => g,
@@ -717,7 +717,7 @@ pub fn global_game_finished(tx: &mut Transaction, game: &Game) -> Result<(), Err
 pub fn instance_game_finished(tx: &mut Transaction, game: &Game, instance_id: Uuid) -> Result<(), Error> {
     let mut instance = instance_get(tx, instance_id)?;
     instance.game_finished(game)?;
-    // println!("{:?}", instance_get(tx, instance_id)?);
+    // info!("{:?}", instance_get(tx, instance_id)?);
 
     instance_update(tx, instance)?;
 
@@ -838,6 +838,6 @@ mod tests {
         assert_eq!(instance.rounds.len(), 2);
         assert!(instance.players.iter().all(|p| !p.ready));
 
-        // println!("{:#?}", instance);
+        // info!("{:#?}", instance);
     }
 }

server/src/item.rs

@@ -121,14 +121,14 @@ pub fn item_drop(tx: &mut Transaction, account_id: Uuid, mode: GameMode) -> Resu
     let num_drops = log_normal.sample(&mut rng).floor() as u16;
 
     let actions = mode_drops(mode);
-    println!("{:?} drops", num_drops);
+    info!("{:?} drops", num_drops);
 
     for _i in 0..num_drops {
         let dist = WeightedIndex::new(actions.iter().map(|item| item.1)).unwrap();
         let kind = actions[dist.sample(&mut rng)].0;
         let item = Item::new(kind, account_id);
 
-        println!("{:?} dropped {:?}", account_id, item);
+        info!("{:?} dropped {:?}", account_id, item);
         item_create(item, tx, account_id)?;
     }
 
@@ -190,7 +190,7 @@ pub fn item_delete(tx: &mut Transaction, id: Uuid) -> Result<(), Error> {
         return Err(format_err!("unable to delete item {:?}", id));
     }
 
-    // println!("item deleted {:?}", id);
+    // info!("item deleted {:?}", id);
 
     return Ok(());
 }

server/src/main.rs

@@ -1,7 +1,6 @@
 extern crate rand;
 extern crate uuid;
 extern crate tungstenite;
-extern crate env_logger;
 extern crate bcrypt;
 extern crate chrono;
 
@@ -15,6 +14,9 @@ extern crate serde_cbor;
 #[macro_use] extern crate serde_derive;
 #[macro_use] extern crate failure;
 
+extern crate fern;
+#[macro_use] extern crate log;
+
 mod cryp;
 mod game;
 mod net;
@@ -33,7 +35,30 @@ mod warden;
 use dotenv::dotenv;
 use net::{start};
 
+fn setup_logger() -> Result<(), fern::InitError> {
+    fern::Dispatch::new()
+        .format(|out, message, record| {
+            out.finish(format_args!(
+                "{}[{}][{}] {}",
+                chrono::Local::now().format("[%Y-%m-%d][%H:%M:%S]"),
+                record.target(),
+                record.level(),
+                message
+            ))
+        })
+        .level_for("postgres", log::LevelFilter::Info)
+        .level_for("tungstenite", log::LevelFilter::Info)
+        .level(log::LevelFilter::Debug)
+        .chain(std::io::stdout())
+        .chain(fern::log_file("log/cryps.log")?)
+        .apply()?;
+    Ok(())
+}
+
 fn main() {
     dotenv().ok();
+    setup_logger().unwrap();
+
+    info!("server started");
     start()
 }

server/src/net.rs

@@ -8,7 +8,7 @@ use serde_cbor::{to_vec};
 
 use std::env;
 use std::thread::{spawn, sleep};
-use std::time::Duration;
+use std::time::{Instant, Duration};
 use std::any::Any;
 use std::panic;
 
@@ -43,7 +43,7 @@ fn receive(db: Db, rpc: &Rpc, msg: Message, client: &mut WebSocket<TcpStream>) -
             client.write_message(Binary(response))
         },
         Err(e) => {
-            println!("{:?}", e);
+            info!("{:?}", e);
             let response = to_vec(&RpcErrorResponse { err: e.to_string() })
                 .expect("failed to serialize error response");
             client.write_message(Binary(response))
@@ -71,16 +71,16 @@ fn print_panic_payload(ctx: &str, payload: &(Any + Send + 'static)) {
         // "PAYLOAD IS NOT A STRING"
         d.as_str()
     };
-    println!("{}: PANIC OCCURRED: {}", ctx, s);
+    info!("{}: PANIC OCCURRED: {}", ctx, s);
 }
 
 pub fn start() {
     panic::set_hook(Box::new(|panic_info| {
         print_panic_payload("set_hook", panic_info.payload());
         if let Some(location) = panic_info.location() {
-            println!("LOCATION: {}:{}", location.file(), location.line());
+            info!("LOCATION: {}:{}", location.file(), location.line());
         } else {
-            println!("NO LOCATION INFORMATION");
+            info!("NO LOCATION INFORMATION");
         }
     }));
 
@@ -101,7 +101,7 @@ pub fn start() {
         loop {
             let db_connection = warden_pool.get().expect("unable to get db connection");
             if let Err(e) = warden(db_connection) {
-                println!("{:?}", e);
+                info!("{:?}", e);
             }
             sleep(Duration::new(5, 0));
         }
@@ -117,15 +117,17 @@ pub fn start() {
             loop {
                 match websocket.read_message() {
                     Ok(msg) => {
+                        let begin = Instant::now();
+                        info!("new message");
                         let db_connection = db.get().expect("unable to get db connection");
                         match receive(db_connection, &rpc, msg, &mut websocket) {
-                            Ok(_r) => (),
-                            Err(e) => println!("{:?}", e),
+                            Ok(_r) => info!("response sent. total duration: {:?}", begin.elapsed()),
+                            Err(e) => info!("{:?}", e),
                         }
                     },
                     // connection is closed
                     Err(e) => {
-                        println!("{:?}", e);
+                        info!("{:?}", e);
                         return;
                     }
                 };

server/src/passives.rs

@@ -62,9 +62,9 @@ mod tests {
         let _graph = create_passive_graph();
         // good shit;
         // let nodes = graph.node_indices().collect::<Vec<NodeIndex>>();
-        // println!("{:?}", nodes[0]);
-        // println!("{:?}", graph.node_weight(nodes[0]));
+        // info!("{:?}", nodes[0]);
+        // info!("{:?}", graph.node_weight(nodes[0]));
 
-        // println!("{:?}", Dot::with_config(&graph, &[Config::EdgeNoLabel]));
+        // info!("{:?}", Dot::with_config(&graph, &[Config::EdgeNoLabel]));
     }
 }

server/src/player.rs

@@ -98,7 +98,7 @@ impl Player {
                 self.vbox_apply(s, cryp_id).expect("could not apply");
                 continue;
             }
-            println!("no skills available...");
+            info!("no skills available...");
         }
 
         // now keep buying and applying items cause whynot
@@ -135,7 +135,7 @@ impl Player {
 
             if self.vbox.bound.len() < 3 || num_colours < 2 {
                 if (needs_skills && self.vbox.bits < 4) || self.vbox.bits < 5 {
-                    // println!("insufficient balance");
+                    // info!("insufficient balance");
                     break;
                 }
 
@@ -148,7 +148,7 @@ impl Player {
                 self.vbox_accept(group_i, 0).expect("could't accept group 0");
             }
 
-            // println!("{:?}", self.vbox.bound);
+            // info!("{:?}", self.vbox.bound);
 
             let skills = [Var::Attack, Var::Block, Var::Buff, Var::Debuff, Var::Stun];
             let combo_i = match group_i {
@@ -277,7 +277,7 @@ impl Player {
             .filter(|c| !c.is_ko())
             .filter(|c| c.available_skills().len() > 0)
             .collect::<Vec<&Cryp>>().len();
-        // println!("{:} requires {:} skills this turn", self.id, required);
+        // info!("{:} requires {:} skills this turn", self.id, required);
         return required;
     }
 
@@ -336,7 +336,7 @@ pub fn player_create(tx: &mut Transaction, player: Player, instance: Uuid, accou
 
     let _returned = result.iter().next().expect("no row written");
 
-    println!("wrote player {:} joined instance: {:}", account.name, instance);
+    info!("wrote player {:} joined instance: {:}", account.name, instance);
 
     return Ok(player);
 }
@@ -376,7 +376,7 @@ pub fn player_delete(tx: &mut Transaction, id: Uuid) -> Result<(), Error> {
         return Err(format_err!("unable to delete player {:?}", id));
     }
 
-    println!("player deleted {:?}", id);
+    info!("player deleted {:?}", id);
 
     return Ok(());
 }

server/src/rpc.rs

@@ -35,6 +35,7 @@ impl Rpc {
         // cast the msg to this type to receive method name
         match from_slice::<RpcMessage>(&data) {
             Ok(v) => {
+                info!("message method: {:?}", v.method);
                 let mut tx = db.transaction()?;
 
                 let account: Option<Account> = match v.token {
@@ -96,7 +97,7 @@ impl Rpc {
                 return response;
             },
             Err(e) => {
-                println!("{:?}", e);
+                info!("{:?}", e);
                 Err(err_msg("unknown error"))
             },
         }

server/src/skill.rs

@@ -467,7 +467,7 @@ impl Effect {
             },
 
             _ => {
-                println!("{:?} does not have a mod effect", self);
+                info!("{:?} does not have a mod effect", self);
                 return value;
             },
         }
@@ -728,7 +728,7 @@ impl Skill {
             Skill::Siphon => 2,
 
             _ => {
-                println!("{:?} does not have a duration", self);
+                info!("{:?} does not have a duration", self);
                 return 1;
             },
         }
@@ -741,7 +741,7 @@ impl Skill {
             Skill::Throw => 3, // Inc dmg taken debuff
 
             _ => {
-                println!("{:?} does not have a secondary duration", self);
+                info!("{:?} does not have a secondary duration", self);
                 return 1;
             },
         }

server/src/util.rs

@@ -7,13 +7,13 @@ use failure::Error;
 pub fn startup(db: Db) -> Result<(), Error> {
     let mut tx = db.transaction()?;
 
-    println!("running startup fns");
+    info!("running startup fns");
 
     // game_global_startup(&mut tx)?;
 
     match tx.commit() {
         Ok(_) => {
-            println!("startup processes completed");
+            info!("startup processes completed");
             Ok(())
         },
         Err(e) => Err(format_err!("failed to commit startup tx {:?}", e)),

server/src/vbox.rs

@@ -560,7 +560,7 @@ impl Vbox {
         self.bound.get(i).ok_or(format_err!("no var at index {:?}", i))?;
         let reclaimed = self.bound.remove(i);
         let refund = reclaimed.cost();
-        // println!("reclaiming {:?} for {:?}", refund, reclaimed);
+        // info!("reclaiming {:?} for {:?}", refund, reclaimed);
         self.balance_add(refund);
         Ok(self)
     }
@@ -677,6 +677,6 @@ mod tests {
 
     // #[test]
     // fn vbox_info_test() {
-    //     println!("{:#?}", vbox_info());
+    //     info!("{:#?}", vbox_info());
     // }
 }

server/src/warden.rs

@@ -15,7 +15,7 @@ fn fetch_games(mut tx: Transaction) -> Result<Transaction, Error> {
         match game_update(&mut tx, &game) {
             Ok(_) => (),
             Err(e) =>  {
-                println!("{:?}", e);
+                info!("{:?}", e);
                 game_delete(&mut tx, game.id)?;
             }
         }

server/src/zone.rs

@@ -81,7 +81,7 @@ pub fn zone_delete(tx: &mut Transaction, id: Uuid) -> Result<(), Error> {
         return Err(format_err!("unable to delete zone {:?}", id));
     }
 
-    println!("zone deleted {:?}", id);
+    info!("zone deleted {:?}", id);
 
     return Ok(());
 }
@@ -402,10 +402,10 @@ mod tests {
         let _graph = create_zone_graph();
         // good shit;
         // let nodes = graph.node_indices().collect::<Vec<NodeIndex>>();
-        // println!("{:?}", nodes[0]);
-        // println!("{:?}", graph.node_weight(nodes[0]));
+        // info!("{:?}", nodes[0]);
+        // info!("{:?}", graph.node_weight(nodes[0]));
 
-        // println!("{:?}", Dot::with_config(&graph, &[Config::EdgeNoLabel]));
+        // info!("{:?}", Dot::with_config(&graph, &[Config::EdgeNoLabel]));
     }
 
     #[test]