Time series logging

.gitignore

@@ -35,3 +35,7 @@ run-debug-*
 .pytest_cache
 
 test/nodal-dg
+
+# Logging output files
+*.sqlite
+*.sqlite-journal

doc/conf.py

@@ -84,6 +84,8 @@
     "https://documen.tician.de/loopy/": None,
     "https://documen.tician.de/pymbolic/": None,
     "https://documen.tician.de/pytools/": None,
+    "https://logpyle.readthedocs.io/en/latest/": None,
+    "https://psutil.readthedocs.io/en/latest/": None,
     }
 
 autoclass_content = "class"

doc/running/profiling.rst

@@ -1,5 +1,9 @@
+Profiling and logging
+=====================
+
+
 Profiling kernel execution
-==========================
+--------------------------
 
 You can use :class:`mirgecom.profiling.PyOpenCLProfilingArrayContext` instead of
 :class:`~meshmode.array_context.PyOpenCLArrayContext` to profile kernel executions.
@@ -12,3 +16,15 @@ In addition to using this array context, you also need to enable profiling in th
 Note that profiling has a performance impact (~20% at the time of this writing).
 
 .. automodule:: mirgecom.profiling
+
+
+Time series logging
+-------------------
+
+Mirgecom supports logging of simulation and profiling quantities with the help
+of :mod:`logpyle`. Logpyle requires
+classes to describe how quantities for logging are calculated. For mirgecom, these classes are described below.
+
+.. automodule:: mirgecom.logging_quantities
+
+An overview of how to use logpyle is given in the :any:`Logpyle documentation <logpyle>`.

doc/support/tools.rst

@@ -2,3 +2,5 @@ Random Pile'o'Tools
 ===================
 
 .. automodule:: mirgecom.simutil
+
+.. automodule:: mirgecom.utils

examples/vortex-mpi.py

@@ -35,6 +35,7 @@
 from grudge.eager import EagerDGDiscretization
 from grudge.shortcuts import make_visualizer
 
+from mirgecom.profiling import PyOpenCLProfilingArrayContext
 
 from mirgecom.euler import inviscid_operator
 from mirgecom.simutil import (
@@ -52,17 +53,36 @@
 from mirgecom.initializers import Vortex2D
 from mirgecom.eos import IdealSingleGas
 
+from logpyle import IntervalTimer
+from mirgecom.euler import extract_vars_for_logging, units_for_logging
+
+from mirgecom.logging_quantities import (initialize_logmgr,
+    logmgr_add_default_discretization_quantities, logmgr_add_device_name)
+
 
 logger = logging.getLogger(__name__)
 
 
 @mpi_entry_point
-def main(ctx_factory=cl.create_some_context):
+def main(ctx_factory=cl.create_some_context, use_profiling=False, use_logmgr=False):
     """Drive the example."""
+    from mpi4py import MPI
+    comm = MPI.COMM_WORLD
+
+    logmgr = initialize_logmgr(use_logmgr,
+        filename="vortex.sqlite", mode="wu", mpi_comm=comm)
+
     cl_ctx = ctx_factory()
-    queue = cl.CommandQueue(cl_ctx)
-    actx = PyOpenCLArrayContext(queue,
-                allocator=cl_tools.MemoryPool(cl_tools.ImmediateAllocator(queue)))
+    if use_profiling:
+        queue = cl.CommandQueue(cl_ctx,
+            properties=cl.command_queue_properties.PROFILING_ENABLE)
+        actx = PyOpenCLProfilingArrayContext(queue,
+            allocator=cl_tools.MemoryPool(cl_tools.ImmediateAllocator(queue)),
+            logmgr=logmgr)
+    else:
+        queue = cl.CommandQueue(cl_ctx)
+        actx = PyOpenCLArrayContext(queue,
+            allocator=cl_tools.MemoryPool(cl_tools.ImmediateAllocator(queue)))
 
     dim = 2
     nel_1d = 16
@@ -89,8 +109,6 @@ def main(ctx_factory=cl.create_some_context):
     box_ll = -5.0
     box_ur = 5.0
 
-    from mpi4py import MPI
-    comm = MPI.COMM_WORLD
     rank = comm.Get_rank()
 
     if dim != 2:
@@ -108,6 +126,27 @@ def main(ctx_factory=cl.create_some_context):
     nodes = thaw(actx, discr.nodes())
     current_state = initializer(nodes)
 
+    vis_timer = None
+
+    if logmgr:
+        logmgr_add_device_name(logmgr, queue)
+        logmgr_add_default_discretization_quantities(logmgr, discr, dim,
+                             extract_vars_for_logging, units_for_logging)
+
+        logmgr.add_watches(["step.max", "t_step.max", "t_log.max",
+                            "min_temperature", "L2_norm_momentum1"])
+
+        try:
+            logmgr.add_watches(["memory_usage.max"])
+        except KeyError:
+            pass
+
+        if use_profiling:
+            logmgr.add_watches(["multiply_time.max"])
+
+        vis_timer = IntervalTimer("t_vis", "Time spent visualizing")
+        logmgr.add_quantity(vis_timer)
+
     visualizer = make_visualizer(discr, order + 3 if dim == 2 else order)
 
     initname = initializer.__class__.__name__
@@ -134,14 +173,16 @@ def my_checkpoint(step, t, dt, state):
         return sim_checkpoint(discr, visualizer, eos, q=state,
                               exact_soln=initializer, vizname=casename, step=step,
                               t=t, dt=dt, nstatus=nstatus, nviz=nviz,
-                              exittol=exittol, constant_cfl=constant_cfl, comm=comm)
+                              exittol=exittol, constant_cfl=constant_cfl, comm=comm,
+                              vis_timer=vis_timer)
 
     try:
         (current_step, current_t, current_state) = \
             advance_state(rhs=my_rhs, timestepper=timestepper,
                           checkpoint=my_checkpoint,
                           get_timestep=get_timestep, state=current_state,
-                          t=current_t, t_final=t_final)
+                          t=current_t, t_final=t_final, logmgr=logmgr, eos=eos,
+                          dim=dim)
     except ExactSolutionMismatch as ex:
         current_step = ex.step
         current_t = ex.t
