[core] Ray Core / Ray Data logging configuration leads to unexpected behavior

python/ray/_private/log.py

@@ -1,5 +1,4 @@
 import logging
-from logging.config import dictConfig
 import threading
 from typing import Union
 
@@ -74,44 +73,19 @@ def generate_logging_config():
             return
         logger_initialized = True
 
-        formatters = {
-            "plain": {
-                "format": (
-                    "%(asctime)s\t%(levelname)s %(filename)s:%(lineno)s -- %(message)s"
-                ),
-            },
-        }
-
-        handlers = {
-            "default": {
-                "()": PlainRayHandler,
-                "formatter": "plain",
-            }
-        }
-
-        loggers = {
-            # Default ray logger; any log message that gets propagated here will be
-            # logged to the console. Disable propagation, as many users will use
-            # basicConfig to set up a default handler. If so, logs will be
-            # printed twice unless we prevent propagation here.
-            "ray": {
-                "level": "INFO",
-                "handlers": ["default"],
-                "propagate": False,
-            },
-            # Special handling for ray.rllib: only warning-level messages passed through
-            # See https://github.com/ray-project/ray/pull/31858 for related PR
-            "ray.rllib": {
-                "level": "WARN",
-            },
-        }
-
-        dictConfig(
-            {
-                "version": 1,
-                "formatters": formatters,
-                "handlers": handlers,
-                "loggers": loggers,
-                "disable_existing_loggers": False,
-            }
+        plain_formatter = logging.Formatter(
+            "%(asctime)s\t%(levelname)s %(filename)s:%(lineno)s -- %(message)s"
         )
+
+        default_handler = PlainRayHandler()
+        default_handler.setFormatter(plain_formatter)
+
+        ray_logger = logging.getLogger("ray")
+        ray_logger.setLevel(logging.INFO)
+        ray_logger.addHandler(default_handler)
+        ray_logger.propagate = False
+
+        # Special handling for ray.rllib: only warning-level messages passed through
+        # See https://github.com/ray-project/ray/pull/31858 for related PR
+        rllib_logger = logging.getLogger("ray.rllib")
+        rllib_logger.setLevel(logging.WARN)

python/ray/_private/ray_logging/__init__.py

@@ -1,6 +1,7 @@
 import colorama
 from dataclasses import dataclass
 import logging
+import logging.handlers
 import os
 import re
 import sys

python/ray/_private/ray_logging/default_impl.py

@@ -1,4 +1,4 @@
-def get_dict_config_provider():
-    from ray._private.ray_logging.logging_config import DefaultDictConfigProvider
+def get_logging_configurator():
+    from ray._private.ray_logging.logging_config import DefaultLoggingConfigurator
 
-    return DefaultDictConfigProvider()
+    return DefaultLoggingConfigurator()

python/ray/_private/ray_logging/logging_config.py

@@ -12,68 +12,47 @@
 import time
 
 
-class DictConfigProvider(ABC):
+class LoggingConfigurator(ABC):
     @abstractmethod
     def get_supported_encodings(self) -> Set[str]:
         raise NotImplementedError
 
     @abstractmethod
-    def get_dict_config(self, encoding: str, log_level: str) -> dict:
+    def configure_logging(self, encoding: str, log_level: str):
         raise NotImplementedError
 
 
-class DefaultDictConfigProvider(DictConfigProvider):
+class DefaultLoggingConfigurator(LoggingConfigurator):
     def __init__(self):
-        self._dict_configs = {
-            "TEXT": lambda log_level: {
-                "version": 1,
-                "disable_existing_loggers": False,
-                "formatters": {
-                    "text": {
-                        "()": (
-                            f"{TextFormatter.__module__}."
-                            f"{TextFormatter.__qualname__}"
-                        ),
-                    },
-                },
-                "filters": {
-                    "core_context": {
-                        "()": (
-                            f"{CoreContextFilter.__module__}."
-                            f"{CoreContextFilter.__qualname__}"
-                        ),
-                    },
-                },
-                "handlers": {
-                    "console": {
-                        "level": log_level,
-                        "class": "logging.StreamHandler",
-                        "formatter": "text",
-                        "filters": ["core_context"],
-                    },
-                },
-                "root": {
-                    "level": log_level,
-                    "handlers": ["console"],
-                },
-                "loggers": {
-                    "ray": {
-                        "level": log_level,
-                        "handlers": ["console"],
-                        "propagate": False,
-                    }
-                },
-            }
+        self._encoding_to_formatter = {
+            "TEXT": TextFormatter(),
         }
 
     def get_supported_encodings(self) -> Set[str]:
-        return self._dict_configs.keys()
+        return self._encoding_to_formatter.keys()
 
-    def get_dict_config(self, encoding: str, log_level: str) -> dict:
-        return self._dict_configs[encoding](log_level)
+    def configure_logging(self, encoding: str, log_level: str):
+        formatter = self._encoding_to_formatter[encoding]
+        core_context_filter = CoreContextFilter()
+        handler = logging.StreamHandler()
+        handler.setLevel(log_level)
+        handler.setFormatter(formatter)
+        handler.addFilter(core_context_filter)
 
+        root_logger = logging.getLogger()
+        root_logger.setLevel(log_level)
+        root_logger.addHandler(handler)
 
-_dict_config_provider: DictConfigProvider = default_impl.get_dict_config_provider()
+        ray_logger = logging.getLogger("ray")
+        ray_logger.setLevel(log_level)
+        # Remove all existing handlers added by `ray/__init__.py`.
+        for h in ray_logger.handlers[:]:
+            ray_logger.removeHandler(h)
+        ray_logger.addHandler(handler)
+        ray_logger.propagate = False
+
+
+_logging_configurator: LoggingConfigurator = default_impl.get_logging_configurator()
 
 
 @PublicAPI(stability="alpha")
@@ -84,19 +63,16 @@ class LoggingConfig:
     log_level: str = "INFO"
 
     def __post_init__(self):
-        if self.encoding not in _dict_config_provider.get_supported_encodings():
+        if self.encoding not in _logging_configurator.get_supported_encodings():
             raise ValueError(
                 f"Invalid encoding type: {self.encoding}. "
                 "Valid encoding types are: "
-                f"{list(_dict_config_provider.get_supported_encodings())}"
+                f"{list(_logging_configurator.get_supported_encodings())}"
             )
 
-    def _get_dict_config(self) -> dict:
-        """Get the logging configuration based on the encoding type.
-        Returns:
-            dict: The logging configuration.
-        """
-        return _dict_config_provider.get_dict_config(self.encoding, self.log_level)
+    def _configure_logging(self):
+        """Set up the logging configuration for the current process."""
+        _logging_configurator.configure_logging(self.encoding, self.log_level)
 
     def _setup_log_record_factory(self):
         old_factory = logging.getLogRecordFactory()
@@ -121,7 +97,7 @@ def record_factory(*args, **kwargs):
     def _apply(self):
         """Set up both the LogRecord factory and the logging configuration."""
         self._setup_log_record_factory()
-        logging.config.dictConfig(self._get_dict_config())
+        self._configure_logging()
 
 
 LoggingConfig.__doc__ = f"""
@@ -153,7 +129,7 @@ def f():
 
     Args:
         encoding: Encoding type for the logs. The valid values are
-            {list(_dict_config_provider.get_supported_encodings())}
+            {list(_logging_configurator.get_supported_encodings())}
         log_level: Log level for the logs. Defaults to 'INFO'. You can set
             it to 'DEBUG' to receive more detailed debug logs.
     """  # noqa: E501

python/ray/tests/test_logging_2.py

@@ -207,17 +207,9 @@ def test_record_with_exception(self):
             assert s in formatted
 
 
-class TestLoggingConfig:
-    def test_log_level(self):
-        log_level = "DEBUG"
-        logging_config = LoggingConfig(log_level=log_level)
-        dict_config = logging_config._get_dict_config()
-        assert dict_config["handlers"]["console"]["level"] == log_level
-        assert dict_config["root"]["level"] == log_level
-
-    def test_invalid_dict_config(self):
-        with pytest.raises(ValueError):
-            LoggingConfig(encoding="INVALID")._get_dict_config()
+def test_invalid_encoding():
+    with pytest.raises(ValueError):
+        LoggingConfig(encoding="INVALID")
 
 
 class TestTextModeE2E:
@@ -477,6 +469,27 @@ def print_message(self):
     assert "(MyActor pid=" not in stderr
 
 
+def test_configure_both_structured_logging_and_lib_logging(shutdown_only):
+    """
+    Configure the `ray.test` logger. Then, configure the `root` and `ray`
+    loggers in `ray.init()`. Ensure that the `ray.test` logger is not affected.
+    """
+    script = """
+import ray
+import logging
+
+old_test_logger = logging.getLogger("ray.test")
+assert old_test_logger.getEffectiveLevel() != logging.DEBUG
+old_test_logger.setLevel(logging.DEBUG)
+
+ray.init(logging_config=ray.LoggingConfig(encoding="TEXT", log_level="INFO"))
+
+new_test_logger = logging.getLogger("ray.test")
+assert old_test_logger.getEffectiveLevel() == logging.DEBUG
+"""
+    run_string_as_driver(script)
+
+
 if __name__ == "__main__":
     if os.environ.get("PARALLEL_CI"):
         sys.exit(pytest.main(["-n", "auto", "--boxed", "-vs", __file__]))