Move log file after creation to correct model directory

gusto/io.py

@@ -10,7 +10,7 @@
 from firedrake import (Function, functionspaceimpl, File,
                        DumbCheckpoint, FILE_CREATE, FILE_READ, CheckpointFile)
 import numpy as np
-from gusto.logging import logger
+from gusto.logging import logger, update_logfile_location
 
 __all__ = ["pick_up_mesh", "IO"]
 
@@ -36,6 +36,7 @@ def pick_up_mesh(output, mesh_name):
         chkfile = output.checkpoint_pickup_filename
     else:
         dumpdir = path.join("results", output.dirname)
+        update_logfile_location(dumpdir)
         chkfile = path.join(dumpdir, "chkpt.h5")
     with CheckpointFile(chkfile, 'r') as chk:
         mesh = chk.load_mesh(mesh_name)
@@ -293,6 +294,7 @@ def setup_dump(self, state_fields, t, pick_up=False):
                 self.output.point_data, self.output.checkpoint and not pick_up]):
             # setup output directory and check that it does not already exist
             self.dumpdir = path.join("results", self.output.dirname)
+            update_logfile_location(self.dumpdir)
             running_tests = '--running-tests' in sys.argv or "pytest" in self.output.dirname
 
             if self.mesh.comm.Get_rank() == 0:
@@ -429,6 +431,7 @@ def pick_up_from_checkpoint(self, state_fields):
         # Set dumpdir if has not been done already
         if self.dumpdir is None:
             self.dumpdir = path.join("results", self.output.dirname)
+            update_logfile_location(self.dumpdir)
 
         # Need to pick up reference profiles, but don't know which are stored
         possible_ref_profiles = []

gusto/logging.py

@@ -31,14 +31,36 @@
 
 from datetime import datetime
 from logging import NOTSET, DEBUG, INFO, WARNING, ERROR, CRITICAL  # noqa: F401
+from pathlib import Path
 
 from pyop2.mpi import COMM_WORLD
 
-__all__ = ["logger", "set_log_handler"]
+__all__ = [
+    "logger", "set_log_handler", "LoggingError", "NOTSET", "DEBUG",
+    "INFO", "WARNING", "ERROR", "CRITICAL"
+]
+
+
+class LoggingError(Exception):
+    pass
+
 
 logging.captureWarnings(True)
 logger = logging.getLogger("gusto")
 
+
+def capture_exceptions(exception_type, exception_value, traceback, logger=logger):
+    """ This function allows all unhandled exceptions to be logged to
+    Gusto's logs
+    """
+    logger.error(
+        "Gusto is logging this unhandled exception:",
+        exc_info=(exception_type, exception_value, traceback)
+    )
+
+
+sys.excepthook = capture_exceptions
+
 # Set the log level based on environment variables
 log_level = os.environ.get("GUSTO_LOG_LEVEL", WARNING)
 logfile_level = os.environ.get("GUSTO_FILE_LOG_LEVEL", DEBUG)
@@ -60,14 +82,14 @@
         parallel_log = None
 
 
-def create_logfile_handler(path):
-    ''' Handler for logfiles
+def create_logfile_handler(path, mode="w"):
+    """ Handler for logfiles.
 
     Args:
         path: path to log file
 
-    '''
-    logfile = logging.FileHandler(filename=path, mode="w")
+    """
+    logfile = logging.FileHandler(filename=path, mode=mode)
     logfile.setLevel(logfile_level)
     logfile_formatter = logging.Formatter(
         '%(asctime)s %(levelname)-8s %(message)s'
@@ -77,11 +99,11 @@ def create_logfile_handler(path):
 
 
 def create_console_handler(fmt):
-    ''' Handler for console logging
+    """ Handler for console logging.
 
     Args:
         fmt: format string for log output
-    '''
+    """
     console = logging.StreamHandler()
     console.setLevel(logconsole_level)
     console_formatter = logging.Formatter(fmt)
@@ -90,15 +112,14 @@ def create_console_handler(fmt):
 
 
 def set_log_handler(comm=COMM_WORLD):
-    """
-    Set all handlers for logging.
+    """ Set all handlers for logging.
 
     Args:
         comm (:class:`MPI.Comm`): MPI communicator.
     """
     # Set up logging
     timestamp = datetime.now()
-    logfile_name = f"gusto-{timestamp.strftime('%Y-%m-%dT%H%M%S')}"
+    logfile_name = f"temp-gusto-{timestamp.strftime('%Y-%m-%dT%H%M%S')}"
     if parallel_log in ["FILE", "BOTH"]:
         logfile_name += f"_{comm.rank}"
     logfile_name += ".log"
@@ -113,15 +134,55 @@ def set_log_handler(comm=COMM_WORLD):
 
     if comm.rank == 0:
         # Always log on rank 0
-        logger.addHandler(create_logfile_handler(logfile_path))
-        logger.addHandler(create_console_handler(console_format_str))
+        lfh = create_logfile_handler(logfile_path)
+        lfh.name = "gusto-temp-file-log"
+        logger.addHandler(lfh)
+        ch = create_console_handler(console_format_str)
+        ch.name = "gusto-console-log"
+        logger.addHandler(ch)
     else:
         # Only log on other ranks if enabled
         if parallel_log in ["FILE", "BOTH"]:
-            logger.addHandler(create_logfile_handler(logfile_path))
+            lfh = create_logfile_handler(logfile_path)
+            lfh.name = "gusto-temp-file-log"
+            logger.addHandler(lfh)
         if parallel_log in ["CONSOLE", "BOTH"]:
-            logger.addHandler(create_console_handler(console_format_str))
+            ch = create_console_handler(console_format_str)
+            ch.name = "gusto-console-log"
+            logger.addHandler(ch)
         if not logger.handlers:
             logger.addHandler(logging.NullHandler())
 
     logger.info("Running %s" % " ".join(sys.argv))
+
+
+def update_logfile_location(new_path):
+    """ Update the location of the logfile.
+
+    This is used to move the temporary log file created in the results
+    directory to the appropriate model directory.
+
+    """
+    new_path = Path(new_path)
+    fh = [*filter(lambda x: x.name == "gusto-temp-file-log", logger.handlers)]
+
+    if len(fh) == 1:
+        fh = fh[0]
+        logger.debug("Closing temporary logger and moving logfile")
+        old_path = Path(fh.baseFilename)
+        filename = Path(old_path.name.removeprefix("temp-"))
+        fh.flush()
+        fh.close()
+
+        os.makedirs(new_path, exist_ok=True)
+        os.rename(old_path, new_path/filename)
+
+        new_fh = create_logfile_handler(new_path/filename, mode="a")
+        new_fh.name = "gusto-file-log"
+        logger.addHandler(new_fh)
+        logger.debug("Re-opening logger")
+    elif len(fh) > 1:
+        raise LoggingError(
+            "More than one log handler with name `gusto-temp-file-log`\n"
+            "Logging has been set up incorrectly"
+        )