diff --git a/python/sglang/srt/managers/tokenizer_manager.py b/python/sglang/srt/managers/tokenizer_manager.py index e40d701b1..71d35a413 100644 --- a/python/sglang/srt/managers/tokenizer_manager.py +++ b/python/sglang/srt/managers/tokenizer_manager.py @@ -370,6 +370,7 @@ class TokenizerManager(TokenizerCommunicatorMixin, TokenizerManagerMultiItemMixi log_requests=self.server_args.log_requests, log_requests_level=self.server_args.log_requests_level, log_requests_format=self.server_args.log_requests_format, + log_requests_target=self.server_args.log_requests_target, ) # Dumping diff --git a/python/sglang/srt/server_args.py b/python/sglang/srt/server_args.py index c94b47238..ff34a0672 100644 --- a/python/sglang/srt/server_args.py +++ b/python/sglang/srt/server_args.py @@ -339,6 +339,7 @@ class ServerArgs: log_requests: bool = False log_requests_level: int = 2 log_requests_format: str = "text" + log_requests_target: Optional[List[str]] = None crash_dump_folder: Optional[str] = None show_time_cost: bool = False enable_metrics: bool = False @@ -3013,6 +3014,14 @@ class ServerArgs: choices=["text", "json"], help="Format for request logging: 'text' (human-readable) or 'json' (structured)", ) + parser.add_argument( + "--log-requests-target", + type=str, + nargs="+", + default=ServerArgs.log_requests_target, + help="Target(s) for request logging: 'stdout' and/or directory path(s) for file output. " + "Can specify multiple targets, e.g., '--log-requests-target stdout /my/path'. ", + ) parser.add_argument( "--crash-dump-folder", type=str, diff --git a/python/sglang/srt/utils/request_logger.py b/python/sglang/srt/utils/request_logger.py index d5db3f49a..c861e2421 100644 --- a/python/sglang/srt/utils/request_logger.py +++ b/python/sglang/srt/utils/request_logger.py @@ -16,9 +16,14 @@ from __future__ import annotations import dataclasses import json import logging +import os +import socket from datetime import datetime from functools import lru_cache -from typing import TYPE_CHECKING, Any, Optional, Set, Tuple, Union +from logging.handlers import TimedRotatingFileHandler +from typing import TYPE_CHECKING, Any, List, Optional, Set, Tuple, Union + +import torch.distributed as dist from sglang.srt.environ import envs from sglang.srt.utils.common import get_bool_env_var @@ -28,12 +33,6 @@ if TYPE_CHECKING: logger = logging.getLogger(__name__) -_json_logger = logging.getLogger(__name__ + ".json") -_json_logger.propagate = False -_json_handler = logging.StreamHandler() -_json_handler.setFormatter(logging.Formatter("%(message)s")) -_json_logger.addHandler(_json_handler) - class RequestLogger: def __init__( @@ -41,20 +40,31 @@ class RequestLogger: log_requests: bool, log_requests_level: int, log_requests_format: str, + log_requests_target: Optional[List[str]], ): self.log_requests = log_requests self.log_requests_level = log_requests_level self.log_requests_format = log_requests_format + self.log_requests_target = log_requests_target + self.metadata: Tuple[Optional[int], Optional[Set[str]], Optional[Set[str]]] = ( self._compute_metadata() ) + self.targets = self._setup_targets() + self.log_exceeded_ms = envs.SGLANG_LOG_REQUEST_EXCEEDED_MS.get() + def _setup_targets(self) -> List[logging.Logger]: + if not self.log_requests_target: + return [_create_log_target_stdout()] + return [_create_log_target(t) for t in self.log_requests_target] + def configure( self, log_requests: Optional[bool] = None, log_requests_level: Optional[int] = None, log_requests_format: Optional[str] = None, + log_requests_target: Optional[List[str]] = None, ) -> None: if log_requests is not None: self.log_requests = log_requests @@ -62,7 +72,11 @@ class RequestLogger: self.log_requests_level = log_requests_level if log_requests_format is not None: self.log_requests_format = log_requests_format + if log_requests_target is not None: + self.log_requests_target = log_requests_target + self.metadata = self._compute_metadata() + self.targets = self._setup_targets() def log_received_request( self, obj: Union["GenerateReqInput", "EmbeddingReqInput"], tokenizer: Any = None @@ -76,9 +90,9 @@ class RequestLogger: "rid": obj.rid, "obj": _transform_data_for_logging(obj, max_length, skip_names), } - _log_json("request.received", log_data) + self._log_json("request.received", log_data) else: - logger.info( + self._log( f"Receive: obj={_dataclass_to_string_truncated(obj, max_length, skip_names=skip_names)}" ) @@ -116,13 +130,13 @@ class RequestLogger: log_data["out"] = _transform_data_for_logging( out, max_length, out_skip_names ) - _log_json("request.finished", log_data) + self._log_json("request.finished", log_data) else: if is_multimodal_gen: msg = f"Finish: obj={_dataclass_to_string_truncated(obj, max_length, skip_names=skip_names)}" else: msg = f"Finish: obj={_dataclass_to_string_truncated(obj, max_length, skip_names=skip_names)}, out={_dataclass_to_string_truncated(out, max_length, skip_names=out_skip_names)}" - logger.info(msg) + self._log(msg) def _compute_metadata( self, @@ -164,6 +178,18 @@ class RequestLogger: ) return max_length, skip_names, out_skip_names + def _log_json(self, event: str, data: dict) -> None: + log_data = { + "timestamp": datetime.now().isoformat(), + "event": event, + **data, + } + self._log(json.dumps(log_data, ensure_ascii=False)) + + def _log(self, msg: str) -> None: + for target in self.targets: + target.info(msg) + # TODO remove this? @lru_cache(maxsize=2) @@ -171,14 +197,37 @@ def disable_request_logging() -> bool: return get_bool_env_var("SGLANG_DISABLE_REQUEST_LOGGING") -# TODO unify logging, e.g. allow normal logs to be JSON as well -def _log_json(event: str, data: dict) -> None: - log_data = { - "timestamp": datetime.now().isoformat(), - "event": event, - **data, - } - _json_logger.info(json.dumps(log_data, ensure_ascii=False)) +def _create_log_target(target: str) -> logging.Logger: + if target.lower() == "stdout": + return _create_log_target_stdout() + return _create_log_target_file(target) + + +def _create_log_target_stdout() -> logging.Logger: + return _create_logger_with_handler(f"{__name__}.stdout", logging.StreamHandler()) + + +def _create_log_target_file(directory: str) -> logging.Logger: + os.makedirs(directory, exist_ok=True) + hostname = socket.gethostname() + rank = dist.get_rank() if dist.is_initialized() else 0 + filename = os.path.join(directory, f"{hostname}_{rank}.log") + handler = TimedRotatingFileHandler( + filename, when="H", backupCount=0, encoding="utf-8" + ) + return _create_logger_with_handler( + f"{__name__}.file.{directory}.{hostname}_{rank}", handler + ) + + +def _create_logger_with_handler(name: str, handler: logging.Handler) -> logging.Logger: + logger = logging.getLogger(name) + logger.setLevel(logging.INFO) + logger.propagate = False + if not logger.handlers: + handler.setFormatter(logging.Formatter("%(message)s")) + logger.addHandler(handler) + return logger # TODO unify this w/ `_transform_data_for_logging` if we find performance enough diff --git a/test/registered/debug_utils/test_request_logger.py b/test/registered/debug_utils/test_request_logger.py index c893a605c..286ce0ba0 100644 --- a/test/registered/debug_utils/test_request_logger.py +++ b/test/registered/debug_utils/test_request_logger.py @@ -1,6 +1,9 @@ import io import json +import tempfile +import time import unittest +from pathlib import Path import requests @@ -21,20 +24,26 @@ class BaseTestRequestLogger: @classmethod def setUpClass(cls): + cls._temp_dir_obj = tempfile.TemporaryDirectory() + cls.temp_dir = cls._temp_dir_obj.name cls.stdout = io.StringIO() cls.stderr = io.StringIO() + other_args = [ + "--log-requests", + "--log-requests-level", + "2", + "--log-requests-format", + cls.log_requests_format, + "--skip-server-warmup", + "--log-requests-target", + "stdout", + cls.temp_dir, + ] cls.process = popen_launch_server( "Qwen/Qwen3-0.6B", DEFAULT_URL_FOR_TEST, timeout=DEFAULT_TIMEOUT_FOR_SERVER_LAUNCH, - other_args=[ - "--log-requests", - "--log-requests-level", - "2", - "--log-requests-format", - cls.log_requests_format, - "--skip-server-warmup", - ], + other_args=other_args, return_stdout_stderr=(cls.stdout, cls.stderr), ) @@ -43,8 +52,12 @@ class BaseTestRequestLogger: kill_process_tree(cls.process.pid) cls.stdout.close() cls.stderr.close() + cls._temp_dir_obj.cleanup() - def _send_request(self): + def _verify_logs(self, content: str, source_name: str): + raise NotImplementedError + + def test_logging(self): response = requests.post( DEFAULT_URL_FOR_TEST + "/generate", json={ @@ -54,28 +67,34 @@ class BaseTestRequestLogger: timeout=30, ) self.assertEqual(response.status_code, 200) - return self.stdout.getvalue() + self.stderr.getvalue() + time.sleep(1) + + stdout_content = self.stdout.getvalue() + self.stderr.getvalue() + self._verify_logs(stdout_content, "stdout") + + log_files = list(Path(self.temp_dir).glob("*.log")) + self.assertGreater(len(log_files), 0, "No log files found in temp directory") + + file_content = "".join(f.read_text() for f in log_files) + self._verify_logs(file_content, "log files") class TestRequestLoggerText(BaseTestRequestLogger, CustomTestCase): log_requests_format = "text" - def test_text_format_logging(self): - combined_output = self._send_request() - self.assertIn("Receive:", combined_output) - self.assertIn("Finish:", combined_output) + def _verify_logs(self, content: str, source_name: str): + self.assertIn("Receive:", content, f"'Receive:' not found in {source_name}") + self.assertIn("Finish:", content, f"'Finish:' not found in {source_name}") class TestRequestLoggerJson(BaseTestRequestLogger, CustomTestCase): log_requests_format = "json" - def test_json_format_logging(self): - combined_output = self._send_request() - + def _verify_logs(self, content: str, source_name: str): received_found = False finished_found = False - for line in combined_output.splitlines(): - if not line.startswith("{"): + for line in content.splitlines(): + if not line.strip() or not line.startswith("{"): continue data = json.loads(line) if data.get("event") == "request.received": @@ -88,8 +107,12 @@ class TestRequestLoggerJson(BaseTestRequestLogger, CustomTestCase): self.assertIn("out", data) finished_found = True - self.assertTrue(received_found, "request.received event not found in logs") - self.assertTrue(finished_found, "request.finished event not found in logs") + self.assertTrue( + received_found, f"request.received event not found in {source_name}" + ) + self.assertTrue( + finished_found, f"request.finished event not found in {source_name}" + ) if __name__ == "__main__":