Centralize results directories and files and revamp logging

e3sm_to_cmip/_logger.py

@@ -1,68 +1,121 @@
+"""Logger module for setting up a custom logger."""
+
 import logging
-import os
-import time
 from datetime import datetime
 
-from pytz import UTC
+LOG_FORMAT = (
+    "%(asctime)s [%(levelname)s]: %(filename)s(%(funcName)s:%(lineno)s) >> %(message)s"
+)
+LOG_FILEMODE = "w"
+LOG_LEVEL = logging.INFO
 
 
-def _setup_root_logger() -> str:  # pragma: no cover
-    """Sets up the root logger.
+class CustomFormatter(logging.Formatter):
+    def formatTime(self, record, datefmt=None):
+        # Includes microseconds up to 6 digits
+        dt = datetime.fromtimestamp(record.created)
 
-    The logger module will write to a log file and stream the console
-    simultaneously.
+        return dt.strftime("%Y-%m-%d %H:%M:%S.%f")
 
-    The log files are saved in a `/logs` directory relative to where
-    `e3sm_to_cmip` is executed.
 
-    Returns
-    -------
-    str
-        The name of the logfile.
+def _setup_root_logger():
+    """Configures the root logger.
+
+    This function sets up the root logger with a predefined format and log level.
+    It also enables capturing of warnings issued by the `warnings` module and
+    redirects them to the logging system.
+
+    Notes
+    -----
+    - The `force=True` parameter ensures that any existing logging configuration
+      is overridden.
+    - The file handler is added dynamically to the root logger later in the
+      E3SMtoCMIP class once the log file path is known.
     """
-    os.makedirs("logs", exist_ok=True)
-    filename = f'logs/{UTC.localize(datetime.utcnow()).strftime("%Y%m%d_%H%M%S_%f")}'
-    log_format = "%(asctime)s_%(msecs)03d:%(levelname)s:%(funcName)s:%(message)s"
+    custom_formatter = CustomFormatter(LOG_FORMAT)
+    console_handler = logging.StreamHandler()
+    console_handler.setFormatter(custom_formatter)
 
-    # Setup the logging module.
     logging.basicConfig(
-        filename=filename,
-        format=log_format,
-        datefmt="%Y%m%d_%H%M%S",
-        level=logging.DEBUG,
+        level=LOG_LEVEL,
+        force=True,
+        handlers=[console_handler],
     )
-    logging.captureWarnings(True)
-    logging.Formatter.converter = time.gmtime
-
-    # Configure and add a console stream handler.
-    console_handler = logging.StreamHandler()
-    console_handler.setLevel(logging.INFO)
-    log_formatter = logging.Formatter(log_format)
-    console_handler.setFormatter(log_formatter)
-    logging.getLogger().addHandler(console_handler)
 
-    return filename
+    logging.captureWarnings(True)
 
 
-def _setup_logger(name, propagate=True) -> logging.Logger:
-    """Sets up a logger object.
+def _setup_child_logger(name: str, propagate: bool = True) -> logging.Logger:
+    """Sets up a logger that is a child of the root logger.
 
-    This function is intended to be used at the top-level of a module.
+    This child logger inherits the root logger's handlers.
 
     Parameters
     ----------
     name : str
         Name of the file where this function is called.
     propagate : bool, optional
-        Propogate this logger module's messages to the root logger or not, by
-        default True.
+        Whether to propagate logger messages or not, by default True.
 
     Returns
     -------
     logging.Logger
-        The logger.
+        The child logger.
+
+    Examples
+    ---------
+    Detailed information, typically of interest only when diagnosing problems:
+
+    >>> logger.debug("")
+
+    Confirmation that things are working as expected:
+
+    >>> logger.info("")
+
+    An indication that something unexpected happened, or indicative of some
+    problem in the near future:
+
+    >>> logger.warning("")
+
+    The software has not been able to perform some function due to a more
+    serious problem:
+
+    >>> logger.error("")
+
+    Similar to ``logger.error()``, but also outputs stack trace:
+
+    >>> logger.exception("", exc_info=True)
+
+    A serious error, indicating that the program itself may be unable to
+    continue running:
+
+    >>> logger.critical("")
     """
     logger = logging.getLogger(name)
     logger.propagate = propagate
 
     return logger
+
+
+def _add_filehandler(log_path: str):
+    """Adds a file handler to the root logger dynamically.
+
+    Adding the file handler will also create the log file automatically.
+
+    Parameters
+    ----------
+    log_path : str
+        The path to the log file.
+
+    Notes
+    -----
+    Any warnings that appear before the log filehandler is instantiated will not
+    be captured (e.g,. esmpy VersionWarning). However, they will still be
+    captured by the console via the default StreamHandler.
+    """
+    file_handler = logging.FileHandler(log_path, mode=LOG_FILEMODE)
+
+    custom_formatter = CustomFormatter(LOG_FORMAT)
+    file_handler.setFormatter(custom_formatter)
+
+    logging.root.addHandler(file_handler)

