mirror of
https://github.com/rennf93/roboco.git
synced 2026-08-03 07:23:24 +02:00
[chore] logical-gaps: stream-bus poison-pill ACK + dead-letter, periodic reclaim, cancelled-handler marker cleanup (3 gaps)
stream_bus.py: - _handle_message isolates Event.from_json in its own try/except; an undecodable payload (unknown EventType, bad UUID/timestamp, malformed JSON) is dead-lettered then ACKed instead of falling through to the broad except that only logged — a poison pill stayed pending forever and re-failed on every reclaim. (gap: stream-bus-malformed-event-poison-pill) - _reclaim_loop spawned alongside _listen_loop in start_listening (cancelled in disconnect). XREADGROUP '>' delivers only NEW messages, so a runtime handler failure left its message pending and unretried until a restart; the loop re-runs recover_pending every 60s so the idempotency-guarded replay actually fires. (gap: stream-bus-no-runtime-reclaim-loop) - _run_handler_guarded marker cleanup catches BaseException so a handler cancelled mid-flight (asyncio.CancelledError is BaseException-derived since 3.8) clears its SET-NX marker; otherwise the guard suppressed the very redelivery that would complete the work. (gap: stream-bus-cancelled- handler-keeps-idempotency-marker) TDD: 4 red->green tests in tests/unit/events/test_bus.py.
This commit is contained in:
@@ -46,6 +46,9 @@ class StreamEventBus:
|
||||
STREAM_PREFIX = "roboco:stream:"
|
||||
DEFAULT_GROUP = "roboco-handlers"
|
||||
MAX_STREAM_LENGTH = 10000 # Trim streams to this length
|
||||
# Undecodable messages are parked here before ACK so an operator can
|
||||
# inspect a poison pill instead of losing it to a silent ACK.
|
||||
DEAD_LETTER_STREAM = "roboco:stream:dead-letter"
|
||||
|
||||
def __init__(
|
||||
self,
|
||||
@@ -66,6 +69,12 @@ class StreamEventBus:
|
||||
self._handlers: dict[EventType, list[EventHandler]] = {}
|
||||
self._running = False
|
||||
self._listen_task: asyncio.Task | None = None
|
||||
# Periodic reclaim: XREADGROUP '>' delivers only NEW messages, so a
|
||||
# runtime handler failure leaves its message pending and unretried
|
||||
# until a restart. This loop re-runs recover_pending so the
|
||||
# idempotency-guarded replay actually fires.
|
||||
self._reclaim_task: asyncio.Task | None = None
|
||||
self._reclaim_interval = 60
|
||||
|
||||
async def connect(self) -> None:
|
||||
"""Connect to Redis."""
|
||||
@@ -85,6 +94,11 @@ class StreamEventBus:
|
||||
with contextlib.suppress(asyncio.CancelledError):
|
||||
await self._listen_task
|
||||
|
||||
if self._reclaim_task:
|
||||
self._reclaim_task.cancel()
|
||||
with contextlib.suppress(asyncio.CancelledError):
|
||||
await self._reclaim_task
|
||||
|
||||
if self._redis:
|
||||
await self._redis.close()
|
||||
|
||||
@@ -205,6 +219,7 @@ class StreamEventBus:
|
||||
|
||||
self._running = True
|
||||
self._listen_task = asyncio.create_task(self._listen_loop())
|
||||
self._reclaim_task = asyncio.create_task(self._reclaim_loop())
|
||||
logger.info("StreamEventBus listening", streams=streams)
|
||||
|
||||
async def _listen_loop(self) -> None:
|
||||
@@ -235,6 +250,27 @@ class StreamEventBus:
|
||||
logger.error("Error in stream event loop", error=str(e))
|
||||
await asyncio.sleep(1)
|
||||
|
||||
async def _reclaim_loop(self) -> None:
|
||||
"""Periodically reclaim pending messages so a runtime handler failure
|
||||
is retried without waiting for an orchestrator restart.
|
||||
|
||||
``_listen_loop``'s XREADGROUP uses ``>`` (new messages only), so a
|
||||
message left pending by a transient handler failure is never
|
||||
re-delivered at runtime. This loop re-runs :meth:`recover_pending`
|
||||
every ``_reclaim_interval`` seconds; the (event.id, handler)
|
||||
idempotency guard makes the replay safe (already-succeeded handlers
|
||||
are skipped, failed ones re-run).
|
||||
"""
|
||||
while self._running:
|
||||
try:
|
||||
await asyncio.sleep(self._reclaim_interval)
|
||||
await self.recover_pending(idle_time_ms=self._reclaim_interval * 1000)
|
||||
except asyncio.CancelledError:
|
||||
break
|
||||
except Exception as e:
|
||||
logger.warning("Reclaim loop error; will retry", error=str(e))
|
||||
await asyncio.sleep(self._reclaim_interval)
|
||||
|
||||
@staticmethod
|
||||
def _to_str(value: object) -> str:
|
||||
"""Decode a Redis stream/key value (bytes or str) to str."""
|
||||
@@ -353,12 +389,48 @@ class StreamEventBus:
|
||||
return
|
||||
try:
|
||||
await handler(event)
|
||||
except Exception:
|
||||
# Clear the marker so a replay re-runs this handler — not a phantom success.
|
||||
except BaseException:
|
||||
# Clear the marker so a replay re-runs this handler — not a phantom
|
||||
# success. BaseException catches asyncio.CancelledError (3.8+ is
|
||||
# BaseException-derived) so a handler cancelled mid-flight (shutdown
|
||||
# or sibling gather cancellation) still clears its marker and is
|
||||
# re-run on reclaim; otherwise the guard would suppress the very
|
||||
# redelivery that completes the work.
|
||||
with contextlib.suppress(Exception):
|
||||
await self._redis.delete(key)
|
||||
raise
|
||||
|
||||
async def _dead_letter(
|
||||
self, stream: str, message_id: str, data: dict, reason: str
|
||||
) -> None:
|
||||
"""Park an undecodable message on the dead-letter stream for inspection.
|
||||
|
||||
Best-effort: a dead-letter publish failure is logged but never blocks
|
||||
the ACK — we will not strand a poison pill in the pending set because
|
||||
the salvage stream was unwritable.
|
||||
"""
|
||||
if self._redis is None:
|
||||
return
|
||||
try:
|
||||
await self._redis.xadd(
|
||||
self.DEAD_LETTER_STREAM,
|
||||
{
|
||||
"source_stream": stream,
|
||||
"message_id": message_id,
|
||||
"data": self._decode_event_data(data) or "",
|
||||
"reason": reason,
|
||||
},
|
||||
maxlen=self.MAX_STREAM_LENGTH,
|
||||
approximate=True,
|
||||
)
|
||||
except Exception as e:
|
||||
logger.warning(
|
||||
"Dead-letter publish failed",
|
||||
error=str(e),
|
||||
stream=stream,
|
||||
message_id=message_id,
|
||||
)
|
||||
|
||||
async def _handle_message(
|
||||
self,
|
||||
stream: str,
|
||||
@@ -369,14 +441,32 @@ class StreamEventBus:
|
||||
if not self._redis:
|
||||
return
|
||||
|
||||
try:
|
||||
event_data = self._decode_event_data(data)
|
||||
if event_data is None:
|
||||
logger.error("Invalid event data", message_id=message_id)
|
||||
await self._redis.xack(stream, self.group_name, message_id)
|
||||
return
|
||||
event_data = self._decode_event_data(data)
|
||||
if event_data is None:
|
||||
logger.error("Invalid event data", message_id=message_id)
|
||||
await self._redis.xack(stream, self.group_name, message_id)
|
||||
return
|
||||
|
||||
try:
|
||||
event = Event.from_json(event_data)
|
||||
except Exception as decode_err:
|
||||
# A message whose payload fails to decode (malformed JSON, an
|
||||
# EventType removed in a version bump, bad UUID/timestamp) is a
|
||||
# poison pill: no handler could ever process it, so retrying is
|
||||
# pointless. Dead-letter it for inspection, then ACK so the stream
|
||||
# doesn't wedge on an unkillable pending message re-failing on
|
||||
# every reclaim cycle.
|
||||
logger.error(
|
||||
"Undecodable stream message; dead-lettering and ACKing",
|
||||
message_id=message_id,
|
||||
stream=stream,
|
||||
error=str(decode_err),
|
||||
)
|
||||
await self._dead_letter(stream, message_id, data, str(decode_err))
|
||||
await self._redis.xack(stream, self.group_name, message_id)
|
||||
return
|
||||
|
||||
try:
|
||||
all_succeeded = await self._dispatch_event(event)
|
||||
|
||||
# ACK the message if all handlers succeeded
|
||||
|
||||
@@ -2,6 +2,9 @@
|
||||
|
||||
from __future__ import annotations
|
||||
|
||||
import asyncio
|
||||
import contextlib
|
||||
import json
|
||||
from typing import TYPE_CHECKING, cast
|
||||
from unittest.mock import AsyncMock, MagicMock, patch
|
||||
|
||||
@@ -153,3 +156,213 @@ async def test_dispatch_runs_handler_when_redis_guard_unavailable() -> None:
|
||||
ok = await bus._dispatch_event(event)
|
||||
assert ok is True
|
||||
assert calls == ["ran"]
|
||||
|
||||
|
||||
# --- poison-pill: an undecodable message must be ACKed, not retried forever ---
|
||||
|
||||
|
||||
class _FakeRedisStream:
|
||||
"""In-memory redis surface for the xack/xadd/group path.
|
||||
|
||||
Tracks ACKs and dead-letter xadds so the poison-pill test can assert a
|
||||
malformed message is acknowledged (not left pending) and parked on the
|
||||
dead-letter stream. ``xreadgroup`` yields nothing so a listen loop never
|
||||
spins.
|
||||
"""
|
||||
|
||||
def __init__(self) -> None:
|
||||
self.xack_calls: list[tuple[str, str, tuple[str, ...]]] = []
|
||||
self.xadd_calls: list[tuple[str, dict]] = []
|
||||
|
||||
async def xack(self, stream: str, group: str, *ids: str) -> int:
|
||||
self.xack_calls.append((stream, group, ids))
|
||||
return len(ids)
|
||||
|
||||
async def xadd(
|
||||
self,
|
||||
stream: str,
|
||||
fields: dict,
|
||||
maxlen: int | None = None,
|
||||
approximate: bool = True,
|
||||
) -> bytes:
|
||||
del maxlen, approximate
|
||||
self.xadd_calls.append((stream, dict(fields)))
|
||||
return b"1-0"
|
||||
|
||||
async def xreadgroup(self, *args: object, **kwargs: object) -> list:
|
||||
del args, kwargs
|
||||
return []
|
||||
|
||||
async def xgroup_create(self, *args: object, **kwargs: object) -> bool:
|
||||
del args, kwargs
|
||||
return True
|
||||
|
||||
async def xpending(self, *args: object, **kwargs: object) -> dict:
|
||||
del args, kwargs
|
||||
return {"pending": 0}
|
||||
|
||||
async def xpending_range(self, *args: object, **kwargs: object) -> list:
|
||||
del args, kwargs
|
||||
return []
|
||||
|
||||
async def xclaim(self, *args: object, **kwargs: object) -> list:
|
||||
del args, kwargs
|
||||
return []
|
||||
|
||||
async def set(
|
||||
self, key: str, value: str, *, nx: bool = False, ex: int | None = None
|
||||
) -> bool:
|
||||
del key, value, nx, ex
|
||||
return True
|
||||
|
||||
async def delete(self, key: str) -> int:
|
||||
del key
|
||||
return 1
|
||||
|
||||
async def get(self, key: str) -> None:
|
||||
del key
|
||||
|
||||
async def close(self) -> None:
|
||||
"""No-op close for the fake client."""
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_undecodable_message_is_acked_and_dead_lettered() -> None:
|
||||
"""A message whose payload fails Event.from_json (unknown EventType value,
|
||||
bad UUID, malformed JSON) is a poison pill: no handler could ever process
|
||||
it, so retrying is pointless. The bus must ACK it (and dead-letter it) so
|
||||
the stream doesn't wedge on an unkillable pending message re-failing on
|
||||
every reclaim."""
|
||||
|
||||
bus = StreamEventBus()
|
||||
fake = _FakeRedisStream()
|
||||
bus._redis = cast("Redis", fake)
|
||||
|
||||
invoked: list[str] = []
|
||||
|
||||
async def _handler(_event: Event) -> None:
|
||||
invoked.append("ran")
|
||||
|
||||
bus.subscribe(EventType.NOTIFICATION_SENT, _handler)
|
||||
|
||||
# type="task.bogus" is not a real EventType → EventType(...) raises ValueError
|
||||
# inside Event.from_json.
|
||||
malformed = json.dumps(
|
||||
{
|
||||
"id": "not-a-uuid",
|
||||
"type": "task.bogus_unknown",
|
||||
"data": {},
|
||||
"timestamp": "2026-06-30T00:00:00+00:00",
|
||||
}
|
||||
)
|
||||
await bus._handle_message("roboco:stream:task", "1234-0", {b"data": malformed})
|
||||
|
||||
# ACKed exactly once — not left pending for reclaim to re-fail forever.
|
||||
assert len(fake.xack_calls) == 1
|
||||
assert fake.xack_calls[0][2] == ("1234-0",)
|
||||
# Dead-lettered for inspection before the ACK.
|
||||
assert len(fake.xadd_calls) == 1
|
||||
assert fake.xadd_calls[0][0] == StreamEventBus.DEAD_LETTER_STREAM
|
||||
# No handler could run — the event never decoded.
|
||||
assert invoked == []
|
||||
|
||||
|
||||
# --- periodic reclaim: a runtime handler failure is retried without a restart ---
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_reclaim_loop_periodically_calls_recover_pending() -> None:
|
||||
"""XREADGROUP '>' delivers only NEW messages, so a handler that fails at
|
||||
runtime leaves its message pending and unretried until the orchestrator
|
||||
restarts. A periodic reclaim loop must call recover_pending so the
|
||||
idempotency-guarded replay actually fires."""
|
||||
|
||||
bus = StreamEventBus()
|
||||
bus._running = True
|
||||
bus._reclaim_interval = 60
|
||||
|
||||
calls: list[int] = []
|
||||
|
||||
async def _fake_recover(idle_time_ms: int = 60000) -> int:
|
||||
calls.append(idle_time_ms)
|
||||
bus._running = False # break the loop after the first reclaim
|
||||
return 0
|
||||
|
||||
bus.recover_pending = _fake_recover # type: ignore[method-assign]
|
||||
|
||||
async def _no_sleep(_seconds: float) -> None:
|
||||
return
|
||||
|
||||
with patch("roboco.events.stream_bus.asyncio.sleep", new=_no_sleep):
|
||||
await bus._reclaim_loop()
|
||||
|
||||
# Reclaim ran once with the interval-aligned idle window, then the loop exited.
|
||||
assert calls == [60000]
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_start_listening_spawns_reclaim_task_alongside_listen() -> None:
|
||||
"""start_listening must spawn the reclaim task, not just the listen task —
|
||||
otherwise pending messages are never re-delivered at runtime."""
|
||||
|
||||
bus = StreamEventBus()
|
||||
bus._redis = cast("Redis", _FakeRedisStream())
|
||||
|
||||
async def _noop(self: StreamEventBus) -> None:
|
||||
del self
|
||||
|
||||
async def _handler(_event: Event) -> None: ...
|
||||
|
||||
bus.subscribe(EventType.NOTIFICATION_SENT, _handler)
|
||||
|
||||
with (
|
||||
patch.object(StreamEventBus, "_listen_loop", _noop),
|
||||
patch.object(StreamEventBus, "_reclaim_loop", _noop),
|
||||
):
|
||||
await bus.start_listening()
|
||||
|
||||
try:
|
||||
assert bus._listen_task is not None
|
||||
assert bus._reclaim_task is not None
|
||||
finally:
|
||||
await bus.disconnect()
|
||||
|
||||
|
||||
# --- cancellation mid-handler must clear the idempotency marker ---
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_cancelled_handler_clears_idempotency_marker() -> None:
|
||||
"""A handler cancelled mid-flight (shutdown / sibling gather cancellation)
|
||||
is BaseException-cancelled, not Exception-raised, so the old ``except
|
||||
Exception`` left the SET-NX marker set: the message stayed pending but the
|
||||
guard then suppressed the very redelivery that would complete the work.
|
||||
The cleanup must catch BaseException so the marker is cleared and reclaim
|
||||
re-runs the handler."""
|
||||
|
||||
bus = StreamEventBus()
|
||||
fake = _FakeRedis()
|
||||
bus._redis = cast("Redis", fake)
|
||||
|
||||
started = asyncio.Event()
|
||||
proceed = asyncio.Event()
|
||||
|
||||
async def _blocking(_event: Event) -> None:
|
||||
started.set()
|
||||
await proceed.wait() # block until the dispatch task is cancelled
|
||||
|
||||
bus.subscribe(EventType.NOTIFICATION_SENT, _blocking)
|
||||
event = Event(type=EventType.NOTIFICATION_SENT, data={"task_id": "tc"})
|
||||
|
||||
task = asyncio.create_task(bus._dispatch_event(event))
|
||||
await started.wait() # handler is now blocked → marker is set
|
||||
|
||||
key = f"bus:processed:{event.id}:_blocking"
|
||||
assert key in fake.keys # marker acquired before the handler blocked
|
||||
|
||||
task.cancel()
|
||||
with contextlib.suppress(asyncio.CancelledError):
|
||||
await task
|
||||
|
||||
# Marker cleared despite cancellation → a replay re-runs the handler.
|
||||
assert key not in fake.keys
|
||||
|
||||
Reference in New Issue
Block a user