From eef76a58fc403352814287da8e8804a98faa793c Mon Sep 17 00:00:00 2001 From: Benjamin Rodenberg Date: Wed, 21 Oct 2026 17:44:03 +0200 Subject: [PATCH] Log to the console on rank 0 only in parallel runs Every rank printed every message, so a run on N ranks repeated each line N times. Ranks other than 0 now only log warnings and errors to the console; log files per rank keep the full level. print_time logs instead of printing. Taken from ade4fba of #197. Assisted-by: Claude Code:claude-opus-5-5 --- CHANGELOG.md | 1 + src/ebfm/core/LOOP_general_functions.py | 9 ++- src/ebfm/core/cli.py | 3 +- src/ebfm/core/logger.py | 4 +- tests/core/test_logger.py | 93 +++++++++++++++++++++++++ 5 files changed, 105 insertions(+), 5 deletions(-) create mode 100644 tests/core/test_logger.py diff --git a/CHANGELOG.md b/CHANGELOG.md index 1fe9ec86..f5bf9239 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -25,6 +25,7 @@ SPDX-License-Identifier: CC-BY-4.0 * Without `--random-seed`, rank 0 now draws the random seed and shares it with all ranks, so the random forcing is the same over the whole domain. Each rank previously drew its own. * `--dump-reference` now holds the columns of all ranks, ordered by Elmer element id. Every rank previously wrote its own partition to the same file. * `--print-diagnostics` now reports the column count and `smb` statistics of the whole domain, logged by rank 0. Each rank previously reported its own partition. +* In a run on several MPI ranks, only rank 0 logs to the console at `--log-level-console`; the other ranks only log warnings and errors there, instead of repeating every message. Log files (`--log-file`, one per rank) are unchanged. The current model time is logged instead of printed. https://github.com/EBFMorg/EBFM/pull/204 # v0.8.0 diff --git a/src/ebfm/core/LOOP_general_functions.py b/src/ebfm/core/LOOP_general_functions.py index 0112b94d..c415366e 100644 --- a/src/ebfm/core/LOOP_general_functions.py +++ b/src/ebfm/core/LOOP_general_functions.py @@ -3,6 +3,9 @@ # SPDX-License-Identifier: BSD-3-Clause from datetime import datetime, timedelta +import logging + +logger = logging.getLogger(__name__) def is_first_time_step(t: int) -> bool: @@ -34,7 +37,7 @@ def is_final_time_step(t: int, time: dict) -> bool: def print_time(t: int, ts: datetime, dt: float) -> datetime: """ - Sets time parameters and prints the current model time to the screen. + Sets time parameters and logs the current model time. Parameters: t (int): Current time step. @@ -50,8 +53,8 @@ def print_time(t: int, ts: datetime, dt: float) -> datetime: # Extract year, month, day, and hour from the current time tempdate = t_cur.timetuple() - # Print the current time parameters - print( + # Log the current time parameters + logger.info( f"Year: {tempdate.tm_year:4d} " f"Month: {tempdate.tm_mon:2d} " f"Day: {tempdate.tm_mday:2d} " diff --git a/src/ebfm/core/cli.py b/src/ebfm/core/cli.py index 7a2c4f97..2ecdfc19 100644 --- a/src/ebfm/core/cli.py +++ b/src/ebfm/core/cli.py @@ -356,7 +356,8 @@ def parse_time_step(value: str) -> float | str: type=str, choices=list(log_levels_map.keys()), default=CliDefaults.LOG_LEVEL_CONSOLE.value, - help="Log level for console output for all MPI ranks (unless overridden by custom settings in utils.py).", + help="Log level for console output. In runs on several MPI ranks, it applies to rank 0; the other ranks " + "only log warnings and errors to the console.", ) logger_group.add_argument( diff --git a/src/ebfm/core/logger.py b/src/ebfm/core/logger.py index fbfe185e..16e9162c 100644 --- a/src/ebfm/core/logger.py +++ b/src/ebfm/core/logger.py @@ -39,7 +39,7 @@ def setup_logging( """ Setup logging for EBFM with MPI support. - @param stdout_log_level: Log level for stdout + @param stdout_log_level: Log level for stdout of rank 0. Other ranks of a parallel run log warnings and errors only. @param stdout_individual_log_levels: Dictionary mapping MPI ranks to their desired log levels for console output. @param comm: MPI communicator to use for determining rank and size. If None, comm defaults to MPI.COMM_WORLD when MPI support is available, or a serial (rank 0, size 1) stub otherwise. @@ -84,6 +84,8 @@ def setup_logging( if comm.rank in stdout_individual_log_levels.keys(): # check for custom log level for this rank use_level = stdout_individual_log_levels[comm.rank] + elif comm.rank != 0: # other ranks would repeat most messages of rank 0 + use_level = max(stdout_log_level, logging.WARNING) else: # use general log level if no individual log level is defined for this rank use_level = stdout_log_level diff --git a/tests/core/test_logger.py b/tests/core/test_logger.py new file mode 100644 index 00000000..69afb8d1 --- /dev/null +++ b/tests/core/test_logger.py @@ -0,0 +1,93 @@ +# SPDX-FileCopyrightText: 2026 EBFM Authors +# +# SPDX-License-Identifier: BSD-3-Clause +# +# This file was generated with the help of AI tools. + +"""Tests for the console log level that setup_logging() gives each MPI rank.""" + +import io +import logging +import unittest +from contextlib import redirect_stderr, redirect_stdout + +from ebfm.core.logger import setup_logging + + +class _FakeComm: + def __init__(self, rank: int, size: int): + self.rank = rank + self.size = size + + +class TestSetupLoggingConsoleLevel(unittest.TestCase): + def _console_levels(self, rank: int, size: int, **kwargs) -> tuple[set[int], set[int]]: + """Set up logging on the given rank, log one message per level and return the levels on stdout and stderr.""" + root = logging.getLogger() + saved_handlers, saved_level = list(root.handlers), root.level + root.handlers.clear() + stdout, stderr = io.StringIO(), io.StringIO() + try: + with redirect_stdout(stdout), redirect_stderr(stderr): + setup_logging(comm=_FakeComm(rank, size), **kwargs) + for level in (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR): + logging.getLogger("ebfm.test_logger").log(level, "message") + finally: + for handler in list(root.handlers): + root.removeHandler(handler) + handler.close() + root.handlers.extend(saved_handlers) + root.setLevel(saved_level) + + def levels(text: str) -> set[int]: + return {logging.getLevelName(name) for name in ("DEBUG", "INFO", "WARNING", "ERROR") if f" {name} " in text} + + return levels(stdout.getvalue()), levels(stderr.getvalue()) + + def test_console_level_per_rank(self): + cases = { + "serial run": dict(rank=0, size=1, stdout_log_level=logging.INFO, expected=logging.INFO), + "rank 0 of a parallel run": dict(rank=0, size=4, stdout_log_level=logging.INFO, expected=logging.INFO), + "rank 0 at DEBUG": dict(rank=0, size=4, stdout_log_level=logging.DEBUG, expected=logging.DEBUG), + "other rank": dict(rank=2, size=4, stdout_log_level=logging.INFO, expected=logging.WARNING), + "other rank, DEBUG raised to WARNING": dict( + rank=2, size=4, stdout_log_level=logging.DEBUG, expected=logging.WARNING + ), + "other rank, ERROR kept": dict(rank=2, size=4, stdout_log_level=logging.ERROR, expected=logging.ERROR), + "individual level of other rank": dict( + rank=2, + size=4, + stdout_log_level=logging.INFO, + stdout_individual_log_levels={2: logging.DEBUG}, + expected=logging.DEBUG, + ), + "individual level of rank 0": dict( + rank=0, + size=4, + stdout_log_level=logging.INFO, + stdout_individual_log_levels={0: logging.WARNING}, + expected=logging.WARNING, + ), + "individual level for a different rank": dict( + rank=1, + size=4, + stdout_log_level=logging.INFO, + stdout_individual_log_levels={2: logging.DEBUG}, + expected=logging.WARNING, + ), + } + for name, case in cases.items(): + with self.subTest(name): + case = dict(case) + expected = case.pop("expected") + case.setdefault("stdout_individual_log_levels", {}) + stdout_levels, stderr_levels = self._console_levels(**case) + self.assertEqual( + stdout_levels, + {level for level in (logging.DEBUG, logging.INFO, logging.WARNING) if level >= expected}, + ) + self.assertEqual(stderr_levels, {logging.ERROR}) + + +if __name__ == "__main__": + unittest.main()