e3sm_to_cmip/cmor_handlers/handler.py

@@ -11,11 +11,11 @@
 import xcdat as xc
 import yaml
 
-from e3sm_to_cmip._logger import _setup_logger
+from e3sm_to_cmip._logger import _setup_child_logger
 from e3sm_to_cmip.cmor_handlers import FILL_VALUE, _formulas
 from e3sm_to_cmip.util import _get_table_for_non_monthly_freq
 
-logger = _setup_logger(__name__)
+logger = _setup_child_logger(__name__)
 
 # The names for valid hybrid sigma levels.
 HYBRID_SIGMA_LEVEL_NAMES = [
@@ -645,7 +645,10 @@ def _cmor_write(
         """
         output_data = self._get_output_data(ds)
 
-        cmor.write(var_id=cmor_var_id, data=output_data)
+        try:
+            cmor.write(var_id=cmor_var_id, data=output_data)
+        except Exception as e:
+            logger.error(f"Error writing variable {self.name} to file: {e}")
 
     def _cmor_write_with_time(
         self,

e3sm_to_cmip/cmor_handlers/utils.py

@@ -11,11 +11,11 @@
     LEGACY_HANDLER_DIR_PATH,
     MPAS_HANDLER_DIR_PATH,
 )
-from e3sm_to_cmip._logger import _setup_logger
+from e3sm_to_cmip._logger import _setup_child_logger
 from e3sm_to_cmip.cmor_handlers.handler import VarHandler
 from e3sm_to_cmip.util import _get_table_for_non_monthly_freq
 
-logger = _setup_logger(__name__)
+logger = _setup_child_logger(__name__)
 
 # Type aliases
 Frequency = Literal["mon", "day", "6hrLev", "6hrPlev", "6hrPlevPt", "3hr", "1hr"]

e3sm_to_cmip/cmor_handlers/vars/README.md

@@ -6,4 +6,3 @@ to `handlers.yaml`.
 For example:
 
 - Some contain legacy `handle_simple()` functions that have since been refactored as a single `handle_simple()` function
-- `phalf.py` and `pfull.py` still use `cdms2` and `cdutil`

e3sm_to_cmip/cmor_handlers/vars/areacella.py

@@ -13,11 +13,11 @@
 import xarray as xr
 
 from e3sm_to_cmip import resources
-from e3sm_to_cmip._logger import _setup_logger
+from e3sm_to_cmip._logger import _setup_child_logger
 from e3sm_to_cmip.mpas import write_netcdf
 from e3sm_to_cmip.util import print_message, setup_cmor
 
-logger = _setup_logger(__name__)
+logger = _setup_child_logger(__name__)
 
 # list of raw variable names needed
 RAW_VARIABLES = [str("area")]

e3sm_to_cmip/cmor_handlers/vars/clisccp.py

@@ -13,10 +13,10 @@
 import numpy as np
 import xarray as xr
 
-from e3sm_to_cmip._logger import _setup_logger
+from e3sm_to_cmip._logger import _setup_child_logger
 from e3sm_to_cmip.util import print_message, setup_cmor
 
-logger = _setup_logger(__name__)
+logger = _setup_child_logger(__name__)
 
 # list of raw variable names needed
 RAW_VARIABLES = [str("FISCCP1_COSP")]

e3sm_to_cmip/cmor_handlers/vars/orog.py

@@ -13,11 +13,11 @@
 import xarray as xr
 
 from e3sm_to_cmip import resources
-from e3sm_to_cmip._logger import _setup_logger
+from e3sm_to_cmip._logger import _setup_child_logger
 from e3sm_to_cmip.mpas import write_netcdf
 from e3sm_to_cmip.util import print_message, setup_cmor
 
-logger = _setup_logger(__name__)
+logger = _setup_child_logger(__name__)
 
 # list of raw variable names needed
 RAW_VARIABLES = [str("PHIS")]

e3sm_to_cmip/cmor_handlers/vars/sftlf.py

@@ -13,11 +13,11 @@
 import xarray as xr
 
 from e3sm_to_cmip import resources
-from e3sm_to_cmip._logger import _setup_logger
+from e3sm_to_cmip._logger import _setup_child_logger
 from e3sm_to_cmip.mpas import write_netcdf
 from e3sm_to_cmip.util import print_message, setup_cmor
 
-logger = _setup_logger(__name__)
+logger = _setup_child_logger(__name__)
 
 # list of raw variable names needed
 RAW_VARIABLES = [str("LANDFRAC")]

e3sm_to_cmip/mpas.py

@@ -728,7 +728,7 @@ def _compute_moc_time_series(
     lat_bnds = np.zeros((len(lat) - 1, 2))
     lat_bnds[:, 0] = lat[0:-1]
     lat_bnds[:, 1] = lat[1:]
-    lat = 0.5 * (lat_bnds[:, 0] + lat_bnds[:, 1])
+    lat = 0.5 * (lat_bnds[:, 0] + lat_bnds[:, 1])  # type: ignore
 
     lat_bnds = xarray.DataArray(lat_bnds, dims=("lat", "nbnd"))  # type: ignore
     lat = xarray.DataArray(lat, dims=("lat",))  # type: ignore

e3sm_to_cmip/util.py

@@ -14,9 +14,9 @@
 import yaml
 from tqdm import tqdm
 
-from e3sm_to_cmip._logger import _setup_logger
+from e3sm_to_cmip._logger import _setup_child_logger
 
-logger = _setup_logger(__name__)
+logger = _setup_child_logger(__name__)
 
 
 ATMOS_TABLES = [
@@ -50,6 +50,7 @@
 
 
 def print_debug(e):
+    # TODO: Deprecate this function. We use Python logger now.
     _, _, tb = sys.exc_info()
     traceback.print_tb(tb)
     print(e)
@@ -73,11 +74,16 @@ def print_message(message, status="error"):
     """
     Prints a message with either a green + or a red -
 
+    # TODO: Deprecate this function. We use Python logger now. Colors can't
+    # be captured in log files.
+
     Parameters:
         message (str): the message to print
-        status (str): th"""
+        status (str): the status message.
+    """
+
     if status == "error":
-        print(
+        logger.error(
             colors.FAIL
             + "[-] "
             + colors.ENDC
@@ -86,11 +92,11 @@ def print_message(message, status="error"):
             + colors.ENDC
         )
     elif status == "ok":
-        print(colors.OKGREEN + "[+] " + colors.ENDC + str(message))
+        logger.info(colors.OKGREEN + "[+] " + colors.ENDC + str(message))
     elif status == "info":
-        print(str(message))
+        logger.info(str(message))
     elif status == "debug":
-        print(
+        logger.info(
             colors.OKBLUE
             + "[*] "
             + colors.ENDC

tests/run_script.py

@@ -9,20 +9,25 @@
 NOTE: This script can only be executed on LCRC machines.
 """
 
-import datetime
+import os
 
 from e3sm_to_cmip.__main__ import main
 
 # The list of variables to process. Update as needed.
-VAR_LIST = (
-    "pfull, phalf, tas, ts, psl, ps, sfcWind, huss, pr, prc, prsn, evspsbl, tauu, "
-    "tauv, hfls, clt, rlds, rlus, rsds, rsus, hfss, cl, clw, cli, clivi, clwvi, prw, "
-    "rldscs, rlut, rlutcs, rsdt, rsuscs, rsut, rsutcs, rtmt, abs550aer, od550aer "
-    "rsdscs, hur"
-)
+# VAR_LIST = (
+#     "pfull, phalf, tas, ts, psl, ps, sfcWind, huss, pr, prc, prsn, evspsbl, tauu, "
+#     "tauv, hfls, clt, rlds, rlus, rsds, rsus, hfss, cl, clw, cli, clivi, clwvi, prw, "
+#     "rldscs, rlut, rlutcs, rsdt, rsuscs, rsut, rsutcs, rtmt, abs550aer, od550aer "
+#     "rsdscs, hur"
+# )1
+
+VAR_LIST = "pfull, phalf, tas"
 
 # The output path for CMORized datasets. Update as needed.
-OUTPUT_PATH = f"../qa/run_{datetime.datetime.now().strftime('%Y%m%d_%H%M%S')}"
+OUTPUT_PATH = (
+    "/lcrc/group/e3sm/public_html/e3sm_to_cmip/feature-274-redesign-logger-info"
+)
+
 
 args = [
     "--var-list",
@@ -35,9 +40,17 @@
     "/lcrc/group/e3sm/e3sm_to_cmip/cmip6-cmor-tables/Tables/",
     "--user-metadata",
     "/lcrc/group/e3sm/e3sm_to_cmip/CMIP6-Metadata/template.json",
-    "--serial",
+    "--info",
 ]
 
 # `main()` creates an `E3SMtoCMIP` object and passes `args` to it, which sets
 # the object parameters to execute a run.
 main(args)
+
+# Ensure the path and its contents have the correct permissions recursively
+for root, dirs, files in os.walk(OUTPUT_PATH):
+    os.chmod(root, 0o505)  # o=rx (read and execute for others)
+    for d in dirs:
+        os.chmod(os.path.join(root, d), 0o505)
+    for f in files:
+        os.chmod(os.path.join(root, f), 0o404)  # o=r (read for others)