Redesign the logger module to unify structure and remove repeated messages

e3sm_to_cmip/__main__.py

@@ -21,8 +21,8 @@
 import yaml
 from tqdm import tqdm
 
-from e3sm_to_cmip import ROOT_HANDLERS_DIR, __version__, resources
-from e3sm_to_cmip._logger import _setup_logger, _setup_root_logger
+from e3sm_to_cmip import ROOT_HANDLERS_DIR, __version__, _logger, resources
+from e3sm_to_cmip.cmor_handlers.handler import instantiate_handler_logger
 from e3sm_to_cmip.cmor_handlers.utils import (
     MPAS_REALMS,
     REALMS,
@@ -31,6 +31,7 @@
     Realm,
     _get_mpas_handlers,
     derive_handlers,
+    instantiate_h_utils_logger,
     load_all_handlers,
 )
 from e3sm_to_cmip.util import (
@@ -41,6 +42,7 @@
     find_atm_files,
     find_mpas_files,
     get_handler_info_msg,
+    instantiate_util_logger,
     precheck,
     print_debug,
     print_message,
@@ -51,11 +53,6 @@
 warnings.filterwarnings("ignore")
 
 
-# Setup the root logger and this module's logger.
-log_filename = _setup_root_logger()
-logger = _setup_logger(__name__, propagate=True)
-
-
 @dataclass
 class CLIArguments:
     """A data class storing the command line arguments for e3sm_to_cmip.
@@ -98,9 +95,19 @@ class CLIArguments:
 
 class E3SMtoCMIP:
     def __init__(self, args: Optional[List[str]] = None):
+        # logger assignment is moved into __init__ AFTER the call to _parse_args
+        # to prevent the default logfile directory being created whenever a call
+        # to "--help" or "--version" is invoked.  Doing so, however, makes the
+        # logger unavailable to the functions in this class unless made global.
+        global logger
+
         # A dictionary of command line arguments.
         parsed_args = self._parse_args(args)
 
+        # Setup this module's logger AFTER args are parsed in __init__, so that
+        # default log file is NOT created for "--help" or "--version" calls.
+        logger = _logger._logger(name=__name__, to_logfile=True)
+
         # NOTE: The order of these attributes align with class CLIArguments.
         # ======================================================================
         # Run Mode settings.
@@ -141,6 +148,9 @@ def __init__(self, args: Optional[List[str]] = None):
         if self.precheck_path is not None:
             self._run_precheck()
 
+        self.handlers = self._get_handlers()
+
+    def print_config(self):
         logger.info("--------------------------------------")
         logger.info("| E3SM to CMIP Configuration")
         logger.info("--------------------------------------")
@@ -150,28 +160,24 @@ def __init__(self, args: Optional[List[str]] = None):
         logger.info(f"    * precheck_path='{self.precheck_path}'")
         logger.info(f"    * freq='{self.freq}'")
         logger.info(f"    * realm='{self.realm}'")
-        logger.info(f"    * Writing log output file to: {log_filename}")
-
-        self.handlers = self._get_handlers()
 
     def run(self):
-        # Setup logger information and print out e3sm_to_cmip CLI arguments.
+        # If info_mode, call and then exit.
         # ======================================================================
-        if self.output_path is not None:
-            self.new_metadata_path = os.path.join(
-                self.output_path, "user_metadata.json"
-            )
+        if self.info_mode:
+            self._run_info_mode()
+            sys.exit(0)
 
         # Setup directories using the CLI argument paths (e.g., output dir).
         # ======================================================================
-        if not self.info_mode:
-            self._setup_dirs_with_paths()
+        self._setup_dirs_with_paths()
 
-        # Run e3sm_to_cmip with info mode.
+        # Set new metadata path if output path was provided.
         # ======================================================================
-        if self.info_mode:
-            self._run_info_mode()
-            sys.exit(0)
+        if self.output_path is not None:
+            self.new_metadata_path = os.path.join(
+                self.output_path, "user_metadata.json"
+            )
 
         # Run e3sm_to_cmip to CMORize serially or in parallel.
         # ======================================================================
@@ -229,6 +235,10 @@ def _get_handlers(self):
             elif self.realm in MPAS_REALMS:
                 handlers = _get_mpas_handlers(self.var_list)
 
+            else:
+                logger.error(f"No such realm: {self.realm}")
+                sys.exit(0)
+
             if len(handlers) == 0:
                 logger.error(
                     "No CMIP6 variable handlers were derived from the variables found "
@@ -960,7 +970,15 @@ def _timeout_exit(self):
 
 def main(args: Optional[List[str]] = None):
     app = E3SMtoCMIP(args)
-    app.run()
+
+    # These calls allow module loggers that create default logfiles to avoid being
+    # instantiated by arguments "--help" or "--version" upon import.
+    instantiate_util_logger()
+    instantiate_h_utils_logger()
+    instantiate_handler_logger()
+
+    app.print_config()
+    return app.run()
 
 
 if __name__ == "__main__":

e3sm_to_cmip/_logger.py

@@ -1,68 +1,70 @@
+from __future__ import annotations
+
 import logging
 import os
-import time
-from datetime import datetime
-
-from pytz import UTC
+from datetime import datetime, timezone
 
+DEFAULT_LOG_LEVEL = logging.INFO
+DEFAULT_LOG_DIR = "e2c_logs"
+DEFAULT_LOGPATH = f"{DEFAULT_LOG_DIR}/e2c_root_log-{datetime.now(timezone.utc).strftime('%Y%m%d_%H%M%S_%f')}.log"
 
-def _setup_root_logger() -> str:  # pragma: no cover
-    """Sets up the root logger.
+# Logger message and date formats.
+MSGFMT = "%(asctime)s_%(msecs)03d:%(levelname)s:%(name)s:%(funcName)s:%(message)s"
+DATEFMT = "%Y%m%d_%H%M%S"
 
-    The logger module will write to a log file and stream the console
-    simultaneously.
 
-    The log files are saved in a `/logs` directory relative to where
-    `e3sm_to_cmip` is executed.
+def _logger(
+    name: str | None = None,
+    log_filename: str = DEFAULT_LOGPATH,
+    log_level: int = DEFAULT_LOG_LEVEL,
+    to_console: bool = False,
+    to_logfile: bool = False,
+    propagate: bool = False,
+):
+    """Return a root or named logger with variable configuration.
 
-    Returns
-    -------
-    str
-        The name of the logfile.
+    Parameters
+    ----------
+    name : str | None
+        The name displayed for the logger in messages.
+        If name == None or name == "__main__", the root logger is returned
+    log_filename : str
+        If logfile handling is requested, any logfile may be specified.
+    log_level : LogLevel
+        Either logging.DEBUG (10), logging.INFO (20), logging.WARNING (30),
+        logging.ERROR (40), logging.CRITICAL (50), by default logging.INFO.
+    to_console : boolean
+        If True, a logging.StreamHandler is supplied, by default False.
+    to_logfile : boolean
+        If True, a logging.FileHandler is supplied, by default False.
+    propagate : boolean
+        If True, messages logged are propagated to the root logger, by default
+        False.
     """
-    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"
-
-    # Setup the logging module.
-    logging.basicConfig(
-        filename=filename,
-        format=log_format,
-        datefmt="%Y%m%d_%H%M%S",
-        level=logging.DEBUG,
-    )
-    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)
+    if to_logfile:
+        dn = os.path.dirname(log_filename)
+        if len(dn) and not os.path.exists(dn):
+            os.makedirs(dn)
 
