Clean up logger and reduce the amount of debug messages printed

doc/index.rst

@@ -141,9 +141,12 @@ The following flags exist:
    * - ``disable_stiffness_check``
      - :python:`False`
      - Set to True to disable stiffness check.
+   * - ``disable_analytic_solver``
+     - :python:`False`
+     - Set to True to return numerical solver recommendations, and no propagators, even for ODEs that are analytically tractable.
    * - ``disable_singularity_detection``
      - :python:`False`
-     - Set to True to disable detection of conditions under which numerical singularities (division by zero) could occur.
+     - Set to True to disable detection of conditions under which numerical singularities (division by zero) could occur in the generated analytic solver. This can be useful for analytic solvers containing a large amount of conditions, which could take a long time to compute. If True, at most one analytic solver will be returned, in which numerical singularities could occur.
    * - ``use_alternative_expM``
      - :python:`False`
      - If :python:`False`, use the sympy function ``sympy.exp`` to compute the matrix exponential. If :python:`True`, use an alternative function (see :py:func:`odetoolbox.sympy_helpers.expMt` for details). This can be useful as calls to ``sympy.exp`` can sometimes take a very large amount of time.
@@ -372,6 +375,10 @@ The following global options are defined. Note that all are typically formatted
      - :python:`["oo", "zoo", "nan", "NaN", "__h"]`
      - list of strings
      - For each forbidden name: emit an error if a variable or parameter by this name occurs in the input.
+   * - ``use_alternative_expM``
+     - :python:`False`
+     - boolean
+     - If :python:`False`, use the sympy function ``sympy.exp`` to compute the matrix exponential. If :python:`True`, use an alternative function (see :py:func:`odetoolbox.sympy_helpers.expMt` for details). This can be useful as calls to ``sympy.exp`` can sometimes take a very large amount of time.
 
 
 Output

odetoolbox/__init__.py

@@ -36,15 +36,16 @@
     import pygsl.odeiv as odeiv
     PYGSL_AVAILABLE = True
 except ImportError as ie:
-    logging.warning("PyGSL is not available. The stiffness test will be skipped.")
-    logging.warning("Error when importing: " + str(ie))
+    logging.getLogger(__name__).warning("PyGSL is not available. The stiffness test will be skipped.")
+    logging.getLogger(__name__).warning("Error when importing: " + str(ie))
     PYGSL_AVAILABLE = False
 
 if PYGSL_AVAILABLE:
     from .stiffness import StiffnessTester
 
 try:
     import graphviz
+    logging.getLogger("graphviz").setLevel(logging.ERROR)
     PLOT_DEPENDENCY_GRAPH = True
 except ImportError:
     PLOT_DEPENDENCY_GRAPH = False
@@ -61,7 +62,7 @@ def _find_analytically_solvable_equations(shape_sys, shapes, parameters=None):
 
     Perform dependency analysis and plot dependency graph.
     """
-    logging.info("Finding analytically solvable equations...")
+    logging.getLogger(__name__).debug("Finding analytically solvable equations...")
     dependency_edges = shape_sys.get_dependency_edges()
 
     if PLOT_DEPENDENCY_GRAPH:
@@ -94,7 +95,7 @@ def _read_global_config(indict):
     r"""
     Process global configuration options.
     """
-    logging.info("Processing global options...")
+    logging.getLogger(__name__).debug("Processing global options...")
     if "options" in indict.keys():
         for key, value in indict["options"].items():
             assert key in Config.config.keys(), "Unknown key specified in global options dictionary: \"" + str(key) + "\""
@@ -108,12 +109,13 @@ def _from_json_to_shapes(indict, parameters=None) -> Tuple[List[Shape], Dict[sym
     :param indict: ODE-toolbox input dictionary.
     """
 
-    logging.info("Processing input shapes...")
+    logging.getLogger(__name__).debug("Processing input...")
 
     # first run for grabbing all the variable names. Coefficients might be incorrect.
     all_variable_symbols = []
     all_parameter_symbols = set()
     all_variable_symbols_ = set()
