Added logging and timing

gemla/Cargo.toml

@@ -22,4 +22,6 @@ regex = "1"
 file_linked = { version = "0.1.0", path = "../file_linked" }
 thiserror = "1.0"
 anyhow = "1.0"
-rand = "0.8.4"
+rand = "0.8.4"
+log = "0.4.14"
+env_logger = "0.9.0"

gemla/src/bin/bin.rs

@@ -1,13 +1,17 @@
 #[macro_use]
 extern crate clap;
 extern crate gemla;
+#[macro_use]
+extern crate log;
 
 mod test_state;
 
 use clap::App;
 use gemla::core::{Gemla, GemlaConfig};
+use gemla::error::log_error;
 use std::path::PathBuf;
 use test_state::TestState;
+use std::time::Instant;
 // use std::io::Write;
 
 /// Runs a simluation of a genetic algorithm against a dataset.
@@ -15,6 +19,11 @@ use test_state::TestState;
 /// Use the -h, --h, or --help flag to see usage syntax.
 /// TODO
 fn main() -> anyhow::Result<()> {
+    env_logger::init();
+    info!("Starting");
+    
+    let now = Instant::now();
+
     // Command line arguments are parsed with the clap crate. And this program uses
     // the yaml method with clap.
     let yaml = load_yaml!("../../cli.yml");
@@ -22,18 +31,20 @@ fn main() -> anyhow::Result<()> {
 
     // Checking that the first argument <DIRECTORY> is a valid directory
     let file_path = matches.value_of(gemla::constants::args::FILE).unwrap();
-    let mut gemla = Gemla::<TestState>::new(
+    let mut gemla = log_error(Gemla::<TestState>::new(
         &PathBuf::from(file_path),
         GemlaConfig {
             generations_per_node: 10,
             overwrite: true,
         },
-    )?;
+    ))?;
 
-    gemla.simulate(10)?;
+    log_error(gemla.simulate(10))?;
 
     // let mut f = std::fs::File::create("./test")?;
     // write!(f, "{}", serde_json::to_string(&gemla.data.readonly().0)?)?;
 
+    info!("Finished in {:?}", now.elapsed());
+
     Ok(())
 }

gemla/src/core/genetic_node.rs

@@ -12,7 +12,6 @@ use std::fmt::Debug;
 ///
 /// [`GeneticNode`]: crate::bracket::genetic_node
 #[derive(Debug, Serialize, Deserialize, PartialEq, Clone, Copy)]
-#[serde(tag = "enumType", content = "enumContent")]
 pub enum GeneticState {
     /// The node and it's data have not finished initializing
     Initialize,

gemla/src/core/mod.rs

@@ -10,11 +10,13 @@ use file_linked::FileLinked;
 use genetic_node::{GeneticNode, GeneticNodeWrapper, GeneticState};
 use serde::de::DeserializeOwned;
 use serde::{Deserialize, Serialize};
+use log::{info, trace};
 use std::fmt::Debug;
 use std::fs::File;
 use std::io::ErrorKind;
 use std::mem::swap;
 use std::path::Path;
+use std::time::Instant;
 
 type SimulationTree<T> = Tree<GeneticNodeWrapper<T>>;
 
@@ -65,9 +67,13 @@ where
         self.data
             .mutate(|(d, c)| Gemla::increase_height(d, c, steps))??;
 
+        info!("Height of simulation tree increased to {}", self.data.readonly().0.as_ref().unwrap().height());
+
         self.data
             .mutate(|(d, _c)| Gemla::process_tree(d.as_mut().unwrap()))??;
 
+        info!("Processed tree");
+
         Ok(())
     }
 
@@ -130,12 +136,21 @@ where
     }
 
     fn process_node(node: &mut GeneticNodeWrapper<T>) -> Result<(), Error> {
+        let node_time = Instant::now();
+
         loop {
+            let node_state_time = Instant::now();
+            let node_state = node.state().clone();
+
             if node.process_node()? == GeneticState::Finish {
                 break;
             }
+
+            trace!("{:?} completed in {:?}", node_state, node_state_time.elapsed());
         }
 
+        info!("Processed node in {:?}", node_time.elapsed());
+
         Ok(())
     }
 }

gemla/src/error.rs

@@ -1,4 +1,5 @@
 use thiserror::Error;
+use log::error;
 
 #[derive(Error, Debug)]
 pub enum Error {
@@ -24,3 +25,11 @@ impl From<std::io::Error> for Error {
         Error::IO(error)
     }
 }
+
+pub fn log_error<T>(result: Result<T, Error>) -> Result<T, Error> {
+    result.map_err(|e| {
+        error!("{}", e);
+        e
+    })
+}
+

gemla/src/lib.rs

@@ -1,6 +1,3 @@
-extern crate file_linked;
-extern crate regex;
-
 #[macro_use]
 pub mod tree;
 pub mod constants;