-    return filename
+    if name is None or name == "__main__":
+        # FIXME: F821 Undefined name `logger`
+        logger = logger.root  # noqa: F821
+    else:
+        logger = logging.getLogger(name)
 
+    logger.propagate = propagate
+    logger.setLevel(log_level)
 
-def _setup_logger(name, propagate=True) -> logging.Logger:
-    """Sets up a logger object.
-
-    This function is intended to be used at the top-level of a module.
+    logger.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.
+    if to_console:
+        logStreamHandler = logging.StreamHandler()
+        logStreamHandler.setFormatter(logging.Formatter(MSGFMT, datefmt=DATEFMT))
+        logger.addHandler(logStreamHandler)
 
-    Returns
-    -------
-    logging.Logger
-        The logger.
-    """
-    logger = logging.getLogger(name)
-    logger.propagate = propagate
+    if to_logfile:
+        logFileHandler = logging.FileHandler(log_filename)
+        logFileHandler.setFormatter(logging.Formatter(MSGFMT, datefmt=DATEFMT))
+        logger.addHandler(logFileHandler)
 
     return logger

e3sm_to_cmip/cmor_handlers/handler.py

@@ -1,7 +1,6 @@
 from __future__ import annotations
 
 import json
-import logging
 import os
 from typing import Any, Dict, KeysView, List, Literal, Optional, Tuple, TypedDict
 
@@ -11,11 +10,16 @@
 import xcdat as xc
 import yaml
 
