feat: Add logging for branchers

pumpkin-solver/src/api/outputs/solution_callback_arguments.rs

@@ -1,31 +1,49 @@
+use std::fmt::Debug;
+
+use crate::branching::Brancher;
 use crate::results::Solution;
+use crate::statistics::StatisticLogger;
 use crate::Solver;
 
 /// The input which is passed to the solution callback (which can be set using
 /// [`Solver::with_solution_callback`]).
 ///
 /// Provides direct access to the solution via [`SolutionCallbackArguments::solution`] and allows
 /// logging the statistics of the [`Solver`] using [`SolutionCallbackArguments::log_statistics`].
-#[derive(Debug)]
 pub struct SolutionCallbackArguments<'a, 'b> {
     /// The solver which found the solution
     solver: &'a Solver,
     /// The solution which has been found
     pub solution: &'b Solution,
     /// The (optional) objective value provided to the [`Solver`].
     objective_value: Option<i64>,
+    /// The brancher that was used to find the solution
+    brancher: &'a mut dyn Brancher,
+}
+
+impl Debug for SolutionCallbackArguments<'_, '_> {
+    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+        f.debug_struct("SolutionCallbackArguments")
+            .field("solver", self.solver)
+            .field("solution", self.solution)
+            .field("objective_value", &self.objective_value)
+            .field("brancher", &"brancher")
+            .finish()
+    }
 }
 
 impl<'a, 'b> SolutionCallbackArguments<'a, 'b> {
     pub(crate) fn new(
         solver: &'a Solver,
         solution: &'b Solution,
         objective_value: Option<i64>,
+        brancher: &'a mut dyn Brancher,
     ) -> Self {
         Self {
             solver,
             solution,
             objective_value,
+            brancher,
         }
     }
 
@@ -34,6 +52,7 @@ impl<'a, 'b> SolutionCallbackArguments<'a, 'b> {
     /// If the solution was found using [`Solver::minimise`] or [`Solver::maximise`] then the
     /// objective value of the current solution is included in the statistics.
     pub fn log_statistics(&self) {
+        self.brancher.log_statistics(StatisticLogger::default());
         if let Some(objective_value) = self.objective_value {
             self.solver.log_statistics_with_objective(objective_value)
         } else {

pumpkin-solver/src/api/solver.rs

@@ -592,6 +592,7 @@ impl Solver {
             self,
             solution,
             objective_value,
+            brancher,
         ));
     }
 

pumpkin-solver/src/bin/pumpkin-solver/flatzinc/mod.rs

@@ -12,6 +12,7 @@ use std::time::Duration;
 use pumpkin_solver::branching::branchers::alternating_brancher::AlternatingBrancher;
 use pumpkin_solver::branching::branchers::alternating_brancher::AlternatingStrategy;
 use pumpkin_solver::branching::branchers::dynamic_brancher::DynamicBrancher;
+use pumpkin_solver::branching::Brancher;
 #[cfg(doc)]
 use pumpkin_solver::constraints::cumulative;
 use pumpkin_solver::options::CumulativeOptions;
@@ -20,6 +21,7 @@ use pumpkin_solver::results::OptimisationResult;
 use pumpkin_solver::results::ProblemSolution;
 use pumpkin_solver::results::SatisfactionResult;
 use pumpkin_solver::results::Solution;
+use pumpkin_solver::statistics::StatisticLogger;
 use pumpkin_solver::termination::Combinator;
 use pumpkin_solver::termination::OsSignal;
 use pumpkin_solver::termination::TimeBudget;
@@ -95,6 +97,7 @@ pub(crate) fn solve(
                 let optimal_objective_value =
                     optimal_solution.get_integer_value(*objective_function.get_domain());
                 if !options.all_solutions {
+                    brancher.log_statistics(StatisticLogger::default());
                     solver.log_statistics();
                     print_solution_from_solver(&optimal_solution, &instance.outputs)
                 }
@@ -150,6 +153,7 @@ pub(crate) fn solve(
         None
     };
 
+    brancher.log_statistics(StatisticLogger::default());
     if let Some(value) = value {
         solver.log_statistics_with_objective(value as i64)
     } else {

pumpkin-solver/src/branching/brancher.rs

@@ -8,11 +8,14 @@ use crate::branching::value_selection::ValueSelector;
 #[cfg(doc)]
 use crate::branching::variable_selection::VariableSelector;
 use crate::branching::SelectionContext;
+#[cfg(doc)]
+use crate::create_statistics_struct;
 use crate::engine::predicates::predicate::Predicate;
 use crate::engine::variables::DomainId;
 use crate::engine::Assignments;
 #[cfg(doc)]
 use crate::results::solution_iterator::SolutionIterator;
+use crate::statistics::StatisticLogger;
 #[cfg(doc)]
 use crate::Solver;
 
@@ -28,6 +31,11 @@ use crate::Solver;
 /// If the [`Brancher`] (or any component thereof) is implemented incorrectly then the
 /// behaviour of the solver is undefined.
 pub trait Brancher {
+    /// Logs statistics of the brancher using the provided [`StatisticLogger`].
+    ///
+    /// It is recommended to create a struct through the [`create_statistics_struct!`] macro!
+    fn log_statistics(&self, _statistic_logger: StatisticLogger) {}
+
     /// Returns the next decision concerning a single variable and value; it returns the
     /// [`Predicate`] corresponding to this decision (or [`None`] if all variables under
     /// consideration are assigned).

pumpkin-solver/src/branching/branchers/alternating_brancher.rs

@@ -7,6 +7,7 @@ use crate::branching::SelectionContext;
 use crate::engine::predicates::predicate::Predicate;
 use crate::engine::variables::DomainId;
 use crate::engine::Assignments;
+use crate::statistics::StatisticLogger;
 use crate::DefaultBrancher;
 use crate::Solver;
 
@@ -109,6 +110,12 @@ impl<OtherBrancher: Brancher> Brancher for AlternatingBrancher<OtherBrancher> {
         }
     }
 
+    fn log_statistics(&self, statistic_logger: StatisticLogger) {
+        self.default_brancher
+            .log_statistics(statistic_logger.clone());
+        self.other_brancher.log_statistics(statistic_logger);
+    }
+
     fn on_appearance_in_conflict_predicate(&mut self, predicate: Predicate) {
         self.default_brancher
             .on_appearance_in_conflict_predicate(predicate);

pumpkin-solver/src/branching/branchers/autonomous_search.rs

@@ -1,4 +1,6 @@
 use super::independent_variable_value_brancher::IndependentVariableValueBrancher;
+use crate::basic_types::moving_averages::CumulativeMovingAverage;
+use crate::basic_types::moving_averages::MovingAverage;
 use crate::basic_types::PredicateId;
 use crate::basic_types::PredicateIdGenerator;
 use crate::basic_types::SolutionReference;
@@ -8,9 +10,12 @@ use crate::branching::Brancher;
 use crate::branching::SelectionContext;
 use crate::containers::KeyValueHeap;
 use crate::containers::StorageKey;
+use crate::create_statistics_struct;
 use crate::engine::predicates::predicate::Predicate;
 use crate::engine::Assignments;
 use crate::results::Solution;
+use crate::statistics::Statistic;
+use crate::statistics::StatisticLogger;
 use crate::DefaultBrancher;
 /// A [`Brancher`] that combines [VSIDS \[1\]](https://dl.acm.org/doi/pdf/10.1145/378239.379017)
 /// and [Solution-based phase saving \[2\]](https://people.eng.unimelb.edu.au/pstuckey/papers/lns-restarts.pdf).
@@ -54,7 +59,6 @@ use crate::DefaultBrancher;
 /// value-selection heuristic to simulate local search behavior in complete solvers’, in the
 /// proceedings of the Principles and Practice of Constraint Programming (CP 2018).
 #[derive(Debug)]
-
 pub struct AutonomousSearch<BackupBrancher> {
     /// Predicates are mapped to ids. This is used internally in the heap.
     predicate_id_info: PredicateIdGenerator,
@@ -81,8 +85,19 @@ pub struct AutonomousSearch<BackupBrancher> {
     /// If the heap does not contain any more unfixed predicates then this backup_brancher will be
     /// used instead.
     backup_brancher: BackupBrancher,
+
+    statistics: AutonomousSearchStatistics,
 }
 
+create_statistics_struct!(AutonomousSearchStatistics {
+    num_backup_called: usize,
+    num_predicates_removed: usize,
+    num_calls: usize,
+    num_predicates_added: usize,
+    average_size_of_heap: CumulativeMovingAverage<usize>,
+    num_assigned_predicates_encountered: usize,
+});
+
 const DEFAULT_VSIDS_INCREMENT: f64 = 1.0;
 const DEFAULT_VSIDS_MAX_THRESHOLD: f64 = 1e100;
 const DEFAULT_VSIDS_DECAY_FACTOR: f64 = 0.95;
@@ -109,6 +124,7 @@ impl DefaultBrancher {
                 Smallest::new(&variables),
                 InDomainMin,
             ),
+            statistics: Default::default(),
         }
     }
 }
@@ -129,6 +145,7 @@ impl<BackupSelector> AutonomousSearch<BackupSelector> {
             decay_factor: DEFAULT_VSIDS_DECAY_FACTOR,
             best_known_solution: None,
             backup_brancher,
+            statistics: Default::default(),
         }
     }
 
@@ -147,6 +164,8 @@ impl<BackupSelector> AutonomousSearch<BackupSelector> {
     /// Bumps the activity of a predicate by [`Vsids::increment`].
     /// Used when a predicate is encountered during a conflict.
     fn bump_activity(&mut self, predicate: Predicate) {
+        self.statistics.num_predicates_added +=
+            (!self.predicate_id_info.has_id_for_predicate(predicate)) as usize;
         let id = self.predicate_id_info.get_id(predicate);
         self.resize_heap(id);
 
@@ -168,6 +187,7 @@ impl<BackupSelector> AutonomousSearch<BackupSelector> {
                 if *self.heap.get_value(predicate_id) <= self.minimum_activity_threshold()
                     && predicate_id != id
                 {
+                    self.statistics.num_predicates_removed += 1;
                     self.heap.delete_key(predicate_id);
                     self.predicate_id_info.delete_id(predicate_id);
                 }
@@ -198,6 +218,7 @@ impl<BackupSelector> AutonomousSearch<BackupSelector> {
                     .get_predicate(*candidate)
                     .expect("We expected present predicates to be registered.");
                 if context.is_predicate_assigned(predicate) {
+                    self.statistics.num_assigned_predicates_encountered += 1;
                     let _ = self.heap.pop_max();
 
                     // We know that this predicate is now dormant
@@ -243,17 +264,27 @@ impl<BackupSelector> AutonomousSearch<BackupSelector> {
 
 impl<BackupBrancher: Brancher> Brancher for AutonomousSearch<BackupBrancher> {
     fn next_decision(&mut self, context: &mut SelectionContext) -> Option<Predicate> {
+        self.statistics.num_calls += 1;
+        self.statistics
+            .average_size_of_heap
+            .add_term(self.heap.num_nonremoved_elements());
         let result = self
             .next_candidate_predicate(context)
             .map(|predicate| self.determine_polarity(predicate));
         if result.is_none() && !context.are_all_variables_assigned() {
             // There are variables for which we do not have a predicate, rely on the backup
+            self.statistics.num_backup_called += 1;
             self.backup_brancher.next_decision(context)
         } else {
             result
         }
     }
 
+    fn log_statistics(&self, statistic_logger: StatisticLogger) {
+        let statistic_logger = statistic_logger.attach_to_prefix("AutonomousSearch");
+        self.statistics.log(statistic_logger);
+    }
+
     fn on_backtrack(&mut self) {
         self.backup_brancher.on_backtrack()
     }

pumpkin-solver/src/branching/branchers/dynamic_brancher.rs

@@ -12,6 +12,7 @@ use crate::branching::SelectionContext;
 use crate::engine::predicates::predicate::Predicate;
 use crate::engine::variables::DomainId;
 use crate::engine::Assignments;
+use crate::statistics::StatisticLogger;
 
 /// An implementation of a [`Brancher`] which takes a [`Vec`] of `Box<dyn Brancher>` and
 /// sequentially applies [`Brancher::next_decision`] until all of them return [`None`].
@@ -66,6 +67,15 @@ impl Brancher for DynamicBrancher {
         }
     }
 
+    fn log_statistics(&self, statistic_logger: StatisticLogger) {
+        self.branchers
+            .iter()
+            .enumerate()
+            .for_each(move |(index, brancher)| {
+                brancher.log_statistics(statistic_logger.attach_to_prefix(index))
+            })
+    }
+
     fn on_conflict(&mut self) {
         // A conflict has occurred, we do not know which brancher now can select a variable, reset
         // to the first one

pumpkin-solver/src/statistics/statistic_logger.rs

@@ -8,7 +8,7 @@ use crate::engine::propagation::Propagator;
 
 /// Responsible for logging the statistics with the provided prefix; currently used when logging
 /// the statistics of propagators.
-#[derive(Debug, Default)]
+#[derive(Debug, Default, Clone)]
 pub struct StatisticLogger {
     /// The prefix which will be attached to the statistic name
     name_prefix: String,