From e3acafbbe94f21aec83478d9c21ca08874d6156a Mon Sep 17 00:00:00 2001
From: VIGNET Pierre <pierre.vignet@irisa.fr>
Date: Wed, 4 Dec 2019 02:43:07 +0100
Subject: [PATCH] [lib] Adjust logging, prepare for the switch INFO -> DEBUG

---
 .../clause_constraints/mcl/CLUnfolder.py      | 11 +++--
 .../clause_constraints/mcl/MCLAnalyser.py     | 42 +++++++++++++++----
 2 files changed, 38 insertions(+), 15 deletions(-)

diff --git a/library/cadbiom/models/clause_constraints/mcl/CLUnfolder.py b/library/cadbiom/models/clause_constraints/mcl/CLUnfolder.py
index a031c04..47b7dd9 100644
--- a/library/cadbiom/models/clause_constraints/mcl/CLUnfolder.py
+++ b/library/cadbiom/models/clause_constraints/mcl/CLUnfolder.py
@@ -832,7 +832,7 @@ class CLUnfolder(object):
                 self.__precomputed_dynamic_constraints[self.__current_step]
             )
             LOGGER.info(
-                "__shift_dynamic:: OPTI-DO NOT SHIFT; "
+                "shift_dynamic:: OPTI DO NOT SHIFT; "
                 "Reload dynamic constraints; step: %s",
                 self.__current_step
             )
@@ -840,7 +840,7 @@ class CLUnfolder(object):
 
         # System has not been shifted for this step until now
         LOGGER.info(
-                "__shift_dynamic:: SHIFT; "
+                "shift_dynamic:: SHIFT; "
                 "Set dynamic constraints; step: %s; dyn consts len: %s",
                 self.__current_step,
                 len(self.__dynamic_constraints)
@@ -1340,7 +1340,6 @@ class CLUnfolder(object):
         solv.add_clauses(it.chain(*self.__dynamic_constraints))
         solv.add_clauses(self.__initial_constraints)
 
-        # LOGGING
         if LOGGER.getEffectiveLevel() == DEBUG:
             # final
             LOGGER.debug("Load new solver !!")
@@ -1476,7 +1475,7 @@ class CLUnfolder(object):
             # Auto shift loop: Shift without checking (optimization)
             # Do not search solutions before the specified limit
             while self.__current_step < self.__steps_before_check:
-                print("SATIS TEST AUTO SHIFT opti")
+                LOGGER.info("Satis test:: OPTI AUTO SHIFT")
                 self.shift()
 
             satisfiability_test = False
@@ -1487,7 +1486,7 @@ class CLUnfolder(object):
 
                 # Test satisfiability
                 satisfiability_test = self.__constraints_satisfied()
-                print("SATIS TEST done, current_step", self.__current_step)
+                LOGGER.info("Satis test:: done, current_step %s", self.__current_step)
 
                 if satisfiability_test:
                     return True
@@ -1552,7 +1551,7 @@ class CLUnfolder(object):
             # Do not search solutions before the specified limit
             print("squery_solve: begining; current_step:", self.__current_step, "max_step:", max_step)
             while self.__current_step < self.__steps_before_check:
-                print("AUTO SHIFT opti")
+                LOGGER.info("Solve: OPTI AUTO SHIFT")
                 self.shift()
 
             # Search for solutions for each remaining step
diff --git a/library/cadbiom/models/clause_constraints/mcl/MCLAnalyser.py b/library/cadbiom/models/clause_constraints/mcl/MCLAnalyser.py
index 04ddf45..48eec00 100644
--- a/library/cadbiom/models/clause_constraints/mcl/MCLAnalyser.py
+++ b/library/cadbiom/models/clause_constraints/mcl/MCLAnalyser.py
@@ -199,8 +199,11 @@ from cadbiom.models.guard_transitions.translators.cadlangParser import cadlangPa
 from cadbiom.models.guard_transitions.chart_model import ChartModel
 from cadbiom.models.clause_constraints.mcl.MCLSolutions import FrontierSolution, DimacsFrontierSol
 from cadbiom.models.clause_constraints.mcl.MCLQuery import MCLSimpleQuery
-
 from cadbiom import commons as cm
+
+# Standard imports
+from logging import DEBUG, INFO
+
 LOGGER = cm.logger()
 
 
@@ -427,7 +430,12 @@ class MCLAnalyser(object):
                     max_step,
                     self.nb_sols_to_be_pruned
                 )
