Skip to content
Open
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
31 changes: 27 additions & 4 deletions astrbot/core/pipeline/context_utils.py
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
import asyncio
import inspect
import traceback
import typing as T
Expand Down Expand Up @@ -76,13 +77,21 @@ async def call_event_hook(
event: AstrMessageEvent,
hook_type: EventType,
*args,
timeout: float = 300.0,
Comment thread
leafliber marked this conversation as resolved.
Outdated
**kwargs,
) -> bool:
"""调用事件钩子函数

Args:
event: 事件对象
hook_type: 钩子事件类型
*args: 传递给钩子处理器的位置参数
timeout: 单个钩子处理器的超时时间(秒),超时后跳过该处理器继续执行。
设为 0 或负数则不启用超时。默认 300 秒。
**kwargs: 传递给钩子处理器的关键字参数

Returns:
bool: 如果事件被终止,返回 True
#

"""
handlers = star_handlers_registry.get_handlers_by_event_type(
Expand All @@ -92,16 +101,30 @@ async def call_event_hook(
for handler in handlers:
try:
assert inspect.iscoroutinefunction(handler.handler)
plugin_name = star_map[handler.handler_module_path].name
Comment thread
leafliber marked this conversation as resolved.
handler_name = handler.handler_name
logger.debug(
f"hook({hook_type.name}) -> {star_map[handler.handler_module_path].name} - {handler.handler_name}",
f"hook({hook_type.name}) -> {plugin_name} - {handler_name}",
)
await handler.handler(event, *args, **kwargs)
if timeout > 0:
Comment thread
leafliber marked this conversation as resolved.
Outdated
try:
await asyncio.wait_for(
handler.handler(event, *args, **kwargs),
timeout=timeout,
)
except asyncio.TimeoutError:
logger.warning(
f"hook({hook_type.name}) -> {plugin_name} - {handler_name} "
f"timed out after {timeout}s, skipping.",
)
else:
await handler.handler(event, *args, **kwargs)
except BaseException:
logger.error(traceback.format_exc())
Comment thread
sourcery-ai[bot] marked this conversation as resolved.
Comment thread
leafliber marked this conversation as resolved.

if event.is_stopped():
logger.info(
f"{star_map[handler.handler_module_path].name} - {handler.handler_name} 终止了事件传播。",
f"{plugin_name} - {handler_name} 终止了事件传播。",
)
return True

Expand Down
219 changes: 219 additions & 0 deletions tests/unit/test_call_event_hook.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,219 @@
"""Tests for call_event_hook timeout protection."""

import asyncio
from unittest.mock import AsyncMock, MagicMock, patch

import pytest

from astrbot.core.pipeline.context_utils import call_event_hook
from astrbot.core.star.star_handler import EventType


def _make_handler_metadata(
handler_coro, module_path="test_module", handler_name="test_handler"
):
handler = MagicMock()
handler.handler_module_path = module_path
handler.handler_name = handler_name
handler.handler = handler_coro
handler.enabled = True
return handler


def _make_event(stopped=False, plugins_name=None):
event = MagicMock()
event.unified_msg_origin = "test_umo"
event.plugins_name = plugins_name or []
event.is_stopped = MagicMock(return_value=stopped)
return event


@pytest.fixture
def mock_star_map():
with patch("astrbot.core.pipeline.context_utils.star_map") as sm:
sm.__getitem__ = MagicMock(return_value=MagicMock(name="TestPlugin"))
yield sm


@pytest.fixture
def mock_handlers_registry():
with patch(
"astrbot.core.pipeline.context_utils.star_handlers_registry"
) as registry:
yield registry


@pytest.mark.asyncio
async def test_hook_completes_within_timeout(mock_star_map, mock_handlers_registry):
handler_fn = AsyncMock()
handler_md = _make_handler_metadata(handler_fn)
mock_handlers_registry.get_handlers_by_event_type = MagicMock(
return_value=[handler_md]
)
event = _make_event()

result = await call_event_hook(event, EventType.OnLLMRequestEvent, timeout=5.0)

handler_fn.assert_awaited_once()
assert result is False


@pytest.mark.asyncio
async def test_hook_timeout_skips_handler(mock_star_map, mock_handlers_registry):
async def slow_handler(*args, **kwargs):
await asyncio.sleep(10)

handler_md = _make_handler_metadata(slow_handler)
mock_handlers_registry.get_handlers_by_event_type = MagicMock(
return_value=[handler_md]
)
event = _make_event()

result = await call_event_hook(event, EventType.OnLLMRequestEvent, timeout=0.5)

assert result is False


Comment thread
leafliber marked this conversation as resolved.
@pytest.mark.asyncio
async def test_hook_timeout_does_not_block_subsequent_handlers(
mock_star_map, mock_handlers_registry
):
async def slow_handler(*args, **kwargs):
await asyncio.sleep(10)

fast_handler_fn = AsyncMock()
slow_md = _make_handler_metadata(
slow_handler, module_path="slow_mod", handler_name="slow_h"
)
fast_md = _make_handler_metadata(
fast_handler_fn, module_path="fast_mod", handler_name="fast_h"
)
mock_handlers_registry.get_handlers_by_event_type = MagicMock(
return_value=[slow_md, fast_md]
)
event = _make_event()

result = await call_event_hook(event, EventType.OnLLMRequestEvent, timeout=0.5)

fast_handler_fn.assert_awaited_once()
assert result is False


@pytest.mark.asyncio
async def test_hook_timeout_zero_disables_timeout(
mock_star_map, mock_handlers_registry
):
async def slow_handler(*args, **kwargs):
await asyncio.sleep(0.3)

handler_md = _make_handler_metadata(slow_handler)
mock_handlers_registry.get_handlers_by_event_type = MagicMock(
return_value=[handler_md]
)
event = _make_event()

result = await call_event_hook(event, EventType.OnLLMRequestEvent, timeout=0)

assert result is False


@pytest.mark.asyncio
async def test_hook_timeout_negative_disables_timeout(
mock_star_map, mock_handlers_registry
):
async def slow_handler(*args, **kwargs):
await asyncio.sleep(0.3)

handler_md = _make_handler_metadata(slow_handler)
mock_handlers_registry.get_handlers_by_event_type = MagicMock(
return_value=[handler_md]
)
event = _make_event()

result = await call_event_hook(event, EventType.OnLLMRequestEvent, timeout=-1)

assert result is False


@pytest.mark.asyncio
async def test_hook_exception_continues(mock_star_map, mock_handlers_registry):
async def failing_handler(*args, **kwargs):
raise RuntimeError("test error")

handler_md = _make_handler_metadata(failing_handler)
mock_handlers_registry.get_handlers_by_event_type = MagicMock(
return_value=[handler_md]
)
event = _make_event()

result = await call_event_hook(event, EventType.OnLLMRequestEvent)

assert result is False


@pytest.mark.asyncio
async def test_hook_stops_event_propagation(mock_star_map, mock_handlers_registry):
handler_fn = AsyncMock()
handler_md = _make_handler_metadata(handler_fn)
mock_handlers_registry.get_handlers_by_event_type = MagicMock(
return_value=[handler_md]
)
event = _make_event(stopped=True)

result = await call_event_hook(event, EventType.OnLLMRequestEvent)

assert result is True


@pytest.mark.asyncio
async def test_default_timeout_value(mock_star_map, mock_handlers_registry):
import inspect

sig = inspect.signature(call_event_hook)
timeout_param = sig.parameters["timeout"]
assert timeout_param.default == 300.0


@pytest.mark.asyncio
async def test_timeout_logs_plugin_name(mock_star_map, mock_handlers_registry):
async def slow_handler(*args, **kwargs):
await asyncio.sleep(10)

handler_md = _make_handler_metadata(
slow_handler, module_path="my_plugin_module", handler_name="on_llm_req"
)
mock_handlers_registry.get_handlers_by_event_type = MagicMock(
return_value=[handler_md]
)
event = _make_event()

with patch("astrbot.core.pipeline.context_utils.logger") as mock_logger:
await call_event_hook(event, EventType.OnLLMRequestEvent, timeout=0.2)

warning_calls = [
call for call in mock_logger.warning.call_args_list if "timed out" in str(call)
]
assert len(warning_calls) == 1
warning_msg = str(warning_calls[0])
assert "on_llm_req" in warning_msg


@pytest.mark.asyncio
async def test_args_kwargs_passed_to_handler(mock_star_map, mock_handlers_registry):
handler_fn = AsyncMock()
handler_md = _make_handler_metadata(handler_fn)
mock_handlers_registry.get_handlers_by_event_type = MagicMock(
return_value=[handler_md]
)
event = _make_event()

extra_arg = MagicMock()
await call_event_hook(
event, EventType.OnLLMRequestEvent, extra_arg, timeout=5.0, extra_kwarg="test"
)

handler_fn.assert_awaited_once()
call_args = handler_fn.call_args
assert call_args[0][0] is event
assert call_args[0][1] is extra_arg
assert call_args[1].get("extra_kwarg") == "test"