[Core/RLlib] Move log_once from rllib to ray.util. (#7273)

* Move log_once from rllib to tune.

* Move log_once from rllib to tune.

* LINT.

* Move to ray.util.debug.

python/ray/tune/logger.py

@@ -7,6 +7,7 @@ import numbers
 import numpy as np
 
 import ray.cloudpickle as cloudpickle
+from ray.util.debug import log_once
 from ray.tune.result import (NODE_IP, TRAINING_ITERATION, TIME_TOTAL_S,
                              TIMESTEPS_TOTAL, EXPR_PARAM_FILE,
                              EXPR_PARAM_PICKLE_FILE, EXPR_PROGRESS_FILE,
@@ -214,10 +215,11 @@ class TBXLogger(Logger):
                 # In case TensorboardX still doesn't think it's a valid value
                 # (e.g. `[[]]`), warn and move on.
                 except (ValueError, TypeError):
-                    logger.warning(
-                        "You are trying to log an invalid value ({}={}) "
-                        "via {}!".format(full_attr, value,
-                                         type(self).__name__))
+                    if log_once("invalid_tbx_value"):
+                        logger.warning(
+                            "You are trying to log an invalid value ({}={}) "
+                            "via {}!".format(full_attr, value,
+                                             type(self).__name__))
 
         self.last_result = valid_result
         self._file_writer.flush()

python/ray/tune/utils/__init__.py

@@ -1,9 +1,14 @@
-from ray.tune.utils.util import (deep_update, flatten_dict, get_pinned_object,
-                                 merge_dicts, pin_in_object_store, UtilMonitor,
-                                 validate_save_restore, warn_if_slow)
+from ray.tune.utils.util import deep_update, flatten_dict, get_pinned_object, \
+    merge_dicts, pin_in_object_store, UtilMonitor, validate_save_restore, \
+    warn_if_slow
 
 __all__ = [
-    "deep_update", "flatten_dict", "get_pinned_object", "merge_dicts",
-    "pin_in_object_store", "UtilMonitor", "validate_save_restore",
-    "warn_if_slow"
+    "deep_update",
+    "flatten_dict",
+    "get_pinned_object",
+    "merge_dicts",
+    "pin_in_object_store",
+    "UtilMonitor",
+    "validate_save_restore",
+    "warn_if_slow",
 ]

python/ray/util/__init__.py

@@ -1,10 +1,15 @@
-from .named_actors import get_actor, register_actor
-from .actor_pool import ActorPool
-from . import iter
+from ray.util import iter
+from ray.util.actor_pool import ActorPool
+from ray.util.debug import log_once, disable_log_once_globally, \
+    enable_periodic_logging
+from ray.util.named_actors import get_actor, register_actor
 
 __all__ = [
     "ActorPool",
-    "iter",
+    "disable_log_once_globally",
+    "enable_periodic_logging",
     "get_actor",
+    "iter",
+    "log_once",
     "register_actor",
 ]

python/ray/util/debug.py

@@ -0,0 +1,46 @@
+import time
+
+_logged = set()
+_disabled = False
+_periodic_log = False
+_last_logged = 0.0
+
+
+def log_once(key):
+    """Returns True if this is the "first" call for a given key.
+
+    Various logging settings can adjust the definition of "first".
+
+    Example:
+        >>> if log_once("some_key"):
+        ...     logger.info("Some verbose logging statement")
+    """
+
+    global _last_logged
+
+    if _disabled:
+        return False
+    elif key not in _logged:
+        _logged.add(key)
+        _last_logged = time.time()
+        return True
+    elif _periodic_log and time.time() - _last_logged > 60.0:
+        _logged.clear()
+        _last_logged = time.time()
+        return False
+    else:
+        return False
+
+
+def disable_log_once_globally():
+    """Make log_once() return False in this process."""
+
+    global _disabled
+    _disabled = True
+
+
+def enable_periodic_logging():
+    """Make log_once() periodically return True in this process."""
+
+    global _periodic_log
+    _periodic_log = True

rllib/evaluation/rollout_worker.py

@@ -5,6 +5,8 @@ import logging
 import pickle
 
 import ray
+from ray.util.debug import log_once, disable_log_once_globally, \
+    enable_periodic_logging
 from ray.util.iter import ParallelIteratorWorker
 from ray.rllib.env.atari_wrappers import wrap_deepmind, is_atari
 from ray.rllib.env.base_env import BaseEnv
@@ -26,8 +28,7 @@ from ray.rllib.models import ModelCatalog
 from ray.rllib.models.preprocessors import NoPreprocessor
 from ray.rllib.utils import merge_dicts
 from ray.rllib.utils.annotations import override, DeveloperAPI
-from ray.rllib.utils.debug import disable_log_once_globally, log_once, \
-    summarize, enable_periodic_logging
+from ray.rllib.utils.debug import summarize
 from ray.rllib.utils.filter import get_filter
 from ray.rllib.utils.sgd import do_minibatch_sgd
 from ray.rllib.utils.tf_run_builder import TFRunBuilder

rllib/evaluation/sample_batch_builder.py

@@ -2,9 +2,10 @@ import collections
 import logging
 import numpy as np
 
+from ray.util.debug import log_once
 from ray.rllib.policy.sample_batch import SampleBatch, MultiAgentBatch
 from ray.rllib.utils.annotations import PublicAPI, DeveloperAPI
-from ray.rllib.utils.debug import log_once, summarize
+from ray.rllib.utils.debug import summarize
 
 logger = logging.getLogger(__name__)
 

rllib/evaluation/sampler.py

@@ -5,6 +5,7 @@ import six.moves.queue as queue
 import threading
 import time
 
+from ray.util.debug import log_once
 from ray.rllib.evaluation.episode import MultiAgentEpisode, _flatten_action
 from ray.rllib.evaluation.rollout_metrics import RolloutMetrics
 from ray.rllib.evaluation.sample_batch_builder import \
@@ -15,7 +16,7 @@ from ray.rllib.env.base_env import BaseEnv, ASYNC_RESET_RETURN
 from ray.rllib.env.atari_wrappers import get_wrapper_by_cls, MonitorEnv
 from ray.rllib.offline import InputReader
 from ray.rllib.utils.annotations import override
-from ray.rllib.utils.debug import log_once, summarize
+from ray.rllib.utils.debug import summarize
 from ray.rllib.utils.tuple_actions import TupleActions
 from ray.rllib.utils.tf_run_builder import TFRunBuilder
 

rllib/optimizers/multi_gpu_impl.py

@@ -1,7 +1,8 @@
 from collections import namedtuple
 import logging
 
-from ray.rllib.utils.debug import log_once, summarize
+from ray.util.debug import log_once
+from ray.rllib.utils.debug import summarize
 from ray.rllib.utils import try_import_tf
 
 tf = try_import_tf()

rllib/policy/dynamic_tf_policy.py

@@ -4,12 +4,13 @@ from collections import OrderedDict
 import logging
 import numpy as np
 
+from ray.util.debug import log_once
 from ray.rllib.policy.policy import Policy
 from ray.rllib.policy.sample_batch import SampleBatch
 from ray.rllib.policy.tf_policy import TFPolicy
 from ray.rllib.models.catalog import ModelCatalog
 from ray.rllib.utils import try_import_tf, override
-from ray.rllib.utils.debug import log_once, summarize
+from ray.rllib.utils.debug import summarize
 from ray.rllib.utils.tracking_dict import UsageTrackingDict
 
 tf = try_import_tf()

rllib/policy/eager_tf_policy.py

@@ -6,6 +6,7 @@ import logging
 import functools
 import numpy as np
 
+from ray.util.debug import log_once
 from ray.rllib.evaluation.episode import _flatten_action
 from ray.rllib.models.catalog import ModelCatalog
 from ray.rllib.policy.policy import Policy, LEARNER_STATS_KEY
@@ -13,7 +14,6 @@ from ray.rllib.policy.sample_batch import SampleBatch
 from ray.rllib.policy.policy import ACTION_PROB, ACTION_LOGP
 from ray.rllib.utils import add_mixins
 from ray.rllib.utils.annotations import override
-from ray.rllib.utils.debug import log_once
 from ray.rllib.utils.framework import try_import_tf
 
 tf = try_import_tf()

rllib/policy/tf_policy.py

@@ -5,13 +5,14 @@ import os
 import numpy as np
 import ray
 import ray.experimental.tf_utils
+from ray.util.debug import log_once
 from ray.rllib.policy.policy import Policy, LEARNER_STATS_KEY, \
     ACTION_PROB, ACTION_LOGP
 from ray.rllib.policy.rnn_sequencing import chop_into_sequences
 from ray.rllib.policy.sample_batch import SampleBatch
 from ray.rllib.models.modelv2 import ModelV2
 from ray.rllib.utils.annotations import override, DeveloperAPI
-from ray.rllib.utils.debug import log_once, summarize
+from ray.rllib.utils.debug import summarize
 from ray.rllib.utils.exploration.exploration import Exploration
 from ray.rllib.utils.framework import try_import_tf
 from ray.rllib.utils.schedules import ConstantSchedule, PiecewiseSchedule

rllib/utils/debug.py

@@ -1,56 +1,11 @@
 import numpy as np
 import pprint
-import time
 
 from ray.rllib.policy.sample_batch import SampleBatch, MultiAgentBatch
 
-_logged = set()
-_disabled = False
-_periodic_log = False
-_last_logged = 0.0
 _printer = pprint.PrettyPrinter(indent=2, width=60)
 
 
-def log_once(key):
-    """Returns True if this is the "first" call for a given key.
-
-    Various logging settings can adjust the definition of "first".
-
-    Example:
-        >>> if log_once("some_key"):
-        ...     logger.info("Some verbose logging statement")
-    """
-
-    global _last_logged
-
-    if _disabled:
-        return False
-    elif key not in _logged:
-        _logged.add(key)
-        _last_logged = time.time()
-        return True
-    elif _periodic_log and time.time() - _last_logged > 60.0:
-        _logged.clear()
-        _last_logged = time.time()
-        return False
-    else:
-        return False
-
-
-def disable_log_once_globally():
-    """Make log_once() return False in this process."""
-
-    global _disabled
-    _disabled = True
-
-
-def enable_periodic_logging():
-    """Make log_once() periodically return True in this process."""
-
-    global _periodic_log
-    _periodic_log = True
-
-
 def summarize(obj):
     """Return a pretty-formatted string for an object.
 

rllib/utils/tf_run_builder.py

@@ -2,7 +2,7 @@ import logging
 import os
 import time
 
-from ray.rllib.utils.debug import log_once
+from ray.util.debug import log_once
 from ray.rllib.utils import try_import_tf
 
 tf = try_import_tf()