-            print("iteration", i, "nb pruned inact solutions", len(dimacs_solutions))
+
+            LOGGER.info(
+                "MCLA::Prune: Iteration %s, nb pruned inact solutions: %s",
+                i,
+                len(dimacs_solutions)
+            )
             ####TODO: regarder si ces solutions sont si différentes et ce qu'on en fait au final...
             ### en fin de compte il est possible que le solveur ne soit pas si bete...
             ##TODO:  ajuster automatiquement nb_sols_to_be_pruned
@@ -443,12 +451,18 @@ class MCLAnalyser(object):
             next_sol = self.less_activated_solution(dimacs_solutions)
             next_len = next_sol.nb_activated_frontiers
             is_pruned = current_len > next_len
+
+            LOGGER.info(
+                "MCLA::Prune: Current solution activated length:%s next:%s",
+                current_len, next_len
+            )
+
             if is_pruned:
                 sol_to_prune = next_sol
                 current_len = next_len
 
         # never reach this point
-        raise MCLException("MCLAnalyser:__prune_frontier_solution:: what happened??")
+        raise MCLException("MCLAnalyser:__prune_frontier_solution:: what happened?")
 
     ## Generic solver for simple queries #######################################
 
@@ -618,8 +632,16 @@ class MCLAnalyser(object):
         raw_sols = self.sq_solutions(query, max_step, max_sol, vvars)
         # Get unique DimacsFrontierSol objects from RawSolution objects
         dimacfrontsol = DimacsFrontierSol.get_unique_dimacs_front_sols_from_raw_sols(raw_sols)
-        print("Nb activated in dimacsfrontsols", [len(sol) for sol in dimacfrontsol])
-        print("Nb queried:", max_sol, "steps", max_step, "obtenu", len(dimacfrontsol))
+
+        if LOGGER.getEffectiveLevel() == INFO:
+            LOGGER.info(
+                "MCLA: Nb queried: %s, steps: %s\n"
+                "\tget: %s, unique: %s\n"
+                "\tactivated fronts per dimacfrontsol: %s",
+                max_sol, max_step,
+                len(raw_sols), len(dimacfrontsol),
+                [len(sol) for sol in dimacfrontsol]
+            )
         return dimacfrontsol
 
 
@@ -700,7 +722,8 @@ class MCLAnalyser(object):
                 # If we do not want to self-adjust steps, just break the loop
                 # break
 
-                print("NOT FOUND - current step ?", self.unfolder.get_current_step())
+                LOGGER.info("MCLA: NOT FOUND -> satis test; current step %s",
+                            self.unfolder.get_current_step())
                 if self.unfolder.get_current_step() + 1 > max_user_step:
                     # Cosmetic break, avoid to do useless test
                     break
@@ -740,9 +763,6 @@ class MCLAnalyser(object):
             # => reduce the number of activated variables
             current_mac = self.__prune_frontier_solution(small_fsol, query, min_step)
 
-            ## TEST
-            print("__mac_exhaustive_search:: final current step ?", self.unfolder.get_current_step())
-
             yield current_mac
             # mac_list.append(current_mac)
 
@@ -752,6 +772,10 @@ class MCLAnalyser(object):
             forbidden_frontier_values.append(
                 [-var for var in current_mac.activated_frontier_values]
             )
+            LOGGER.debug(
+                "MCLA::mac_exhaustive_search: forbidden frontiers: %s",
+                forbidden_frontier_values
+            )
 
     def next_mac(self, query, max_step):
         """Search a Minimal Access Condition for the given query.
-- 
GitLab