Revamp logger module for additional features and bug fixes #924
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
|
@tomvothecoder Another thing that bothers me a little, is that the e3sm_diags_run.log file was created in the directory where the run script is located, I'm wondering if it makes more sense to have it initiate under |
tomvothecoder
changed the title
Run() objectRun() object and fix logger not including full traceback
I agree, it makes sense to store the log immediately in the To achieve this, we need to find a way to pass the |
- Saves log file directly to `prov` dir - Fix issue where complete log output not being printed to logfile - Add feature to print diagnostic run information at the top of the logger output
tomvothecoder
changed the title
Run() object and fix logger not including full traceback- Update `custom_logger()` to not add StreamHandler and instead inherit from the root logger - Fix `Run.run_diags()` to properly setup the provenance directory before creating the log file to avoid FileNotFoundError
9 tasks
tomvothecoder
commented
Jan 27, 2025
There was a problem hiding this comment.
Hi @chengzhuzhang, this PR is ready for review.
The PR description includes the summary of changes. Hoping this makes logging much more robust and predictable.
Comment on lines
+9
to
+37
| LOG_FORMAT = ( | ||
| "%(asctime)s [%(levelname)s]: %(filename)s(%(funcName)s:%(lineno)s) >> %(message)s" | ||
| ) | ||
| LOG_FILEMODE = "w" | ||
| LOG_LEVEL = logging.INFO | ||
|
|
||
|
|
||
| # Setup the root logger with a default log file. | ||
| # `force` is set to `True` to automatically remove root handlers whenever | ||
| # `basicConfig` called. This is required for cases where multiple e3sm_diags | ||
| # runs are executed. Otherwise, the logger objects attempt to share the same | ||
| # root file reference (which gets deleted between runs), resulting in | ||
| # `FileNotFoundError: [Errno 2] No such file or directory: 'e3sm_diags_run.log'`. | ||
| # More info here: https://stackoverflow.com/a/49202811 | ||
| logging.basicConfig( | ||
| format=LOG_FORMAT, | ||
| filename=LOG_FILENAME, | ||
| filemode=LOG_FILEMODE, | ||
| level=LOG_LEVEL, | ||
| force=True, | ||
| ) | ||
| logging.captureWarnings(True) | ||
|
|
||
| # Add a console handler to display warnings in the console. This is useful | ||
| # for when other package loggers raise warnings (e.g, NumPy, Xarray). | ||
| console_handler = logging.StreamHandler() | ||
| console_handler.setLevel(logging.INFO) | ||
| console_handler.setFormatter(logging.Formatter(LOG_FORMAT)) | ||
| logging.getLogger().addHandler(console_handler) |
There was a problem hiding this comment.
Instead of configuring the root logger handler every time custom_logger() is called, we configure it once here.
We also add a single console handler that handles all console outputs, rather than adding it to every child logger in custom_logger() (which might cause duplicate messages I think).
Comment on lines
+94
to
+119
| def _update_root_logger_filepath_to_prov_dir(log_path: str): | ||
| """Updates the log file path to the provenance directory. | ||
|
|
||
| This method changes the log file path to a subdirectory named 'prov' | ||
| within the given results directory. It updates the filename of the | ||
| existing file handler to the new path. | ||
|
|
||
| Parameters | ||
| ---------- | ||
| log_path : str | ||
| The path to the log file, which is stored in the `results_dir` | ||
| sub-directory called "prov". | ||
|
|
||
| Notes | ||
| ----- | ||
| - The method assumes that a logging file handler is already configured. | ||
| - The log file is closed and reopened at the new location. | ||
| - The log file mode is determined by the constant `LOG_FILEMODE`. | ||
| - The log file name is determined by the constant `LOG_FILENAME`. | ||
| """ | ||
| for handler in logging.root.handlers: | ||
| if isinstance(handler, logging.FileHandler): | ||
| handler.baseFilename = log_path | ||
| handler.stream.close() | ||
| handler.stream = open(log_path, LOG_FILEMODE) # type: ignore | ||
| break |
There was a problem hiding this comment.
This function updates the path of the root logger to the {results_dir}/prov.
Comment on lines
+92
to
+98
| # Make the provenance directory to store the log file. | ||
| prov_dir = os.path.join(params[0].results_dir, "prov") | ||
| pathlib.Path(prov_dir).mkdir(parents=True, exist_ok=True) | ||
|
|
||
| log_dir = os.path.join(prov_dir, LOG_FILENAME) | ||
| _update_root_logger_filepath_to_prov_dir(log_dir) | ||
| self._log_diagnostic_run_info(log_dir) |
There was a problem hiding this comment.
The core change in run_diags(). First, create the prov dir, then update the path of the root logger to the log_dir, then print out the diagnostic info.
Comment on lines
+113
to
+166
| def _log_diagnostic_run_info(self, log_path: str): | ||
| """Logs information about the diagnostic run. | ||
|
|
||
| This method is useful for tracking the provenance of the diagnostic run | ||
| and understanding the context of the diagnostic results. | ||
|
|
||
| It logs the following information: | ||
| - Timestamp of the run | ||
| - Version information (Git branch and commit hash or module version) | ||
|
|
||
| Parameters | ||
| ---------- | ||
| log_path : str | ||
| The path to the log file, which is stored in the `results_dir` | ||
| sub-directory called "prov". | ||
|
|
||
| Notes | ||
| ----- | ||
| The version information is retrieved from the current Git branch and | ||
| commit hash. If the Git information is not available, it falls back | ||
| to the version defined in the `e3sm_diags` module. | ||
| """ | ||
| timestamp = datetime.now().strftime("%Y-%m-%d %H:%M:%S") | ||
|
|
||
| try: | ||
| branch_name = ( | ||
| subprocess.check_output( | ||
| ["git", "rev-parse", "--abbrev-ref", "HEAD"], | ||
| cwd=os.path.dirname(__file__), | ||
| ) | ||
| .strip() | ||
| .decode("utf-8") | ||
| ) | ||
| commit_hash = ( | ||
| subprocess.check_output( | ||
| ["git", "rev-parse", "HEAD"], cwd=os.path.dirname(__file__) | ||
| ) | ||
| .strip() | ||
| .decode("utf-8") | ||
| ) | ||
| version_info = f"branch {branch_name} with commit {commit_hash}" | ||
| except subprocess.CalledProcessError: | ||
| version_info = f"version {e3sm_diags.__version__}" | ||
|
|
||
| logger.info( | ||
| f"\n{'=' * 80}\n" | ||
| f"E3SM Diagnostics Run\n" | ||
| f"{'-' * 20}\n" | ||
| f"Timestamp: {timestamp}\n" | ||
| f"Version Info: {version_info}\n" | ||
| f"Log Filepath: {log_path}\n" | ||
| f"{'=' * 80}\n" | ||
| ) | ||
|
|
There was a problem hiding this comment.
Example output with git branch printed at the top of the traceback.
2025-01-27 14:53:26,245 [INFO]: run.py(_log_diagnostic_run_info:152) >>
================================================================================
E3SM Diagnostics Run
--------------------
Timestamp: 2025-01-27 14:53:26
Version Info: branch bug/848-log with commit a96b1de892aa8a013288c3de9a11471db647c25b
Log Filepath: /lcrc/group/e3sm/public_html/cdat-migration-fy24/909-prov-log/prov/e3sm_diags_run.log
================================================================================
Comment on lines
+30
to
+48
| # Get the current machine's configuration info. | ||
| MACHINE_INFO = MachineInfo() | ||
| MACHINE = MACHINE_INFO.machine | ||
|
|
||
| if MACHINE not in [ | ||
| "anvil", | ||
| "chrysalis", | ||
| "compy", | ||
| "pm-cpu", | ||
| "cori-haswell", | ||
| "cori-knl", | ||
| ]: | ||
| raise ValueError(f"e3sm_diags is not supported on this machine ({MACHINE}).") | ||
|
|
||
| # The location where results will be stored based on your branch changes. | ||
| BASE_RESULTS_DIR = "/global/cfs/cdirs/e3sm/www/cdat-migration-fy24/" | ||
| if MACHINE in ["chrysalis", "anvil"]: | ||
| BASE_RESULTS_DIR = "/lcrc/group/e3sm/public_html/cdat-migration-fy24/" | ||
| elif MACHINE in ["cori-haswell", "cori-knl", "pm-cpu"]: | ||
| BASE_RESULTS_DIR = "/global/cfs/cdirs/e3sm/www/cdat-migration-fy24/" |
There was a problem hiding this comment.
Updated the base_run_script to support LCRC too because perlmutter is down right now.
tomvothecoder
commented
Jan 27, 2025
Comment on lines
+113
to
+166
| def _log_diagnostic_run_info(self, log_path: str): | ||
| """Logs information about the diagnostic run. | ||
|
|
||
| This method is useful for tracking the provenance of the diagnostic run | ||
| and understanding the context of the diagnostic results. | ||
|
|
||
| It logs the following information: | ||
| - Timestamp of the run | ||
| - Version information (Git branch and commit hash or module version) | ||
|
|
||
| Parameters | ||
| ---------- | ||
| log_path : str | ||
| The path to the log file, which is stored in the `results_dir` | ||
| sub-directory called "prov". | ||
|
|
||
| Notes | ||
| ----- | ||
| The version information is retrieved from the current Git branch and | ||
| commit hash. If the Git information is not available, it falls back | ||
| to the version defined in the `e3sm_diags` module. | ||
| """ | ||
| timestamp = datetime.now().strftime("%Y-%m-%d %H:%M:%S") | ||
|
|
||
| try: | ||
| branch_name = ( | ||
| subprocess.check_output( | ||
| ["git", "rev-parse", "--abbrev-ref", "HEAD"], | ||
| cwd=os.path.dirname(__file__), | ||
| ) | ||
| .strip() | ||
| .decode("utf-8") | ||
| ) | ||
| commit_hash = ( | ||
| subprocess.check_output( | ||
| ["git", "rev-parse", "HEAD"], cwd=os.path.dirname(__file__) | ||
| ) | ||
| .strip() | ||
| .decode("utf-8") | ||
| ) | ||
| version_info = f"branch {branch_name} with commit {commit_hash}" | ||
| except subprocess.CalledProcessError: | ||
| version_info = f"version {e3sm_diags.__version__}" | ||
|
|
||
| logger.info( | ||
| f"\n{'=' * 80}\n" | ||
| f"E3SM Diagnostics Run\n" | ||
| f"{'-' * 20}\n" | ||
| f"Timestamp: {timestamp}\n" | ||
| f"Version Info: {version_info}\n" | ||
| f"Log Filepath: {log_path}\n" | ||
| f"{'=' * 80}\n" | ||
| ) | ||
|
|
There was a problem hiding this comment.
Example output with git branch printed at the top of the traceback.
2025-01-27 14:53:26,245 [INFO]: run.py(_log_diagnostic_run_info:152) >>
================================================================================
E3SM Diagnostics Run
--------------------
Timestamp: 2025-01-27 14:53:26
Version Info: branch bug/848-log with commit a96b1de892aa8a013288c3de9a11471db647c25b
Log Filepath: /lcrc/group/e3sm/public_html/cdat-migration-fy24/909-prov-log/prov/e3sm_diags_run.log
================================================================================
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Description
Log File Handling:
provdirectory (parameter.results_dir) upon callingrun_diags()instead of moving them at the end (Closes [Bug]:e3sm_diags_run.logwas not properly generated #848).Diagnostic Run Information:
Logger Fixes and Improvements:
provlog doesn't include complete traceback #909).wfor both outputs.Test file used
Results: Log now prints all output, log + console outputs align, and no repeated messages. Works with serial and multiprocessing, and multiple simulations in a for-loop.
Example log file output (https://web.lcrc.anl.gov/public/e3sm/cdat-migration-fy24/909-prov-log/prov/e3sm_diags_run.log)
Example console output (matches log file)
Checklist
If applicable:
Additional Info
https://docs.python.org/3/library/logging.html#logging.basicConfig