Redesign the logger module to unify structure and remove repeated messages

[TonyB9000]

Description

• Closes [Feature]: Redesign logger module #274
• Closes e3sm_to_cmip --help creates a logs directory #220

Requirements

1. Does not repeat logger messaging across handlers, modules, etc.
2. --help and --version do not create the log directory

Checklist

• My code follows the style guidelines of this project
• I have performed a self-review of my own code
• My changes generate no new warnings
• Any dependent changes have been merged and published in downstream modules

If applicable:

• New and existing unit tests pass with my changes (locally and CI/CD build)
• I have added tests that prove my fix is effective or that my feature works
• I have commented my code, particularly in hard-to-understand areas
• I have made corresponding changes to the documentation
• I have noted that this is a breaking change for a major release (fix or feature that would cause existing functionality to not work as expected)

[TonyB9000]

@tomvothecoder @chengzhuzhang Can you do another review here? The code was pushed after rebasing with xylar's fix to the mpas 3D-masking issue. Module tests seem to be failing do to "logger" not defined (but the function that defines it is called in main, and the code runs fine when run outside of these build tests.)

To avoid e2c creating "log" directories for "--help" and other such invocations, the "logger" established in each module (mpas.py, utils.py, etc) is enclosed in a "instantiate_xxx_logger" function call, so that it is not invoked merely when main imports the modules. I assume that by making main explicitly call each module's "instantiate_logger" function, the logger should become available to the function in each such module. Perhaps that is a mistaken notion. But I am satisfied with the logger behavior (no spurious dropped log-directories, no duplicated messages in the e2c logfiles, etc). However, it does not (yet) seem possible to merge the "cmor_logs" with other logs - perhaps because the "cmor.setup()" calls (which create their own logging) are called long after other logging is established. (We need to understand how the cmor modules sets up its own logging). We could try to make the root logfile directory "global" and pass its full path down to the cmor.setup calls - but time for such experiments is debatable at present.

P.S. For some reason, I cannot type into the "Description" field at the top of this page...

[tomvothecoder]

RE: Why there are 4 remaining modules in vars.py ->
https://github.com/E3SM-Project/e3sm_to_cmip/blob/master/e3sm_to_cmip/cmor_handlers/vars/README.md (note phalf and pfull no longer exist here)

[chengzhuzhang]

@TonyB9000 I think your PR addresses unified logging structure and removed repeated messages as intended. To better structure e2c logging with cmor logging will be addressed later. I will defer to @tomvothecoder to have another look for merging.

[TonyB9000]

cmor logging gets set-up when "cmor.setup" is called, and only exposes "logfile" (directory) name as a user-adjustable parameter. We need "e2c logging" to be set up much earlier to capture other messages, and I prefer that log to have a unique timestamp in the name (so it does not get clobbered by subsequent e2c invocations.) We could make that invocation-specific logfile a global variable, so it can be supplied to cmor.setup as a parameter. However, I mildly despise the cmor log message format (needlessly verbose with border banners, reverse background colors, impenetrable to automated parsing, etc) and would resist incorporating it with any other logging until reformatted (or formatting control by the user is supported.)

[tomvothecoder]

My changes

A changes I've made in commit.

1. Made the _logger() default log level logging.INFO to not have to call from logging import INFO or from _logger import INFO
2. Renamed e2c_logger() back to _logger() and update references -- no more clashing imports due to 1. above
3. Removed custom instantiations of INFO, DEBUG, etc. from _logger.py
4. Updated _logger() docstrings and type annotations

Next steps

I want to fix the issue of repeated loggers without needing to instantiate or override global logger. I find it confusing to instantiate/override global logger because it is hard to tell when/where this logger is being referenced. There should be a way to appropriately propagate messages from each of the logger handlers without having them repeat.

Also, mypy is throwing many errors related to the logger variable not being defined in various modules. I assume this is because logger supposed to reference the global logger variable?

(e3sm_to_cmip_dev) vo13@ml-5556678 e3sm_to_cmip % pre-commit run --all-files
trim trailing whitespace.................................................Passed
fix end of files.........................................................Passed
check yaml...............................................................Passed
ruff-sort-imports........................................................Passed
ruff.....................................................................Passed
ruff-format..............................................................Passed
mypy.............................                      ...Failed
- hook id: mypy
- exit code: 1

e3sm_to_cmip/_logger.py:51: error: Cannot resolve name "logger" (possible cyclic definition)  [misc]
e3sm_to_cmip/_logger.py:51: note: Recursive types are not allowed at function scope
e3sm_to_cmip/util.py:23: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/util.py:500: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/util.py:510: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/util.py:526: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/util.py:550: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/util.py:559: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/util.py:569: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/util.py:643: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/util.py:647: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/util.py:660: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/handler.py:21: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/handler.py:212: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/handler.py:242: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/handler.py:250: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/handler.py:273: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/handler.py:296: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/handler.py:338: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/handler.py:680: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/handler.py:684: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/handler.py:694: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/handler.py:697: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/handler.py:707: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/utils.py:22: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/utils.py:80: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/utils.py:122: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/utils.py:217: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/cmor_handlers/utils.py:223: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:109: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:154: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:155: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:156: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:157: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:158: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:159: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:160: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:161: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:162: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:214: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:229: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:230: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:231: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:233: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:239: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:243: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:660: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:661: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:662: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:744: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:764: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:765: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:766: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:823: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:848: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:851: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:863: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:946: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:948: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:957: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:961: error: Name "logger" is not defined  [name-defined]
e3sm_to_cmip/__main__.py:962: error: Name "logger" is not defined  [name-defined]
Found 61 errors in 5 files (checked 65 source files)

[tomvothecoder]

Instead of instantiating global logger, we should have a conditional that checks if --help/--version is called and not create the default logfile directory.

[TonyB9000]

@tomvothecoder Right. Originally, the "setup_logger" functions were global to modules like mpas.py, and would get executed by main: import mpas.py, LONG before arg-parsing happens. So, the log-directory gets created before arg-parsing occurs.

[tomvothecoder]

I'm creating a generic Python run script to test the changes in this PR. This run script can be used in future PRs as well. It should allow contributors and reviewers to "test" code changes in a standardized way. Otherwise, making our own run scripts to reproduce results can be time-consuming for PR reviews.

#283