Use logging instead of dbg! (#90)

* Replace calls to dbg! with log::debug! + env_logger

We can use the RUST_LOG environment variable to control the
log level.

* Add env_logger as optional dependency

* Revert to dbg! for tests

* Don't use env_logger for wasm

* Change cli logging format

---------

Co-authored-by: Jesse Farmer <[email protected]>

Cargo.toml

@@ -23,6 +23,9 @@ ron = "0.8"
 log = "0.4"
 rust-i18n = "3.1.2"
 
+[target.'cfg(not(target_arch = "wasm32"))'.dependencies]
+env_logger = "0.11.5"
+
 [target.'cfg(target_arch = "wasm32")'.dependencies]
 wasm-bindgen-futures = "0.4"
 console_error_panic_hook = "0.1.7"

raphael-cli/Cargo.toml

@@ -11,3 +11,6 @@ solvers = { path = "../solvers" }
 game-data = { path = "../game_data" }
 
 clap = { version = "4.4.11", features = ["derive", "wrap_help"] }
+
+log = "0.4"
+env_logger = "0.11.5"

raphael-cli/src/main.rs

@@ -53,6 +53,11 @@ struct Args {
 }
 
 fn main() {
+    env_logger::builder()
+        .format_timestamp(None)
+        .format_target(false)
+        .init();
+
     let args = Args::parse();
 
     let recipe = RECIPES

simulator/Cargo.toml

@@ -2,8 +2,6 @@
 name = "simulator"
 edition = "2021"
 
-# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html
-
 [lib]
 crate-type = ["rlib"]
 
@@ -14,3 +12,4 @@ rand = "0.8.5"
 [dependencies]
 bitfield-struct = "0.8.0"
 serde = { version = "1.0.203", features = ["derive"] }
+log = "0.4"

simulator/tests/adversarial_tests.rs

@@ -1,5 +1,4 @@
 use simulator::{Action, ActionMask, Condition, Settings, SimulationState};
-
 const SETTINGS: Settings = Settings {
     max_cp: 1000,
     max_durability: 80,

solvers/Cargo.toml

@@ -12,6 +12,11 @@ simulator = { path = "../simulator" }
 radix-heap = "0.4.2"
 rustc-hash = "1.1.0"
 bitfield-struct = "0.8.0"
+log = "0.4"
+env_logger = { version = "0.11.5", optional = true }
+
+[features]
+env_logger = ["dep:env_logger"]
 
 [dev-dependencies]
 rand = "0.8.5"

solvers/examples/macro_solver_example.rs

@@ -2,8 +2,17 @@ use simulator::{Action, ActionMask, Settings, SimulationState};
 use solvers::MacroSolver;
 
 fn main() {
-    dbg!(std::mem::size_of::<SimulationState>());
-    dbg!(std::mem::align_of::<SimulationState>());
+    #[cfg(feature = "env_logger")]
+    env_logger::builder()
+        .format_timestamp(None)
+        .format_target(false)
+        .init();
+
+    log::trace!(
+        "SimulationState - size: {}, align: {}",
+        std::mem::size_of::<SimulationState>(),
+        std::mem::align_of::<SimulationState>()
+    );
 
     // Ra'Kaznar Lapidary Hammer
     // 4462 Craftsmanship, 4391 Control
@@ -32,5 +41,11 @@ fn main() {
         .quality;
     let steps = actions.len();
     let duration: i16 = actions.iter().map(|action| action.time_cost()).sum();
-    dbg!(quality, steps, duration);
+
+    log::info!(
+        "Solution - quality: {}, steps: {}, duration: {}",
+        quality,
+        steps,
+        duration
+    );
 }

solvers/src/finish_solver.rs

@@ -53,8 +53,11 @@ pub struct FinishSolver {
 
 impl FinishSolver {
     pub fn new(settings: Settings) -> FinishSolver {
-        dbg!(std::mem::size_of::<ReducedState>());
-        dbg!(std::mem::align_of::<ReducedState>());
+        log::trace!(
+            "ReducedState (FinishSolver) - size: {}, align: {}",
+            std::mem::size_of::<ReducedState>(),
+            std::mem::align_of::<ReducedState>()
+        );
         FinishSolver {
             settings,
             max_progress: HashMap::default(),
@@ -105,6 +108,6 @@ impl FinishSolver {
 
 impl Drop for FinishSolver {
     fn drop(&mut self) {
-        dbg!(self.max_progress.len());
+        log::debug!("FinishSolver - states: {}", self.max_progress.len());
     }
 }

solvers/src/macro_solver/fast_lower_bound.rs

@@ -61,7 +61,7 @@ pub fn fast_lower_bound(
         }
     }
 
-    dbg!(quality_lower_bound);
+    log::debug!("Fast quality lower bound: {}", quality_lower_bound);
     std::cmp::min(settings.max_quality, quality_lower_bound)
 }
 

solvers/src/macro_solver/pareto_front/effect_pareto_front.rs

@@ -93,6 +93,10 @@ impl EffectParetoFront {
 impl Drop for EffectParetoFront {
     fn drop(&mut self) {
         let pareto_entries: usize = self.buckets.values().map(|value| value.len()).sum();
-        dbg!(self.buckets.len(), pareto_entries);
+        log::debug!(
+            "EffectParetoFront - buckets: {}, entries: {}",
+            self.buckets.len(),
+            pareto_entries
+        );
     }
 }

solvers/src/macro_solver/pareto_front/quality_pareto_front.rs

@@ -69,6 +69,10 @@ impl QualityParetoFront {
 impl Drop for QualityParetoFront {
     fn drop(&mut self) {
         let pareto_entries: usize = self.buckets.values().map(|value| value.len()).sum();
-        dbg!(self.buckets.len(), pareto_entries);
+        log::debug!(
+            "QualityParetoFront - buckets: {}, entries: {}",
+            self.buckets.len(),
+            pareto_entries
+        );
     }
 }

solvers/src/macro_solver/search_queue.rs

@@ -84,7 +84,8 @@ impl SearchQueue {
             }
             dropped += self.buckets.pop_first().unwrap().1.len();
         }
-        dbg!(self.minimum_score, dropped);
+        log::debug!("New minimum score: {:?}", score);
+        log::debug!("Nodes dropped: {}", dropped);
     }
 
     pub fn push(

solvers/src/macro_solver/solver.rs

@@ -194,7 +194,7 @@ impl<'a> MacroSolver<'a> {
         }
 
         if let Some(solution) = solution {
-            dbg!(&solution.actions);
+            log::trace!("Solution actions: {:?}", &solution.actions);
             Some(solution.actions)
         } else {
             None

solvers/src/quality_upper_bound_solver/solver.rs

@@ -36,8 +36,11 @@ pub struct QualityUpperBoundSolver {
 
 impl QualityUpperBoundSolver {
     pub fn new(settings: Settings, backload_progress: bool, unsound_branch_pruning: bool) -> Self {
-        dbg!(std::mem::size_of::<ReducedState>());
-        dbg!(std::mem::align_of::<ReducedState>());
+        log::trace!(
+            "ReducedState (QualityUpperBoundSolver) - size: {}, align: {}",
+            std::mem::size_of::<ReducedState>(),
+            std::mem::align_of::<ReducedState>()
+        );
 
         let initial_state = SimulationState::new(&settings);
         let mut durability_cost = 100;
@@ -235,10 +238,7 @@ mod tests {
 
     fn solve(settings: Settings, actions: &[Action]) -> u16 {
         let state = SimulationState::from_macro(&settings, actions).unwrap();
-        let result =
-            QualityUpperBoundSolver::new(settings, false, false).quality_upper_bound(state);
-        dbg!(result);
-        result
+        QualityUpperBoundSolver::new(settings, false, false).quality_upper_bound(state)
     }
 
     #[test]

solvers/src/step_lower_bound_solver/solver.rs

@@ -32,8 +32,11 @@ impl StepLowerBoundSolver {
         backload_progress: bool,
         unsound_branch_pruning: bool,
     ) -> Self {
-        dbg!(std::mem::size_of::<ReducedState>());
-        dbg!(std::mem::align_of::<ReducedState>());
+        log::trace!(
+            "ReducedState (StepLowerBoundSolver) - size: {}, align: {}",
+            std::mem::size_of::<ReducedState>(),
+            std::mem::align_of::<ReducedState>()
+        );
         let mut bonus_durability_restore = 0;
         if settings.is_action_allowed::<ImmaculateMend>() {
             bonus_durability_restore =
@@ -216,9 +219,7 @@ mod tests {
 
     fn solve(settings: Settings, actions: &[Action]) -> u8 {
         let state = SimulationState::from_macro(&settings, actions).unwrap();
-        let result = StepLowerBoundSolver::new(settings, false, false).step_lower_bound(state);
-        dbg!(result);
-        result
+        StepLowerBoundSolver::new(settings, false, false).step_lower_bound(state)
     }
 
     #[test]

solvers/src/utils/mod.rs

@@ -19,14 +19,14 @@ impl NamedTimer {
 
 impl Drop for NamedTimer {
     fn drop(&mut self) {
-        #[cfg(target_arch = "wasm32")]
-        eprintln!("{}: (timer not available on WASM)", self.name);
         #[cfg(not(target_arch = "wasm32"))]
-        eprintln!(
-            "{}: {} seconds",
+        log::info!(
+            "Timer \"{}\" elapsed: {} seconds",
             self.name,
             self.timer.elapsed().as_secs_f32()
         );
+        #[cfg(target_arch = "wasm32")]
+        log::info!("Timer \"{}\" elapsed", self.name);
     }
 }
 
@@ -87,6 +87,6 @@ impl<T: Copy> Backtracking<T> {
 
 impl<T: Copy> Drop for Backtracking<T> {
     fn drop(&mut self) {
-        dbg!(self.entries.len());
+        log::debug!("Backtracking - nodes: {}", self.entries.len());
     }
 }

solvers/src/utils/pareto_front_builder.rs

@@ -252,7 +252,8 @@ where
     U: Copy + std::cmp::Ord + std::default::Default,
 {
     fn drop(&mut self) {
-        dbg!(
+        log::debug!(
+            "ParetoFrontBuilder - buffer_size: {}, fronts_generated: {}, storage_size: {}",
             self.buffer.capacity(),
             self.fronts_generated,
             self.storage.len()

src/app.rs

@@ -5,6 +5,8 @@ use std::time::Duration;
 
 use serde::{de::DeserializeOwned, Deserialize, Serialize};
 
+use log::debug;
+
 #[cfg(not(target_arch = "wasm32"))]
 use std::time::Instant;
 #[cfg(target_arch = "wasm32")]
@@ -375,14 +377,14 @@ impl MacroSolverApp {
                     self.solver_progress = progress;
                 }
                 SolverEvent::IntermediateSolution(_) | SolverEvent::FinalSolution(_) => {
-                    dbg!(update);
+                    debug!("Unexpected progress update: {:?}", update);
                 }
             }
         }
         if let Some(update) = self.data_update.solution_update.take() {
             match update {
                 SolverEvent::Progress(_) => {
-                    dbg!(update);
+                    debug!("Unexpected solution update: {:?}", update);
                 }
                 SolverEvent::IntermediateSolution(actions) => {
                     self.actions = actions;

src/main.rs

@@ -1,5 +1,10 @@
 #[cfg(not(target_arch = "wasm32"))]
 fn main() -> eframe::Result<()> {
+    env_logger::builder()
+        .format_timestamp(None)
+        .format_target(false)
+        .init();
+
     let native_options = eframe::NativeOptions {
         viewport: egui::ViewportBuilder::default()
             .with_inner_size([400.0, 300.0])