+
     for shape_json in indict["dynamics"]:
         shape = Shape.from_json(shape_json, parameters=parameters)
         all_variable_symbols.extend(shape.get_state_variables())
@@ -122,7 +124,6 @@ def _from_json_to_shapes(indict, parameters=None) -> Tuple[List[Shape], Dict[sym
     all_parameter_symbols -= all_variable_symbols_
     del all_variable_symbols_
     assert all([_is_sympy_type(sym) for sym in all_variable_symbols])
-    logging.info("All known variables: " + str(all_variable_symbols) + ", all parameters used in ODEs: " + str(all_parameter_symbols))
 
     # validate input for forbidden names
     for var in set(all_variable_symbols) | all_parameter_symbols:
@@ -137,13 +138,13 @@ def _from_json_to_shapes(indict, parameters=None) -> Tuple[List[Shape], Dict[sym
         assert isinstance(param, SympyExpr)
         if not param in parameters.keys():
             # this parameter was used in an ODE, but not explicitly numerically specified
-            logging.info("No numerical value specified for parameter \"" + str(param) + "\"")    # INFO level because this is OK!
+            logging.getLogger(__name__).info("No numerical value specified for parameter \"" + str(param) + "\"")    # INFO level because this is OK!
             parameters[param] = None
 
     # second run with the now-known list of variable symbols
     shapes = []
     for shape_json in indict["dynamics"]:
-        shape = Shape.from_json(shape_json, all_variable_symbols=all_variable_symbols, parameters=parameters, _debug=True)
+        shape = Shape.from_json(shape_json, all_variable_symbols=all_variable_symbols, parameters=parameters)
         shapes.append(shape)
 
     return shapes, parameters
@@ -220,15 +221,16 @@ def _analysis(indict, disable_stiffness_check: bool = False, disable_analytic_so
 
     _init_logging(log_level)
 
-    logging.info("Analysing input:")
-    logging.info(json.dumps(indict, indent=4, sort_keys=True))
+    logging.getLogger(__name__).info("Analysing input:")
+    logging.getLogger(__name__).info(json.dumps(indict, indent=4, sort_keys=True))
 
     if "dynamics" not in indict:
-        logging.info("Warning: empty input (no dynamical equations found); returning empty output")
+        logging.getLogger(__name__).info("Warning: empty input (no dynamical equations found); returning empty output")
         return [], SystemOfShapes.from_shapes([]), []
 
     _read_global_config(indict)
 
+
     # copy parameters from the input and make sure keys are of type sympy.Symbol
     parameters = None
     if "parameters" in indict.keys():
@@ -250,17 +252,17 @@ def _analysis(indict, disable_stiffness_check: bool = False, disable_analytic_so
 
     for shape in shapes:
         if not shape.is_homogeneous() and shape.order > 1:
-            logging.error("For symbol " + str(shape.symbol) + ": higher-order inhomogeneous ODEs are not supported")
+            logging.getLogger(__name__).error("For symbol " + str(shape.symbol) + ": higher-order inhomogeneous ODEs are not supported")
             sys.exit(1)
 
     shape_sys = SystemOfShapes.from_shapes(shapes, parameters=parameters)
     _, node_is_analytically_solvable = _find_analytically_solvable_equations(shape_sys, shapes, parameters=parameters)
 
-    logging.debug("System of equations:")
-    logging.debug("x = " + str(shape_sys.x_))
-    logging.debug("A = " + repr(shape_sys.A_))
-    logging.debug("b = " + str(shape_sys.b_))
-    logging.debug("c = " + str(shape_sys.c_))
+    logging.getLogger(__name__).info("System of equations (with dx/dt = Ax + b + c):")
+    logging.getLogger(__name__).info("x = " + str(shape_sys.x_))
+    logging.getLogger(__name__).info("A = " + repr(shape_sys.A_))
+    logging.getLogger(__name__).info("b = " + str(shape_sys.b_))
+    logging.getLogger(__name__).info("c = " + str(shape_sys.c_))
 
     #
     #   generate analytical solutions (propagators) where possible
@@ -274,7 +276,7 @@ def _analysis(indict, disable_stiffness_check: bool = False, disable_analytic_so
 
     analytic_solver_json = None
     if analytic_syms:
-        logging.info("Generating propagators for the following symbols: " + ", ".join([str(k) for k in analytic_syms]))
+        logging.getLogger(__name__).info("Generating propagators for the following symbols: " + ", ".join([str(k) for k in analytic_syms]))
         sub_sys = shape_sys.get_sub_system(analytic_syms)
         analytic_solver_json = sub_sys.generate_propagator_solver(disable_singularity_detection=disable_singularity_detection, use_alternative_expM=use_alternative_expM)
         analytic_solver_json["solver"] = "analytical"
@@ -286,15 +288,15 @@ def _analysis(indict, disable_stiffness_check: bool = False, disable_analytic_so
 
     if len(analytic_syms) < len(shape_sys.x_):
         numeric_syms = list(set(shape_sys.x_) - set(analytic_syms))
-        logging.info("Generating numerical solver for the following symbols: " + ", ".join([str(sym) for sym in numeric_syms]))
+        logging.getLogger(__name__).info("Generating numerical solver for the following symbols: " + ", ".join([str(sym) for sym in numeric_syms]))
         sub_sys = shape_sys.get_sub_system(numeric_syms)
         solver_json = sub_sys.generate_numeric_solver(state_variables=shape_sys.x_)
         solver_json["solver"] = "numeric"   # will be appended to if stiffness testing is used
         if not disable_stiffness_check:
             if not PYGSL_AVAILABLE:
                 raise Exception("Stiffness test requested, but PyGSL not available")
 
-            logging.info("Performing stiffness test...")
+            logging.getLogger(__name__).info("Performing stiffness test...")
             kwargs = {}   # type: Dict[str, Any]
             if "options" in indict.keys() and "random_seed" in indict["options"].keys():
                 random_seed = int(indict["options"]["random_seed"])
@@ -313,7 +315,7 @@ def _analysis(indict, disable_stiffness_check: bool = False, disable_analytic_so
             solver_type = tester.check_stiffness()
             if not solver_type is None:
                 solver_json["solver"] += "-" + solver_type
-                logging.info(solver_type + " scheme")
+                logging.getLogger(__name__).info(solver_type + " scheme")
 
         solvers_json.append(solver_json)
 
@@ -385,10 +387,10 @@ def _analysis(indict, disable_stiffness_check: bool = False, disable_analytic_so
 
                 if preserve_expressions and sym in preserve_expressions:
                     if "analytic" in solver_json["solver"]:
-                        logging.warning("Not preserving expression for variable \"" + sym + "\" as it is solved by propagator solver")
+                        logging.getLogger(__name__).warning("Not preserving expression for variable \"" + sym + "\" as it is solved by propagator solver")
                         continue
 
-                    logging.info("Preserving expression for variable \"" + sym + "\"")
+                    logging.getLogger(__name__).info("Preserving expression for variable \"" + sym + "\"")
                     var_def_str = _find_variable_definition(indict, sym, order=1)
                     assert var_def_str is not None
                     solver_json["update_expressions"][sym] = var_def_str.replace("'", Config().differential_order_symbol)
@@ -417,8 +419,8 @@ def _analysis(indict, disable_stiffness_check: bool = False, disable_analytic_so
                     for sym, expr in cond_solver["propagators"].items():
                         cond_solver["propagators"][sym] = str(expr)
 
-    logging.info("In ode-toolbox: returning outdict = ")
-    logging.info(json.dumps(solvers_json, indent=4, sort_keys=True))
+    logging.getLogger(__name__).info("Final output result:")
+    logging.getLogger(__name__).info(json.dumps(solvers_json, indent=4, sort_keys=True))
 
     return solvers_json, shape_sys, shapes
 
@@ -429,9 +431,10 @@ def _init_logging(log_level: Union[str, int] = logging.WARNING):
 
     :param log_level: Sets the logging threshold. Logging messages which are less severe than ``log_level`` will be ignored. Log levels can be provided as an integer or string, for example "INFO" (more messages) or "WARN" (fewer messages). For a list of valid logging levels, see https://docs.python.org/3/library/logging.html#logging-levels
     """
-    fmt = '%(levelname)s:%(message)s'
+    fmt = "[ODE-toolbox] %(levelname)s:%(message)s"
     logging.basicConfig(format=fmt)
-    logging.getLogger().setLevel(log_level)
+    logger = logging.getLogger(__name__)
+    logger.setLevel(log_level)
 
 
 def analysis(indict, disable_stiffness_check: bool = False, disable_analytic_solver: bool = False, disable_singularity_detection: bool = False, use_alternative_expM: bool = False, preserve_expressions: Union[bool, Iterable[str]] = False, log_level: Union[str, int] = logging.WARNING) -> List[Dict]:

odetoolbox/config.py

@@ -36,7 +36,8 @@ class Config:
         "max_step_size": 999.,
         "integration_accuracy_abs": 1E-6,
         "integration_accuracy_rel": 1E-6,
-        "forbidden_names": ["oo", "zoo", "nan", "NaN", "__h"]
+        "forbidden_names": ["oo", "zoo", "nan", "NaN", "__h"],
+        "use_alternative_expM": False
     }
 
     def __getitem__(self, key):

odetoolbox/dependency_graph_plotter.py

@@ -75,5 +75,5 @@ def plot_graph(cls, shapes, dependency_edges, node_is_lin, fn=None):
             dot.edge(str(e[0]), str(e[1]))
 
         if not fn is None:
-            logging.info("Saving dependency graph plot to " + fn)
+            logging.getLogger(__name__).debug("Saving dependency graph plot to " + fn)
             dot.render(fn)

odetoolbox/mixed_integrator.py

@@ -41,8 +41,8 @@
     import pygsl.odeiv as odeiv
     PYGSL_AVAILABLE = True
 except ImportError as ie:
-    logging.warning("PyGSL is not available. The stiffness test will be skipped.")
-    logging.warning("Error when importing: " + str(ie))
+    logging.getLogger(__name__).warning("PyGSL is not available. The stiffness test will be skipped.")
+    logging.getLogger(__name__).warning("Error when importing: " + str(ie))
     PYGSL_AVAILABLE = False
 
 
@@ -263,7 +263,7 @@ def integrate_ode(self, initial_values=None, h_min_lower_bound=5E-9, raise_error
 
                     if h_min < h_min_lower_bound:
                         estr = "Integration step below %.e (s=%.f). Please check your ODE." % (h_min_lower_bound, h_min)
-                        logging.warning(estr)
+                        logging.getLogger(__name__).warning(estr)
                         if raise_errors:
                             raise Exception(estr)
 
@@ -337,7 +337,7 @@ def integrate_ode(self, initial_values=None, h_min_lower_bound=5E-9, raise_error
             if self._debug_plot_dir:
                 self.integrator_debug_plot(t_log, h_log, y_log, dir=self._debug_plot_dir)
 
-        logging.info("For integrator = " + str(self.numeric_integrator) + ": h_min = " + str(h_min) + ", h_avg = " + str(h_avg) + ", runtime = " + str(runtime))
+        logging.getLogger(__name__).info("For integrator = " + str(self.numeric_integrator) + ": h_min = " + str(h_min) + ", h_avg = " + str(h_avg) + ", runtime = " + str(runtime))
 
         sym_list = self._system_of_shapes.x_
 
@@ -460,10 +460,10 @@ def step(self, t, y, params):
             # return [ float(self._update_expr[str(sym)].evalf(subs=self._locals)) for sym in self._system_of_shapes.x_ ]	# non-wrapped version
             _ret = [self._update_expr_wrapped[str(sym)](*y) for sym in self._system_of_shapes.x_]
         except Exception as e:
-            logging.error("E==>", type(e).__name__ + ": " + str(e))
-            logging.error("     Local parameters at time of failure:")
+            logging.getLogger(__name__).error("E==>", type(e).__name__ + ": " + str(e))
+            logging.getLogger(__name__).error("     Local parameters at time of failure:")
             for k, v in self._locals.items():
-                logging.error("    ", k, "=", v)
+                logging.getLogger(__name__).error("    ", k, "=", v)
             raise
 
         return _ret