-from e3sm_to_cmip._logger import _setup_logger
+from e3sm_to_cmip import _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__)
+
+def instantiate_handler_logger():
+    global logger
+
+    logger = _logger._logger(name=__name__, to_logfile=True, propagate=True)
+
 
 # The names for valid hybrid sigma levels.
 HYBRID_SIGMA_LEVEL_NAMES = [
@@ -289,7 +293,7 @@ def _all_vars_have_filepaths(
         """
         for var, filepaths in vars_to_filespaths.items():
             if len(filepaths) == 0:
-                logging.error(f"{var}: Unable to find input files for {var}")
+                logger.error(f"{var}: Unable to find input files for {var}")
                 return False
 
         return True
@@ -331,7 +335,7 @@ def _setup_cmor_module(
         cmor.dataset_json(metadata_path)
         cmor.load_table(self.table)
 
-        logging.info(f"{var_name}: CMOR setup complete")
+        logger.info(f"{var_name}: CMOR setup complete")
 
     def _get_var_time_dim(self, table_path: str) -> str | None:
         """Get the CMIP variable's time dimension, if it exists.

e3sm_to_cmip/cmor_handlers/mpas_vars/areacello.py

@@ -2,11 +2,9 @@
 compute  Grid-Cell Area for Ocean Variables areacello
 """
 
-import logging
-
 import xarray
 
-from e3sm_to_cmip import mpas, util
+from e3sm_to_cmip import _logger, mpas, util
 from e3sm_to_cmip.util import print_message
 
 # 'MPAS' as a placeholder for raw variables needed
@@ -17,6 +15,8 @@
 VAR_UNITS = "m2"
 TABLE = "CMIP6_Ofx.json"
 
+logger = _logger._logger(name=__name__, to_logfile=True, propagate=False)
+
 
 def handle(infiles, tables, user_input_path, **kwargs):
     """
@@ -43,7 +43,7 @@ def handle(infiles, tables, user_input_path, **kwargs):
         return
 
     msg = "Starting {name}".format(name=__name__)
-    logging.info(msg)
+    logger.info(msg)
 
     meshFileName = infiles["MPAS_mesh"]
     mappingFileName = infiles["MPAS_map"]

e3sm_to_cmip/cmor_handlers/mpas_vars/fsitherm.py

@@ -4,11 +4,9 @@
 
 from __future__ import absolute_import, division, print_function
 
-import logging
-
 import xarray
 
-from e3sm_to_cmip import mpas, util
+from e3sm_to_cmip import _logger, mpas, util
 from e3sm_to_cmip.util import print_message
 
 # 'MPAS' as a placeholder for raw variables needed
@@ -19,6 +17,8 @@
 VAR_UNITS = "kg m-2 s-1"
 TABLE = "CMIP6_Omon.json"
 
+logger = _logger._logger(name=__name__, to_logfile=True, propagate=False)
+
 
 def handle(infiles, tables, user_input_path, **kwargs):
     """
@@ -44,7 +44,7 @@ def handle(infiles, tables, user_input_path, **kwargs):
         print_message(f"Simple CMOR output not supported for {VAR_NAME}", "error")
         return None
 
-    logging.info(f"Starting {VAR_NAME}")
+    logger.info(f"Starting {VAR_NAME}")
 
     mappingFileName = infiles["MPAS_map"]
     timeSeriesFiles = infiles["MPASO"]

e3sm_to_cmip/cmor_handlers/mpas_vars/hfds.py

@@ -4,11 +4,9 @@
 
 from __future__ import absolute_import, division, print_function
 
-import logging
-
 import xarray
 
-from e3sm_to_cmip import mpas, util
+from e3sm_to_cmip import _logger, mpas, util
 from e3sm_to_cmip.util import print_message
 
 # 'MPAS' as a placeholder for raw variables needed
@@ -19,6 +17,8 @@
 VAR_UNITS = "W m-2"
 TABLE = "CMIP6_Omon.json"
 
+logger = _logger._logger(name=__name__, to_logfile=True, propagate=False)
+
 
 def handle(infiles, tables, user_input_path, **kwargs):
     """
@@ -47,7 +47,7 @@ def handle(infiles, tables, user_input_path, **kwargs):
         print_message(f"Simple CMOR output not supported for {VAR_NAME}", "error")
         return None
 
-    logging.info(f"Starting {VAR_NAME}")
+    logger.info(f"Starting {VAR_NAME}")
 
     mappingFileName = infiles["MPAS_map"]
     timeSeriesFiles = infiles["MPASO"]