@@ -157,9 +198,17 @@ def my_checkpoint(step, t, dt, state):
     if current_t - t_final < 0:
         raise ValueError("Simulation exited abnormally")
 
+    if logmgr:
+        logmgr.close()
+    elif use_profiling:
+        print(actx.tabulate_profiling_data())
+
 
 if __name__ == "__main__":
     logging.basicConfig(format="%(message)s", level=logging.INFO)
-    main()
+    use_profiling = True
+    use_logging = True
+
+    main(use_profiling=use_profiling, use_logmgr=use_logging)
 
 # vim: foldmethod=marker

mirgecom/eos.py

@@ -111,7 +111,7 @@ def gamma(self):
         raise NotImplementedError()
 
     def dependent_vars(self, q: ConservedVars) -> EOSDependentVars:
-        """Get an agglomerated array of the depedent variables."""
+        """Get an agglomerated array of the dependent variables."""
         return EOSDependentVars(
             pressure=self.pressure(q),
             temperature=self.temperature(q),

mirgecom/euler.py

@@ -352,6 +352,32 @@ def get_inviscid_cfl(discr, eos, dt, q):
     return dt / wanted_dt
 
 
+# By default, run unitless
+NAME_TO_UNITS = {
+    "mass": "",
+    "energy": "",
+    "momentum": "",
+    "temperature": "",
+    "pressure": ""
+}
+
+
+def units_for_logging(quantity: str) -> str:
+    """Return unit for quantity."""
+    return NAME_TO_UNITS[quantity]
+
+
+def extract_vars_for_logging(dim: int, state: np.ndarray, eos) -> dict:
+    """Extract state vars."""
+    cv = split_conserved(dim, state)
+    dv = eos.dependent_vars(cv)
+
+    from mirgecom.utils import asdict_shallow
+    name_to_field = asdict_shallow(cv)
+    name_to_field.update(asdict_shallow(dv))
+    return name_to_field
+
+
 def get_inviscid_timestep(discr, eos, cfl, q):
     """Routine (will) return the (local) maximum stable inviscid timestep.