Change logging strategy and add new logging for adaptivity metrics

CHANGELOG.md

@@ -2,6 +2,7 @@
 
 ## latest
 
+- Improve logging by wrapping Python logger in a class https://github.com/precice/micro-manager/pull/133
 - Refactor large parts of solve and adaptivity to group datasets and simplify handling https://github.com/precice/micro-manager/pull/135
 - Add information about adaptivity tuning parameters https://github.com/precice/micro-manager/pull/131
 - Put computation of counting active steps inside the adaptivity variant `if` condition https://github.com/precice/micro-manager/pull/130

docs/configuration.md

@@ -13,7 +13,7 @@ The Micro Manager is configured with a JSON file. An example configuration file
 {
     "micro_file_name": "micro_solver",
     "coupling_params": {
-        "config_file_name": "precice-config.xml",
+        "precice_config_file_name": "precice-config.xml",
         "macro_mesh_name": "macro-mesh",
         "read_data_names": {"temperature": "scalar", "heat-flux": "vector"},
         "write_data_names": {"porosity": "scalar", "conductivity": "vector"}
@@ -38,7 +38,7 @@ There are three main sections in the configuration file, the `coupling_params`,
 
 Parameter | Description
 --- | ---
-`config_file_name` |  Path to the preCICE XML configuration file from the current working directory.
+`precice_config_file_name` |  Path to the preCICE XML configuration file from the current working directory.
 `macro_mesh_name` |  Name of the macro mesh as stated in the preCICE configuration.
 `read_data_names` |  A Python dictionary with the names of the data to be read from preCICE as keys and `"scalar"` or `"vector"`  as values depending on the nature of the data.
 `write_data_names` |  A Python dictionary with the names of the data to be written to preCICE as keys and `"scalar"` or `"vector"`  as values depending on the nature of the data.
@@ -74,14 +74,14 @@ If the parameter `data_from_micro_sims` is set, the data to be output needs to b
 </participant>
 ```
 
-If `output_micro_sim_solve_time` is set, add similar entries for the data `micro_sim_time` in the following way:
+If `output_micro_sim_solve_time` is set, add similar entries for the data `solve_cpu_time` in the following way:
 
 ```xml
-<data:scalar name="micro_sim_time"/>
+<data:scalar name="solve_cpu_time"/>
 
 <participant name="Micro-Manager">
   ...
-  <write-data name="micro_sim_time" mesh="macro-mesh"/>
+  <write-data name="solve_cpu_time" mesh="macro-mesh"/>
   <export:vtu directory="Micro-Manager-output" every-n-time-windows="5"/>
 </participant>
 ```
@@ -120,6 +120,7 @@ Parameter | Description
 `refining_constant` | Refining constant $$ C_r $$, set as $$ 0 =< C_r < 1 $$.
 `every_implicit_iteration` | If True, adaptivity is calculated in every implicit iteration. <br> If False, adaptivity is calculated once at the start of the time window and then reused in every implicit time iteration.
 `similarity_measure`| Similarity measure to be used for adaptivity. Can be either `L1`, `L2`, `L1rel` or `L2rel`. By default, `L1` is used. The `rel` variants calculate the respective relative norms. This parameter is *optional*.
+`output_cpu_time` | Write CPU time of the adaptivity computation to preCICE, to be exported. This parameter is *optional*.
 
 The primary tuning parameters for adaptivity are the history parameter $$ \Lambda $$, the coarsening constant $$ C_c $$, and the refining constant $$ C_r $$. Their effects can be interpreted as:
 
@@ -170,6 +171,8 @@ The Micro Manager uses the output functionality of preCICE, hence these data set
 </participant>
 ```
 
+If the parameter `output_cpu_time` in `adaptivity_settings` is set to `True`, a scalar data field `adaptivity_cpu_time` needs to be added in the same way as described above.
+
 ## Interpolate a crashed micro simulation
 
 If the optional dependency `sklearn` is installed, the Micro Manager will derive the output of a crashed micro simulation by interpolating outputs from similar simulations. To enable this, set

examples/micro-manager-cpp-adaptivity-config.json

@@ -1,7 +1,7 @@
 {
     "micro_file_name": "cpp-dummy/micro_dummy",
     "coupling_params": {
-        "config_file_name": "precice-config-adaptivity.xml",
+        "precice_config_file_name": "precice-config-adaptivity.xml",
         "macro_mesh_name": "macro-mesh",
         "read_data_names": {"macro-scalar-data": "scalar", "macro-vector-data": "vector"},
         "write_data_names": {"micro-scalar-data": "scalar", "micro-vector-data": "vector"}
@@ -16,7 +16,8 @@
             "history_param": 0.5,
             "coarsening_constant": 0.3,
             "refining_constant": 0.4,
-            "every_implicit_iteration": "True"
+            "every_implicit_iteration": "True",
+            "output_cpu_time": "True"
         }
     },
     "diagnostics": {

examples/micro-manager-cpp-config.json

@@ -1,7 +1,7 @@
 {
     "micro_file_name": "cpp-dummy/micro_dummy",
     "coupling_params": {
-        "config_file_name": "precice-config.xml",
+        "precice_config_file_name": "precice-config.xml",
         "macro_mesh_name": "macro-mesh",
         "read_data_names": {"macro-scalar-data": "scalar", "macro-vector-data": "vector"},
         "write_data_names": {"micro-scalar-data": "scalar", "micro-vector-data": "vector"}

examples/micro-manager-python-adaptivity-config.json

@@ -1,7 +1,7 @@
 {
     "micro_file_name": "python-dummy/micro_dummy",
     "coupling_params": {
-        "config_file_name": "precice-config-adaptivity.xml",
+        "precice_config_file_name": "precice-config-adaptivity.xml",
         "macro_mesh_name": "macro-mesh",
         "read_data_names": {"macro-scalar-data": "scalar", "macro-vector-data": "vector"},
         "write_data_names": {"micro-scalar-data": "scalar", "micro-vector-data": "vector"}
@@ -16,7 +16,8 @@
             "history_param": 0.5,
             "coarsening_constant": 0.3,
             "refining_constant": 0.4,
-            "every_implicit_iteration": "True"
+            "every_implicit_iteration": "True",
+            "output_cpu_time": "True"
         }
     },
     "diagnostics": {

examples/micro-manager-python-config.json

@@ -1,7 +1,7 @@
 {
     "micro_file_name": "python-dummy/micro_dummy",
     "coupling_params": {
-        "config_file_name": "precice-config.xml",
+        "precice_config_file_name": "precice-config.xml",
         "macro_mesh_name": "macro-mesh",
         "read_data_names": {"macro-scalar-data": "scalar", "macro-vector-data": "vector"},
         "write_data_names": {"micro-scalar-data": "scalar", "micro-vector-data": "vector"}

examples/precice-config-adaptivity.xml

@@ -10,18 +10,20 @@
     <data:vector name="macro-vector-data"/>
     <data:scalar name="micro-scalar-data"/>
     <data:vector name="micro-vector-data"/>
-    <data:scalar name="micro_sim_time"/>
+    <data:scalar name="solve_cpu_time"/>
     <data:scalar name="active_state"/>
     <data:scalar name="active_steps"/>
+    <data:scalar name="adaptivity_cpu_time"/>
 
     <mesh name="macro-mesh" dimensions="3">
        <use-data name="macro-scalar-data"/>
        <use-data name="macro-vector-data"/>
        <use-data name="micro-scalar-data"/>
        <use-data name="micro-vector-data"/>
-       <use-data name="micro_sim_time"/>
+       <use-data name="solve_cpu_time"/>
        <use-data name="active_state"/>
        <use-data name="active_steps"/>
+       <use-data name="adaptivity_cpu_time"/>
     </mesh>
 
     <participant name="Macro-dummy">
@@ -38,9 +40,10 @@
       <read-data name="macro-vector-data" mesh="macro-mesh"/>
       <write-data name="micro-scalar-data" mesh="macro-mesh"/>
       <write-data name="micro-vector-data" mesh="macro-mesh"/>
-      <write-data name="micro_sim_time" mesh="macro-mesh"/>
+      <write-data name="solve_cpu_time" mesh="macro-mesh"/>
       <write-data name="active_state" mesh="macro-mesh"/>
       <write-data name="active_steps" mesh="macro-mesh"/>
+      <write-data name="adaptivity_cpu_time" mesh="macro-mesh"/>
     </participant>
 
     <m2n:sockets acceptor="Micro-Manager" connector="Macro-dummy"/>

examples/precice-config.xml

@@ -8,14 +8,14 @@
   <data:vector name="macro-vector-data" />
   <data:scalar name="micro-scalar-data" />
   <data:vector name="micro-vector-data" />
-  <data:scalar name="micro_sim_time" />
+  <data:scalar name="solve_cpu_time" />
 
   <mesh name="macro-mesh" dimensions="3">
     <use-data name="macro-scalar-data" />
     <use-data name="macro-vector-data" />
     <use-data name="micro-scalar-data" />
     <use-data name="micro-vector-data" />
-    <use-data name="micro_sim_time" />
+    <use-data name="solve_cpu_time" />
   </mesh>
 
   <participant name="Macro-dummy">
@@ -32,7 +32,7 @@
     <read-data name="macro-vector-data" mesh="macro-mesh" />
     <write-data name="micro-scalar-data" mesh="macro-mesh" />
     <write-data name="micro-vector-data" mesh="macro-mesh" />
-    <write-data name="micro_sim_time" mesh="macro-mesh" />
+    <write-data name="solve_cpu_time" mesh="macro-mesh" />
   </participant>
 
   <m2n:sockets acceptor="Micro-Manager" connector="Macro-dummy" />

micro_manager/adaptivity/adaptivity.py

@@ -10,7 +10,7 @@
 
 
 class AdaptivityCalculator:
-    def __init__(self, configurator, logger) -> None:
+    def __init__(self, configurator) -> None:
         """
         Class constructor.
 
@@ -26,8 +26,6 @@ def __init__(self, configurator, logger) -> None:
         self._adaptivity_data_names = configurator.get_data_for_adaptivity()
         self._adaptivity_type = configurator.get_adaptivity_type()
 
-        self._logger = logger
-
         self._coarse_tol = 0.0
         self._ref_tol = 0.0
 

micro_manager/adaptivity/global_adaptivity.py

@@ -19,7 +19,6 @@ class GlobalAdaptivityCalculator(AdaptivityCalculator):
     def __init__(
         self,
         configurator,
-        logger,
         global_number_of_sims: int,
         global_ids: list,
         rank: int,
@@ -43,7 +42,7 @@ def __init__(
         comm : MPI.COMM_WORLD
             Global communicator of MPI.
         """
-        super().__init__(configurator, logger)
+        super().__init__(configurator)
         self._global_ids = global_ids
         self._comm = comm
         self._rank = rank
@@ -127,19 +126,7 @@ def compute_adaptivity(
             similarity_dists, is_sim_active, sim_is_associated_to
         )
 
-        self._logger.info(
-            "{} active simulations, {} inactive simulations".format(
-                np.count_nonzero(
-                    is_sim_active[self._global_ids[0] : self._global_ids[-1] + 1]
-                ),
-                np.count_nonzero(
-                    is_sim_active[self._global_ids[0] : self._global_ids[-1] + 1]
-                    == False
-                ),
-            )
-        )
-
-        return [similarity_dists, is_sim_active, sim_is_associated_to]
+        return similarity_dists, is_sim_active, sim_is_associated_to
 
     def get_active_sim_ids(self, is_sim_active: np.array) -> np.ndarray:
         """
@@ -203,6 +190,22 @@ def get_full_field_micro_output(
 
         return micro_sims_output
 
+    def log_metrics(self, logger, adaptivity_data: list, n: int) -> None:
+        """ """
+        is_sim_active = adaptivity_data[1]
+        global_active_sims = np.count_nonzero(is_sim_active)
+        global_inactive_sims = np.count_nonzero(is_sim_active == False)
+
+        logger.log_info_one_rank(
+            "{},{},{},{},{}".format(
+                n,
+                np.mean(global_active_sims),
+                np.mean(global_inactive_sims),
+                np.max(global_active_sims),
+                np.max(global_inactive_sims),
+            )
+        )
+
     def _communicate_micro_output(
         self,
         adaptivity_data: list,

micro_manager/adaptivity/local_adaptivity.py

@@ -10,18 +10,19 @@
 
 
 class LocalAdaptivityCalculator(AdaptivityCalculator):
-    def __init__(self, configurator, logger) -> None:
+    def __init__(self, configurator, comm) -> None:
         """
         Class constructor.
 
         Parameters
         ----------
         configurator : object of class Config
             Object which has getter functions to get parameters defined in the configuration file.
-        logger : object of logging
-            Logger defined from the standard package logging
+        comm : MPI.COMM_WORLD
+            Global communicator of MPI.
         """
-        super().__init__(configurator, logger)
+        super().__init__(configurator)
+        self._comm = comm
 
     def compute_adaptivity(
         self,
@@ -75,14 +76,7 @@ def compute_adaptivity(
             similarity_dists, is_sim_active, sim_is_associated_to
         )
 
-        self._logger.info(
-            "{} active simulations, {} inactive simulations".format(
-                np.count_nonzero(is_sim_active),
-                np.count_nonzero(is_sim_active == False),
-            )
-        )
-
-        return [similarity_dists, is_sim_active, sim_is_associated_to]
+        return similarity_dists, is_sim_active, sim_is_associated_to
 
     def get_active_sim_ids(self, is_sim_active) -> np.ndarray:
         """
@@ -150,6 +144,27 @@ def get_full_field_micro_output(
 
         return micro_sims_output
 
+    def log_metrics(self, logger, adaptivity_list: list, n: int) -> None:
+        """ """
+        is_sim_active = adaptivity_list[1]
+
+        # MPI Gather is necessary as local adaptivity only stores local data
+        local_active_sims = np.count_nonzero(is_sim_active)
+        global_active_sims = self._comm.gather(local_active_sims)
+
+        local_inactive_sims = np.count_nonzero(is_sim_active == False)
+        global_inactive_sims = self._comm.gather(local_inactive_sims)
+
+        logger.log_info_one_rank(
+            "{},{},{},{},{}".format(
+                n,
+                np.mean(global_active_sims),
+                np.mean(global_inactive_sims),
+                np.max(global_active_sims),
+                np.max(global_inactive_sims),
+            )
+        )
+
     def _update_inactive_sims(
         self,
         similarity_dists: np.ndarray,