[Serve] fix logging error on passing traceback object into exc_info

python/ray/serve/_private/logging_utils.py

@@ -100,23 +100,22 @@ def format(self, record: logging.LogRecord) -> str:
                 The formatted log record in json format.
         """
         record_format = copy.deepcopy(self.component_log_fmt)
-        record_attributes = copy.deepcopy(record.__dict__)
         record_format[SERVE_LOG_LEVEL_NAME] = record.levelname
         record_format[SERVE_LOG_TIME] = self.asctime_formatter.format(record)
 
         for field in ServeJSONFormatter.ADD_IF_EXIST_FIELDS:
-            if field in record_attributes:
-                record_format[field] = record_attributes[field]
+            if field in record.__dict__:
+                record_format[field] = record.__dict__[field]
 
         record_format[SERVE_LOG_MESSAGE] = self.message_formatter.format(record)
 
-        if SERVE_LOG_EXTRA_FIELDS in record_attributes:
-            if not isinstance(record_attributes[SERVE_LOG_EXTRA_FIELDS], dict):
+        if SERVE_LOG_EXTRA_FIELDS in record.__dict__:
+            if not isinstance(record.__dict__[SERVE_LOG_EXTRA_FIELDS], dict):
                 raise ValueError(
                     f"Expected a dictionary passing into {SERVE_LOG_EXTRA_FIELDS}, "
-                    f"but got {type(record_attributes[SERVE_LOG_EXTRA_FIELDS])}"
+                    f"but got {type(record.__dict__[SERVE_LOG_EXTRA_FIELDS])}"
                 )
-            for k, v in record_attributes[SERVE_LOG_EXTRA_FIELDS].items():
+            for k, v in record.__dict__[SERVE_LOG_EXTRA_FIELDS].items():
                 if k in record_format:
                     raise KeyError(f"Found duplicated key in the log record: {k}")
                 record_format[k] = v

python/ray/serve/schema.py

@@ -99,12 +99,12 @@ class LoggingConfig(BaseModel):
             from ray import serve
             from ray.serve.schema import LoggingConfig
             # Set log level for the deployment.
-            @serve.deployment(LoggingConfig(log_level="DEBUG")
+            @serve.deployment(LoggingConfig(log_level="DEBUG"))
             class MyDeployment:
                 def __call__(self) -> str:
                     return "Hello world!"
             # Set log directory for the deployment.
-            @serve.deployment(LoggingConfig(logs_dir="/my_dir")
+            @serve.deployment(LoggingConfig(logs_dir="/my_dir"))
             class MyDeployment:
                 def __call__(self) -> str:
                     return "Hello world!"

python/ray/serve/tests/test_logging.py

@@ -832,5 +832,45 @@ def test_stream_to_logger():
         stream_to_logger.i_dont_exist
 
 
+@pytest.mark.skipif(sys.platform == "win32", reason="Fail to create temp dir.")
+@pytest.mark.parametrize(
+    "ray_instance",
+    [
+        {"RAY_SERVE_LOG_TO_STDERR": "0"},
+    ],
+    indirect=True,
+)
+def test_json_logging_with_unpickleable_exc_info(
+    serve_and_ray_shutdown, ray_instance, tmp_dir
+):
+    """Test the json logging with unpickleable exc_info.
+
+    exc_info field is often used to log the exception stack trace. However, we had issue
+    where deepcopy is applied to traceback object from exc_info which is not pickleable
+    and caused logging error.
+
+    See: https://github.com/ray-project/ray/issues/45912
+    """
+    logs_dir = Path(tmp_dir)
+    logging_config = LoggingConfig(encoding="JSON", logs_dir=str(logs_dir))
+    logger = logging.getLogger("ray.serve")
+
+    @serve.deployment(logging_config=logging_config)
+    class App:
+        def __call__(self):
+            try:
+                raise Exception("fake_exception")
+            except Exception as e:
+                logger.info("log message", exc_info=e)
+            return "foo"
+
+    serve.run(App.bind())
+    requests.get("http://127.0.0.1:8000/")
+    for log_file in os.listdir(logs_dir):
+        with open(logs_dir / log_file) as f:
+            assert "Logging error" not in f.read()
+            assert "cannot pickle" not in f.read()
+
+
 if __name__ == "__main__":
     sys.exit(pytest.main(["-v", "-s", __file__]))