From 27957b9f3d8de3b9ddf78edcdb8d11cb320653db Mon Sep 17 00:00:00 2001 From: ruirui6946 <142162413+ruirui6946@users.noreply.github.com> Date: Thu, 13 Aug 2026 12:50:40 +0800 Subject: [PATCH 1/2] feat: allow omitting output token IDs from logs Signed-off-by: ruirui6946 <142162413+ruirui6946@users.noreply.github.com> --- tests/entrypoints/openai/test_cli_args.py | 16 ++++++++ .../serve/utils/test_request_logger.py | 37 +++++++++++++++++++ vllm/entrypoints/openai/api_server.py | 10 ++++- vllm/entrypoints/openai/cli_args.py | 3 ++ .../entrypoints/serve/utils/request_logger.py | 37 +++++++++++++------ 5 files changed, 90 insertions(+), 13 deletions(-) diff --git a/tests/entrypoints/openai/test_cli_args.py b/tests/entrypoints/openai/test_cli_args.py index 1f764202e55e..22ac5403ffab 100644 --- a/tests/entrypoints/openai/test_cli_args.py +++ b/tests/entrypoints/openai/test_cli_args.py @@ -255,6 +255,22 @@ def test_default_chat_template_kwargs_default_none(serve_parser): assert args.default_chat_template_kwargs is None +def test_log_output_token_ids_arg(serve_parser): + assert serve_parser.parse_args([]).enable_log_output_token_ids is True + assert ( + serve_parser.parse_args( + ["--enable-log-output-token-ids"] + ).enable_log_output_token_ids + is True + ) + assert ( + serve_parser.parse_args( + ["--no-enable-log-output-token-ids"] + ).enable_log_output_token_ids + is False + ) + + def test_default_chat_template_kwargs_invalid_json(serve_parser): """Ensure invalid JSON raises an error""" with pytest.raises(SystemExit): diff --git a/tests/entrypoints/serve/utils/test_request_logger.py b/tests/entrypoints/serve/utils/test_request_logger.py index c17f2471e48a..ed4b2ced19e2 100644 --- a/tests/entrypoints/serve/utils/test_request_logger.py +++ b/tests/entrypoints/serve/utils/test_request_logger.py @@ -3,6 +3,8 @@ from unittest.mock import MagicMock, patch +import pytest + from vllm.entrypoints.serve.utils.request_logger import RequestLogger @@ -122,6 +124,41 @@ def test_request_logger_log_outputs_with_truncation(): assert len(logged_token_ids) == 10 +@pytest.mark.parametrize( + ("is_streaming", "delta", "stream_info"), + [ + (False, False, ""), + (True, True, " (streaming delta)"), + (True, False, " (streaming complete)"), + ], +) +def test_request_logger_log_outputs_without_token_ids(is_streaming, delta, stream_info): + mock_logger = MagicMock() + + with patch("vllm.entrypoints.serve.utils.request_logger.logger", mock_logger): + request_logger = RequestLogger(max_log_len=4, enable_log_output_token_ids=False) + + request_logger.log_outputs( + request_id="test-no-token-ids", + outputs="Test output", + output_token_ids=[1, 2, 3], + finish_reason="stop", + is_streaming=is_streaming, + delta=delta, + ) + + mock_logger.info.assert_called_once() + call_args = mock_logger.info.call_args.args + assert "output_token_ids" not in call_args[0] + assert call_args == ( + "Generated response %s%s: output: %r, finish_reason: %s", + "test-no-token-ids", + stream_info, + "Test", + "stop", + ) + + def test_request_logger_log_outputs_none_values(): """Test log_outputs handles None values correctly.""" mock_logger = MagicMock() diff --git a/vllm/entrypoints/openai/api_server.py b/vllm/entrypoints/openai/api_server.py index 5a6dd8c83dd0..07d513bf8c95 100644 --- a/vllm/entrypoints/openai/api_server.py +++ b/vllm/entrypoints/openai/api_server.py @@ -383,7 +383,10 @@ async def init_app_state( served_model_names = [args.model] if args.enable_log_requests: - request_logger = RequestLogger(max_log_len=args.max_log_len) + request_logger = RequestLogger( + max_log_len=args.max_log_len, + enable_log_output_token_ids=args.enable_log_output_token_ids, + ) else: request_logger = None @@ -509,7 +512,10 @@ async def init_render_app_state( ) if args.enable_log_requests: - request_logger = RequestLogger(max_log_len=args.max_log_len) + request_logger = RequestLogger( + max_log_len=args.max_log_len, + enable_log_output_token_ids=args.enable_log_output_token_ids, + ) else: request_logger = None diff --git a/vllm/entrypoints/openai/cli_args.py b/vllm/entrypoints/openai/cli_args.py index fbb5a6df5f50..9058caadbf79 100644 --- a/vllm/entrypoints/openai/cli_args.py +++ b/vllm/entrypoints/openai/cli_args.py @@ -144,6 +144,9 @@ class BaseFrontendArgs: """If set to True, log model outputs (generations). Requires `--enable-log-requests`. As with `--enable-log-requests`, information is only logged at INFO level at maximum.""" + enable_log_output_token_ids: bool = True + """If set to False, omit output token IDs from model output logs. + Relevant only if `--enable-log-outputs` is set.""" enable_log_deltas: bool = True """If set to False, output deltas will not be logged. Relevant only if --enable-log-outputs is set. diff --git a/vllm/entrypoints/serve/utils/request_logger.py b/vllm/entrypoints/serve/utils/request_logger.py index c2a77fbb4e56..e2a654708a2d 100644 --- a/vllm/entrypoints/serve/utils/request_logger.py +++ b/vllm/entrypoints/serve/utils/request_logger.py @@ -15,8 +15,14 @@ class RequestLogger: - def __init__(self, *, max_log_len: int | None) -> None: + def __init__( + self, + *, + max_log_len: int | None, + enable_log_output_token_ids: bool = True, + ) -> None: self.max_log_len = max_log_len + self.enable_log_output_token_ids = enable_log_output_token_ids if not logger.isEnabledFor(logging.INFO): logger.warning_once( @@ -81,7 +87,7 @@ def log_outputs( if outputs is not None: outputs = outputs[:max_log_len] - if output_token_ids is not None: + if self.enable_log_output_token_ids and output_token_ids is not None: # Convert to list and apply truncation output_token_ids = list(output_token_ids)[:max_log_len] @@ -89,12 +95,21 @@ def log_outputs( if is_streaming: stream_info = " (streaming delta)" if delta else " (streaming complete)" - logger.info( - "Generated response %s%s: output: %r, " - "output_token_ids: %s, finish_reason: %s", - request_id, - stream_info, - outputs, - output_token_ids, - finish_reason, - ) + if self.enable_log_output_token_ids: + logger.info( + "Generated response %s%s: output: %r, " + "output_token_ids: %s, finish_reason: %s", + request_id, + stream_info, + outputs, + output_token_ids, + finish_reason, + ) + else: + logger.info( + "Generated response %s%s: output: %r, finish_reason: %s", + request_id, + stream_info, + outputs, + finish_reason, + ) From 58eeb18aaf8ebb1825ee83da90e2225ccfbdac86 Mon Sep 17 00:00:00 2001 From: ruirui6946 <142162413+ruirui6946@users.noreply.github.com> Date: Thu, 13 Aug 2026 19:47:02 +0800 Subject: [PATCH 2/2] refactor: log output token IDs at debug level Keep generated text and finish reasons at INFO while moving output token IDs to DEBUG, matching the existing request-input logging split. Co-authored-by: OpenAI Codex Signed-off-by: ruirui6946 <142162413+ruirui6946@users.noreply.github.com> --- tests/entrypoints/openai/test_cli_args.py | 16 ------- .../serve/utils/test_request_logger.py | 46 +++++++------------ vllm/entrypoints/openai/api_server.py | 10 +--- vllm/entrypoints/openai/cli_args.py | 9 ++-- .../entrypoints/serve/utils/request_logger.py | 45 +++++++----------- 5 files changed, 38 insertions(+), 88 deletions(-) diff --git a/tests/entrypoints/openai/test_cli_args.py b/tests/entrypoints/openai/test_cli_args.py index 22ac5403ffab..1f764202e55e 100644 --- a/tests/entrypoints/openai/test_cli_args.py +++ b/tests/entrypoints/openai/test_cli_args.py @@ -255,22 +255,6 @@ def test_default_chat_template_kwargs_default_none(serve_parser): assert args.default_chat_template_kwargs is None -def test_log_output_token_ids_arg(serve_parser): - assert serve_parser.parse_args([]).enable_log_output_token_ids is True - assert ( - serve_parser.parse_args( - ["--enable-log-output-token-ids"] - ).enable_log_output_token_ids - is True - ) - assert ( - serve_parser.parse_args( - ["--no-enable-log-output-token-ids"] - ).enable_log_output_token_ids - is False - ) - - def test_default_chat_template_kwargs_invalid_json(serve_parser): """Ensure invalid JSON raises an error""" with pytest.raises(SystemExit): diff --git a/tests/entrypoints/serve/utils/test_request_logger.py b/tests/entrypoints/serve/utils/test_request_logger.py index ed4b2ced19e2..717ff190b3a7 100644 --- a/tests/entrypoints/serve/utils/test_request_logger.py +++ b/tests/entrypoints/serve/utils/test_request_logger.py @@ -1,10 +1,9 @@ # SPDX-License-Identifier: Apache-2.0 # SPDX-FileCopyrightText: Copyright contributors to the vLLM project +import logging from unittest.mock import MagicMock, patch -import pytest - from vllm.entrypoints.serve.utils.request_logger import RequestLogger @@ -29,10 +28,10 @@ def test_request_logger_log_outputs(): mock_logger.info.assert_called_once() call_args = mock_logger.info.call_args.args assert "Generated response %s%s" in call_args[0] + assert "output_token_ids" not in call_args[0] assert call_args[1] == "test-123" assert call_args[3] == "Hello, world!" - assert call_args[4] == [1, 2, 3, 4] - assert call_args[5] == "stop" + assert call_args[4] == "stop" def test_request_logger_log_outputs_streaming_delta(): @@ -58,8 +57,7 @@ def test_request_logger_log_outputs_streaming_delta(): assert call_args[1] == "test-456" assert call_args[2] == " (streaming delta)" assert call_args[3] == "Hello" - assert call_args[4] == [1] - assert call_args[5] is None + assert call_args[4] is None def test_request_logger_log_outputs_streaming_complete(): @@ -85,8 +83,7 @@ def test_request_logger_log_outputs_streaming_complete(): assert call_args[1] == "test-789" assert call_args[2] == " (streaming complete)" assert call_args[3] == "Complete response" - assert call_args[4] == [1, 2, 3] - assert call_args[5] == "length" + assert call_args[4] == "length" def test_request_logger_log_outputs_with_truncation(): @@ -119,44 +116,35 @@ def test_request_logger_log_outputs_with_truncation(): assert len(logged_output) == 10 # Check that token IDs were truncated to first 10 tokens - logged_token_ids = call_args[0][4] + mock_logger.debug.assert_called_once() + logged_token_ids = mock_logger.debug.call_args.args[3] assert logged_token_ids == list(range(10)) assert len(logged_token_ids) == 10 -@pytest.mark.parametrize( - ("is_streaming", "delta", "stream_info"), - [ - (False, False, ""), - (True, True, " (streaming delta)"), - (True, False, " (streaming complete)"), - ], -) -def test_request_logger_log_outputs_without_token_ids(is_streaming, delta, stream_info): +def test_request_logger_log_output_token_ids_require_debug(): mock_logger = MagicMock() + mock_logger.isEnabledFor.side_effect = lambda level: level >= logging.INFO with patch("vllm.entrypoints.serve.utils.request_logger.logger", mock_logger): - request_logger = RequestLogger(max_log_len=4, enable_log_output_token_ids=False) + request_logger = RequestLogger(max_log_len=4) request_logger.log_outputs( request_id="test-no-token-ids", outputs="Test output", output_token_ids=[1, 2, 3], finish_reason="stop", - is_streaming=is_streaming, - delta=delta, ) mock_logger.info.assert_called_once() - call_args = mock_logger.info.call_args.args - assert "output_token_ids" not in call_args[0] - assert call_args == ( + assert mock_logger.info.call_args.args == ( "Generated response %s%s: output: %r, finish_reason: %s", "test-no-token-ids", - stream_info, + "", "Test", "stop", ) + mock_logger.debug.assert_not_called() def test_request_logger_log_outputs_none_values(): @@ -181,8 +169,7 @@ def test_request_logger_log_outputs_none_values(): assert "Generated response %s%s" in call_args[0] assert call_args[1] == "test-none" assert call_args[3] == "Test output" - assert call_args[4] is None - assert call_args[5] == "stop" + assert call_args[4] == "stop" def test_request_logger_log_outputs_empty_output(): @@ -207,8 +194,7 @@ def test_request_logger_log_outputs_empty_output(): assert "Generated response %s%s" in call_args[0] assert call_args[1] == "test-empty" assert call_args[3] == "" - assert call_args[4] == [] - assert call_args[5] == "stop" + assert call_args[4] == "stop" def test_request_logger_log_outputs_integration(): @@ -282,4 +268,4 @@ def test_streaming_complete_logs_full_text_content(): # Verify other parameters assert call_args[1] == "test-streaming-full-text" assert call_args[2] == " (streaming complete)" - assert call_args[5] == "streaming_complete" + assert call_args[4] == "streaming_complete" diff --git a/vllm/entrypoints/openai/api_server.py b/vllm/entrypoints/openai/api_server.py index 07d513bf8c95..5a6dd8c83dd0 100644 --- a/vllm/entrypoints/openai/api_server.py +++ b/vllm/entrypoints/openai/api_server.py @@ -383,10 +383,7 @@ async def init_app_state( served_model_names = [args.model] if args.enable_log_requests: - request_logger = RequestLogger( - max_log_len=args.max_log_len, - enable_log_output_token_ids=args.enable_log_output_token_ids, - ) + request_logger = RequestLogger(max_log_len=args.max_log_len) else: request_logger = None @@ -512,10 +509,7 @@ async def init_render_app_state( ) if args.enable_log_requests: - request_logger = RequestLogger( - max_log_len=args.max_log_len, - enable_log_output_token_ids=args.enable_log_output_token_ids, - ) + request_logger = RequestLogger(max_log_len=args.max_log_len) else: request_logger = None diff --git a/vllm/entrypoints/openai/cli_args.py b/vllm/entrypoints/openai/cli_args.py index 58740af630bf..b387fb63573a 100644 --- a/vllm/entrypoints/openai/cli_args.py +++ b/vllm/entrypoints/openai/cli_args.py @@ -141,12 +141,9 @@ class BaseFrontendArgs: """Enable the `/tokenizer_info` endpoint. May expose chat templates and other tokenizer configuration.""" enable_log_outputs: bool = False - """If set to True, log model outputs (generations). - Requires `--enable-log-requests`. As with `--enable-log-requests`, - information is only logged at INFO level at maximum.""" - enable_log_output_token_ids: bool = True - """If set to False, omit output token IDs from model output logs. - Relevant only if `--enable-log-outputs` is set.""" + """If set to True, log model outputs (generations). Requires + `--enable-log-requests`. Output text and finish reasons are logged at INFO, + while output token IDs are logged at DEBUG.""" enable_log_deltas: bool = True """If set to False, output deltas will not be logged. Relevant only if --enable-log-outputs is set. diff --git a/vllm/entrypoints/serve/utils/request_logger.py b/vllm/entrypoints/serve/utils/request_logger.py index e2a654708a2d..ac10feab1011 100644 --- a/vllm/entrypoints/serve/utils/request_logger.py +++ b/vllm/entrypoints/serve/utils/request_logger.py @@ -15,14 +15,8 @@ class RequestLogger: - def __init__( - self, - *, - max_log_len: int | None, - enable_log_output_token_ids: bool = True, - ) -> None: + def __init__(self, *, max_log_len: int | None) -> None: self.max_log_len = max_log_len - self.enable_log_output_token_ids = enable_log_output_token_ids if not logger.isEnabledFor(logging.INFO): logger.warning_once( @@ -83,33 +77,28 @@ def log_outputs( delta: bool = False, ) -> None: max_log_len = self.max_log_len - if max_log_len is not None: - if outputs is not None: - outputs = outputs[:max_log_len] - - if self.enable_log_output_token_ids and output_token_ids is not None: - # Convert to list and apply truncation - output_token_ids = list(output_token_ids)[:max_log_len] + if max_log_len is not None and outputs is not None: + outputs = outputs[:max_log_len] stream_info = "" if is_streaming: stream_info = " (streaming delta)" if delta else " (streaming complete)" - if self.enable_log_output_token_ids: - logger.info( - "Generated response %s%s: output: %r, " - "output_token_ids: %s, finish_reason: %s", + if logger.isEnabledFor(logging.DEBUG): + if max_log_len is not None and output_token_ids is not None: + output_token_ids = list(output_token_ids)[:max_log_len] + + logger.debug( + "Generated response %s%s details: output_token_ids: %s", request_id, stream_info, - outputs, output_token_ids, - finish_reason, - ) - else: - logger.info( - "Generated response %s%s: output: %r, finish_reason: %s", - request_id, - stream_info, - outputs, - finish_reason, ) + + logger.info( + "Generated response %s%s: output: %r, finish_reason: %s", + request_id, + stream_info, + outputs, + finish_reason, + )