wehub-resource-sync
249 lines
8.5 KiB
Python
249 lines
8.5 KiB
Python
# SPDX-License-Identifier: Apache-2.0
|
|
# SPDX-FileCopyrightText: Copyright contributors to the vLLM project
|
|
|
|
from unittest.mock import MagicMock, patch
|
|
|
|
from vllm.entrypoints.serve.utils.request_logger import RequestLogger
|
|
|
|
|
|
def test_request_logger_log_outputs():
|
|
"""Test the new log_outputs functionality."""
|
|
# Create a mock logger to capture log calls
|
|
mock_logger = MagicMock()
|
|
|
|
with patch("vllm.entrypoints.serve.utils.request_logger.logger", mock_logger):
|
|
request_logger = RequestLogger(max_log_len=None)
|
|
|
|
# Test basic output logging
|
|
request_logger.log_outputs(
|
|
request_id="test-123",
|
|
outputs="Hello, world!",
|
|
output_token_ids=[1, 2, 3, 4],
|
|
finish_reason="stop",
|
|
is_streaming=False,
|
|
delta=False,
|
|
)
|
|
|
|
mock_logger.info.assert_called_once()
|
|
call_args = mock_logger.info.call_args.args
|
|
assert "Generated response %s%s" 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"
|
|
|
|
|
|
def test_request_logger_log_outputs_streaming_delta():
|
|
"""Test log_outputs with streaming delta mode."""
|
|
mock_logger = MagicMock()
|
|
|
|
with patch("vllm.entrypoints.serve.utils.request_logger.logger", mock_logger):
|
|
request_logger = RequestLogger(max_log_len=None)
|
|
|
|
# Test streaming delta logging
|
|
request_logger.log_outputs(
|
|
request_id="test-456",
|
|
outputs="Hello",
|
|
output_token_ids=[1],
|
|
finish_reason=None,
|
|
is_streaming=True,
|
|
delta=True,
|
|
)
|
|
|
|
mock_logger.info.assert_called_once()
|
|
call_args = mock_logger.info.call_args.args
|
|
assert "Generated response %s%s" in call_args[0]
|
|
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
|
|
|
|
|
|
def test_request_logger_log_outputs_streaming_complete():
|
|
"""Test log_outputs with streaming complete mode."""
|
|
mock_logger = MagicMock()
|
|
|
|
with patch("vllm.entrypoints.serve.utils.request_logger.logger", mock_logger):
|
|
request_logger = RequestLogger(max_log_len=None)
|
|
|
|
# Test streaming complete logging
|
|
request_logger.log_outputs(
|
|
request_id="test-789",
|
|
outputs="Complete response",
|
|
output_token_ids=[1, 2, 3],
|
|
finish_reason="length",
|
|
is_streaming=True,
|
|
delta=False,
|
|
)
|
|
|
|
mock_logger.info.assert_called_once()
|
|
call_args = mock_logger.info.call_args.args
|
|
assert "Generated response %s%s" in call_args[0]
|
|
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"
|
|
|
|
|
|
def test_request_logger_log_outputs_with_truncation():
|
|
"""Test log_outputs respects max_log_len setting."""
|
|
mock_logger = MagicMock()
|
|
|
|
with patch("vllm.entrypoints.serve.utils.request_logger.logger", mock_logger):
|
|
# Set max_log_len to 10
|
|
request_logger = RequestLogger(max_log_len=10)
|
|
|
|
# Test output truncation
|
|
long_output = "This is a very long output that should be truncated"
|
|
long_token_ids = list(range(20)) # 20 tokens
|
|
|
|
request_logger.log_outputs(
|
|
request_id="test-truncate",
|
|
outputs=long_output,
|
|
output_token_ids=long_token_ids,
|
|
finish_reason="stop",
|
|
is_streaming=False,
|
|
delta=False,
|
|
)
|
|
|
|
mock_logger.info.assert_called_once()
|
|
call_args = mock_logger.info.call_args
|
|
|
|
# Check that output was truncated to first 10 characters
|
|
logged_output = call_args[0][3]
|
|
assert logged_output == "This is a "
|
|
assert len(logged_output) == 10
|
|
|
|
# Check that token IDs were truncated to first 10 tokens
|
|
logged_token_ids = call_args[0][4]
|
|
assert logged_token_ids == list(range(10))
|
|
assert len(logged_token_ids) == 10
|
|
|
|
|
|
def test_request_logger_log_outputs_none_values():
|
|
"""Test log_outputs handles None values correctly."""
|
|
mock_logger = MagicMock()
|
|
|
|
with patch("vllm.entrypoints.serve.utils.request_logger.logger", mock_logger):
|
|
request_logger = RequestLogger(max_log_len=None)
|
|
|
|
# Test with None output_token_ids
|
|
request_logger.log_outputs(
|
|
request_id="test-none",
|
|
outputs="Test output",
|
|
output_token_ids=None,
|
|
finish_reason="stop",
|
|
is_streaming=False,
|
|
delta=False,
|
|
)
|
|
|
|
mock_logger.info.assert_called_once()
|
|
call_args = mock_logger.info.call_args.args
|
|
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"
|
|
|
|
|
|
def test_request_logger_log_outputs_empty_output():
|
|
"""Test log_outputs handles empty output correctly."""
|
|
mock_logger = MagicMock()
|
|
|
|
with patch("vllm.entrypoints.serve.utils.request_logger.logger", mock_logger):
|
|
request_logger = RequestLogger(max_log_len=5)
|
|
|
|
# Test with empty output
|
|
request_logger.log_outputs(
|
|
request_id="test-empty",
|
|
outputs="",
|
|
output_token_ids=[],
|
|
finish_reason="stop",
|
|
is_streaming=False,
|
|
delta=False,
|
|
)
|
|
|
|
mock_logger.info.assert_called_once()
|
|
call_args = mock_logger.info.call_args.args
|
|
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"
|
|
|
|
|
|
def test_request_logger_log_outputs_integration():
|
|
"""Test that log_outputs can be called alongside log_inputs."""
|
|
mock_logger = MagicMock()
|
|
|
|
with patch("vllm.entrypoints.serve.utils.request_logger.logger", mock_logger):
|
|
request_logger = RequestLogger(max_log_len=None)
|
|
|
|
# Test that both methods can be called without interference
|
|
request_logger.log_inputs(
|
|
request_id="test-integration",
|
|
prompt="Test prompt",
|
|
prompt_token_ids=[1, 2, 3],
|
|
prompt_embeds=None,
|
|
params=None,
|
|
lora_request=None,
|
|
)
|
|
|
|
request_logger.log_outputs(
|
|
request_id="test-integration",
|
|
outputs="Test output",
|
|
output_token_ids=[4, 5, 6],
|
|
finish_reason="stop",
|
|
is_streaming=False,
|
|
delta=False,
|
|
)
|
|
|
|
# Should have been called twice - once for inputs, once for outputs
|
|
assert mock_logger.info.call_count == 2
|
|
|
|
# Check that the calls were made with correct patterns
|
|
input_call = mock_logger.info.call_args_list[0][0]
|
|
output_call = mock_logger.info.call_args_list[1][0]
|
|
|
|
assert "Received request %s" in input_call[0]
|
|
assert input_call[1] == "test-integration"
|
|
|
|
assert "Generated response %s%s" in output_call[0]
|
|
assert output_call[1] == "test-integration"
|
|
|
|
|
|
def test_streaming_complete_logs_full_text_content():
|
|
"""Test that streaming complete logging includes
|
|
full accumulated text, not just token count."""
|
|
mock_logger = MagicMock()
|
|
|
|
with patch("vllm.entrypoints.serve.utils.request_logger.logger", mock_logger):
|
|
request_logger = RequestLogger(max_log_len=None)
|
|
|
|
# Test with actual content instead of token count format
|
|
full_response = "This is a complete response from streaming"
|
|
request_logger.log_outputs(
|
|
request_id="test-streaming-full-text",
|
|
outputs=full_response,
|
|
output_token_ids=None,
|
|
finish_reason="streaming_complete",
|
|
is_streaming=True,
|
|
delta=False,
|
|
)
|
|
|
|
mock_logger.info.assert_called_once()
|
|
call_args = mock_logger.info.call_args.args
|
|
|
|
# Verify the logged output is the full text, not a token count format
|
|
logged_output = call_args[3]
|
|
assert logged_output == full_response
|
|
assert "tokens>" not in logged_output
|
|
assert "streaming_complete" not in logged_output
|
|
|
|
# Verify other parameters
|
|
assert call_args[1] == "test-streaming-full-text"
|
|
assert call_args[2] == " (streaming complete)"
|
|
assert call_args[5] == "streaming_complete"
|