Adding OptimizationLogger and replacing print for log in nsga2.py (#1193

)

* replaced print for logger in nsga2.py

* added OptimizationLogger

* fixed callbacks type error

* OptimizationLogger fixes

* Added caplog to OptimizationLogger tests

* test_callback edits

Co-authored-by: Theodore Clarke <[email protected]>

nevergrad/optimization/callbacks.py

@@ -3,11 +3,13 @@
 # This source code is licensed under the MIT license found in the
 # LICENSE file in the root directory of this source tree.
 
+import os
 import json
 import time
 import warnings
 import inspect
 import datetime
+import logging
 from pathlib import Path
 import numpy as np
 import nevergrad.common.typing as tp
@@ -16,6 +18,9 @@
 from nevergrad.parametrization import helpers
 from . import base
 
+logging.basicConfig(level=os.environ.get("LOGLEVEL", "INFO"))
+global_logger = logging.getLogger(__name__)
+
 
 class OptimizationPrinter:
     """Printer to register as callback in an optimizer, for printing
@@ -45,6 +50,47 @@ def __call__(self, optimizer: base.Optimizer, *args: tp.Any, **kwargs: tp.Any) -
             print(f"After {optimizer.num_tell}, recommendation is {x}")  # TODO fetch value
 
 
+class OptimizationLogger:
+    """Logger to register as callback in an optimizer, for Logging
+    best point regularly.
+
+    Parameters
+    ----------
+    logger:
+        given logger that callback will use to log
+    log_level:
+        log level that logger will write to
+    log_interval_tells: int
+        max number of evaluation before performing another log
+    log_interval_seconds:
+        max number of seconds before performing another log
+    """
+
+    def __init__(
+        self,
+        *,
+        logger: logging.Logger = global_logger,
+        log_level: int = logging.INFO,
+        log_interval_tells: int = 1,
+        log_interval_seconds: float = 60.0,
+    ) -> None:
+        assert log_interval_tells > 0
+        assert log_interval_seconds > 0
+        self._logger = logger
+        self._log_level = log_level
+        self._log_interval_tells = int(log_interval_tells)
+        self._log_interval_seconds = log_interval_seconds
+        self._next_tell = self._log_interval_tells
+        self._next_time = time.time() + log_interval_seconds
+
+    def __call__(self, optimizer: base.Optimizer, *args: tp.Any, **kwargs: tp.Any) -> None:
+        if time.time() >= self._next_time or self._next_tell >= optimizer.num_tell:
+            self._next_time = time.time() + self._log_interval_seconds
+            self._next_tell = optimizer.num_tell + self._log_interval_tells
+            x = optimizer.provide_recommendation()
+            self._logger.log(self._log_level, "After %s, recommendation is %s", optimizer.num_tell, x)
+
+
 class ParametersLogger:
     """Logs parameter and run information throughout into a file during
     optimization.

nevergrad/optimization/multiobjective/nsga2.py

@@ -3,11 +3,18 @@
 # This source code is licensed under the MIT license found in the
 # LICENSE file in the root directory of this source tree.
 
+import os
+import logging
 import numpy as np
 import nevergrad.common.typing as tp
 from nevergrad.parametrization import parameter as p
 
 
+# run with LOGLEVEL=DEBUG for more debug information
+logging.basicConfig(level=os.environ.get("LOGLEVEL", "INFO"))
+logger = logging.getLogger(__name__)
+
+
 class CrowdingDistance:
     """This class implements the calculation of crowding distance for NSGA-II."""
 
@@ -40,7 +47,7 @@ def accumulate_distance_per_objective(self, front: tp.List[p.Parameter], i: int)
                     pass  # undefined
                 else:
                     distance = distance / float(objective_maxn - objective_minn)
-                print(f"front[j]: {front[j].uid} distance: {distance}")
+                logger.debug("front[j]: %s distance: %s", front[j].uid, distance)
                 # The overall crowding-distance value is calculated as the sum of
                 # individual distance values corresponding to each objective.
                 front[j]._meta["crowding_distance"] += distance

nevergrad/optimization/test_callbacks.py

@@ -4,6 +4,8 @@
 # LICENSE file in the root directory of this source tree.
 
 from pathlib import Path
+import logging
+import os
 import numpy as np
 import nevergrad as ng
 import nevergrad.common.typing as tp
@@ -112,3 +114,24 @@ def test_early_stopping() -> None:
     # below functions are inlcuded in the docstring
     assert optimizer.current_bests["minimum"].mean < 12
     assert optimizer.recommend().loss < 12  # type: ignore
+
+
+def test_optimization_logger(caplog) -> None:
+    instrum = ng.p.Instrumentation(
+        None, 2.0, blublu="blublu", array=ng.p.Array(shape=(3, 2)), multiobjective=True
+    )
+    logging.basicConfig(level=os.environ.get("LOGLEVEL", "INFO"))
+    logger = logging.getLogger(__name__)
+    optimizer = optimizerlib.OnePlusOne(parametrization=instrum, budget=3)
+    optimizer.register_callback(
+        "tell",
+        callbacks.OptimizationLogger(
+            logger=logger, log_level=logging.INFO, log_interval_tells=10, log_interval_seconds=0.1
+        ),
+    )
+    with caplog.at_level(logging.INFO):
+        optimizer.minimize(_func, verbosity=2)
+    assert (
+        "After 0, recommendation is Instrumentation(Tuple(None,2.0),Dict(array=Array{(3,2)},blublu=blublu,multiobjective=True))"
+        in caplog.text
+    )