diff --git a/README.md b/README.md index 575303712..959e8af63 100644 --- a/README.md +++ b/README.md @@ -88,6 +88,12 @@ python openevolve-run.py examples/function_minimization/initial_program.py \ examples/function_minimization/evaluator.py \ --config examples/function_minimization/config.yaml \ --iterations 50 + +# Running several evolutions in parallel? Give each run a logger prefix so its +# log output is distinguishable (logs as "run1.openevolve.*") +python openevolve-run.py examples/function_minimization/initial_program.py \ + examples/function_minimization/evaluator.py \ + --logger-prefix run1 ``` **Note:** The example config uses Gemini by default, but you can use any OpenAI-compatible provider by modifying the `config.yaml`. See the [configs](configs/) for full configuration options. @@ -549,6 +555,10 @@ OpenEvolve offers extensive configuration for advanced users: max_iterations: 1000 random_seed: 42 # Full reproducibility +# Optional prefix for all logger names, e.g. "run1" logs as "run1.openevolve.*"; +# useful to tell apart log output from multiple concurrent runs +logger_prefix: "run1" + llm: # Ensemble configuration models: diff --git a/openevolve/cli.py b/openevolve/cli.py index d3eb61d3d..a0e5bd1e1 100644 --- a/openevolve/cli.py +++ b/openevolve/cli.py @@ -46,6 +46,15 @@ def parse_args() -> argparse.Namespace: default=None, ) + parser.add_argument( + "--logger-prefix", + help=( + "Optional prefix applied to all OpenEvolve logger names (e.g. 'run1' logs as " + "'run1.openevolve.*'), useful to tell apart log output from concurrent runs" + ), + default=None, + ) + parser.add_argument( "--checkpoint", help="Path to checkpoint directory to resume from (e.g., openevolve_output/checkpoints/checkpoint_50)", @@ -127,6 +136,12 @@ async def main_async() -> int: # Print keys only - values may contain secrets and end up in logs print(f"Using evaluator args keys: {sorted(config.evaluator.evaluator_args.keys())}") + # Apply logger prefix CLI override (issue #290); must happen before the + # OpenEvolve constructor runs _setup_logging + if args.logger_prefix: + config.logger_prefix = args.logger_prefix + print(f"Using logger prefix: {config.logger_prefix}") + # Create config object with command-line overrides if args.api_base or args.primary_model or args.secondary_model: # Apply command-line overrides diff --git a/openevolve/config.py b/openevolve/config.py index 2844e7f77..4fdab7998 100644 --- a/openevolve/config.py +++ b/openevolve/config.py @@ -437,6 +437,9 @@ class Config: checkpoint_interval: int = 100 log_level: str = "INFO" log_dir: Optional[str] = None + # Optional prefix applied to all OpenEvolve logger names (e.g. "run1" logs + # as "run1.openevolve.*"), useful to tell apart concurrent runs (issue #290) + logger_prefix: Optional[str] = None random_seed: Optional[int] = 42 language: str = None file_suffix: str = ".py" diff --git a/openevolve/controller.py b/openevolve/controller.py index b05200c45..b87fdf809 100644 --- a/openevolve/controller.py +++ b/openevolve/controller.py @@ -23,6 +23,7 @@ from openevolve.selection import IslandSelector from openevolve.utils.code_utils import extract_code_language from openevolve.utils.format_utils import format_improvement_safe, format_metrics_safe +from openevolve.utils.logging_utils import LoggerPrefixFilter logger = logging.getLogger(__name__) @@ -180,17 +181,32 @@ def _setup_logging(self) -> None: root_logger = logging.getLogger() root_logger.setLevel(getattr(logging, self.config.log_level)) + # Optional prefix for all logger names (issue #290): rewriting + # record.name at the handler level means every downstream module + # logger (created via logging.getLogger(__name__)) is prefixed too. + prefix_filter = None + if self.config.logger_prefix: + prefix_filter = LoggerPrefixFilter(self.config.logger_prefix) + # Add file handler log_file = os.path.join(log_dir, f"openevolve_{time.strftime('%Y%m%d_%H%M%S')}.log") file_handler = logging.FileHandler(log_file) file_handler.setFormatter( logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s") ) + if prefix_filter is not None: + file_handler.addFilter(prefix_filter) root_logger.addHandler(file_handler) # Add console handler console_handler = logging.StreamHandler() - console_handler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(message)s")) + console_format = "%(asctime)s - %(levelname)s - %(message)s" + if prefix_filter is not None: + # Include the (prefixed) logger name so console output is + # distinguishable across runs as well; default format is unchanged. + console_format = "%(asctime)s - %(name)s - %(levelname)s - %(message)s" + console_handler.addFilter(prefix_filter) + console_handler.setFormatter(logging.Formatter(console_format)) root_logger.addHandler(console_handler) logger.info(f"Logging to {log_file}") diff --git a/openevolve/utils/logging_utils.py b/openevolve/utils/logging_utils.py new file mode 100644 index 000000000..e9d885cf4 --- /dev/null +++ b/openevolve/utils/logging_utils.py @@ -0,0 +1,34 @@ +"""Logging helpers shared across OpenEvolve. + +Provides :class:`LoggerPrefixFilter`, a handler-level filter that rewrites +``record.name`` so every downstream module logger appears under a common +prefix. This lets users tell apart log output coming from multiple concurrent +``OpenEvolve`` runs (GitHub issue #290). +""" + +import logging +from typing import Optional + + +class LoggerPrefixFilter(logging.Filter): + """Rewrite ``record.name`` to live under a configured prefix. + + When installed on a handler, every record emitted through that handler is + renamed from e.g. ``openevolve.controller`` to + ``.openevolve.controller``. Formatters that include ``%(name)s`` + then show the prefixed name, which makes concurrent runs distinguishable + and greppable in shared log output. + + The filter is idempotent: names that already carry the prefix are left + untouched, so a record flowing through several handlers that share the + same filter instance is only prefixed once. + """ + + def __init__(self, prefix: Optional[str] = None) -> None: + super().__init__() + self.prefix = prefix or "" + + def filter(self, record: logging.LogRecord) -> bool: + if self.prefix and not record.name.startswith(self.prefix + "."): + record.name = f"{self.prefix}.{record.name}" + return True diff --git a/tests/test_logger_prefix.py b/tests/test_logger_prefix.py new file mode 100644 index 000000000..960611f19 --- /dev/null +++ b/tests/test_logger_prefix.py @@ -0,0 +1,144 @@ +""" +Tests for the optional logger prefix feature (GitHub issue #290). + +A run can set ``Config.logger_prefix`` (or pass ``--logger-prefix`` on the CLI); +a handler-level ``LoggerPrefixFilter`` then rewrites ``record.name`` so every +downstream module logger shows up under the prefix, making it possible to tell +apart log output from multiple concurrent runs. + +All tests are fully offline: ``LLMEnsemble``/``Evaluator`` are patched out and +only the constructor (which calls ``_setup_logging``) is exercised. +""" + +import glob +import io +import logging +import os +import shutil +import tempfile +import unittest +from unittest.mock import patch + +from openevolve.config import Config +from openevolve.controller import OpenEvolve +from openevolve.utils.logging_utils import LoggerPrefixFilter + + +def _make_record(name: str) -> logging.LogRecord: + return logging.LogRecord(name, logging.INFO, "path", 1, "msg", None, None) + + +class TestLoggerPrefixFilter(unittest.TestCase): + """Unit tests for LoggerPrefixFilter""" + + def test_filter_rewrites_record_name(self): + filt = LoggerPrefixFilter("run1") + record = _make_record("openevolve.controller") + self.assertTrue(filt.filter(record)) + self.assertEqual(record.name, "run1.openevolve.controller") + + def test_filter_is_idempotent(self): + # The same record object flows through every handler attached to the + # logger, so applying the filter twice must not stack the prefix. + filt = LoggerPrefixFilter("run1") + record = _make_record("openevolve.controller") + self.assertTrue(filt.filter(record)) + self.assertTrue(filt.filter(record)) + self.assertEqual(record.name, "run1.openevolve.controller") + + def test_filter_with_empty_prefix_is_noop(self): + filt = LoggerPrefixFilter("") + record = _make_record("openevolve.controller") + self.assertTrue(filt.filter(record)) + self.assertEqual(record.name, "openevolve.controller") + + def test_filter_returns_true_for_all_records(self): + # The filter must never swallow records; it only renames them. + filt = LoggerPrefixFilter("runA") + for name in ("openevolve.controller", "openevolve.evaluator", "some.other.module"): + self.assertTrue(filt.filter(_make_record(name))) + + +class TestLoggerPrefixIntegration(unittest.TestCase): + """ + Integration tests: constructing OpenEvolve calls _setup_logging, which + attaches handlers to the root logger. Verify the resulting log file (and + console stream) carry the configured prefix, and that the default (no + prefix) behavior is unchanged. + """ + + def setUp(self): + self.tmpdir = tempfile.mkdtemp(prefix="oe290_") + # _setup_logging mutates the process-wide root logger; save and restore. + self._root = logging.getLogger() + self._saved_handlers = self._root.handlers[:] + self._saved_level = self._root.level + + def tearDown(self): + current = self._root.handlers[:] + for handler in current: + self._root.removeHandler(handler) + for handler in self._saved_handlers: + self._root.addHandler(handler) + self._root.setLevel(self._saved_level) + for handler in current: + if handler not in self._saved_handlers: + handler.close() + shutil.rmtree(self.tmpdir, ignore_errors=True) + + def _write_program_and_evaluator(self): + program_path = os.path.join(self.tmpdir, "initial_program.py") + with open(program_path, "w", encoding="utf-8") as f: + f.write("def run():\n return 1\n") + evaluation_path = os.path.join(self.tmpdir, "evaluation.py") + with open(evaluation_path, "w", encoding="utf-8") as f: + f.write('def evaluate(program_path):\n return {"combined_score": 1.0}\n') + return program_path, evaluation_path + + def _make_config(self, log_dir_name, **overrides): + config = Config() + config.log_dir = os.path.join(self.tmpdir, log_dir_name) + config.random_seed = None + for key, value in overrides.items(): + setattr(config, key, value) + return config + + def _run_controller(self, config, stderr=None): + program_path, evaluation_path = self._write_program_and_evaluator() + output_dir = os.path.join(self.tmpdir, "output") + with ( + patch("openevolve.controller.LLMEnsemble"), + patch("openevolve.controller.Evaluator"), + patch("sys.stderr", stderr or io.StringIO()), + ): + OpenEvolve(program_path, evaluation_path, config, output_dir=output_dir) + + def _read_log(self, config): + log_files = sorted(glob.glob(os.path.join(config.log_dir, "*.log"))) + self.assertTrue(log_files, f"no log files written to {config.log_dir}") + with open(log_files[0], encoding="utf-8") as f: + return f.read() + + def test_prefixed_run_writes_prefixed_names_to_log_file(self): + config = self._make_config("logs_prefixed", logger_prefix="run1") + self._run_controller(config) + content = self._read_log(config) + self.assertIn("run1.openevolve.controller", content) + + def test_prefixed_run_writes_prefixed_names_to_console(self): + stderr = io.StringIO() + config = self._make_config("logs_console", logger_prefix="run1") + self._run_controller(config, stderr=stderr) + self.assertIn("run1.openevolve.controller", stderr.getvalue()) + + def test_no_prefix_keeps_default_names(self): + config = self._make_config("logs_default") + self._run_controller(config) + content = self._read_log(config) + # Default behavior is unchanged: plain module names, no prefix anywhere. + self.assertIn("openevolve.controller", content) + self.assertNotIn("run1.", content) + + +if __name__ == "__main__": + unittest.main()