Skip to content

Commit ca94094

Browse files
authored
fix: refuse OutboxResponse on a closed session, write the recorded outcome on config errors, take correlation_id from headers (#225)
1 parent 68b4717 commit ca94094

9 files changed

Lines changed: 297 additions & 63 deletions

File tree

‎docs/operations/troubleshooting.md‎

Lines changed: 23 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@ owns the underlying design.
1717
| [`AckPolicy.ACK_FIRST` raises `ValueError` at registration](#ackpolicyack_first-raises-valueerror-at-registration) | By design (would defeat outbox reliability) |
1818
| [`OutboxResponse(...)` + foreign-publisher decorator logs a configuration error](#outboxresponse-foreign-publisher-decorator-config-error) | By design (dual-fire footgun) |
1919
| [Chained `OutboxResponse` retries after the handler "succeeded"](#outboxresponse-relay-publish-failure) | Follow-on publish fails post-handler; nacks the inbound row |
20+
| [`OutboxResponse` raises "no open transaction"](#outboxresponse-no-open-transaction) | The response's session closed before the publish |
2021
| [`validate_schema()` raises `ImportError`](#validate_schema-raises-importerror) | `[validate]` extra not installed |
2122

2223
## `event=lease_lost` recurring in logs { #event-lease_lost-recurring-in-logs }
@@ -245,14 +246,14 @@ See [Subscriber § Ack policy](../usage/subscriber.md#ack-policy).
245246

246247
A handler with both `@kafka_pub` and an `OutboxResponse(...)` return
247248
value logs an ERROR on every dispatch:
248-
`Outbox configuration error (fix required; row left to lease-expiry retry)`.
249+
`Outbox configuration error (fix required; row retried per its strategy)`.
249250

250251
This is by design. The combination would both insert a row into the
251252
outbox *and* publish to Kafka, a dual-fire that doubles delivery. The
252253
subscriber refuses the chain composition after the handler returns. The
253-
worker logs the error and moves on without nacking, so the retry
254-
strategy is not consulted. The row's lease expires, a later fetch
255-
reclaims it, and the cycle repeats until the configuration is fixed.
254+
worker logs the error and writes the nack the ack middleware recorded, so
255+
the row follows its retry strategy until the configuration is fixed (or,
256+
with `max_deliveries` set, until it goes terminal).
256257

257258
To confirm, inspect the handler's decorator stack and return type.
258259

@@ -291,6 +292,24 @@ a redelivery's insert is a no-op.
291292

292293
See [Publisher § Chained publishing](../usage/publisher.md#chained-publishing).
293294

295+
## `OutboxResponse` raises "no open transaction" { #outboxresponse-no-open-transaction }
296+
297+
A handler that returns `OutboxResponse(...)` logs an ERROR on every
298+
dispatch saying the response's session has no open transaction, and the
299+
inbound row keeps retrying.
300+
301+
The response is published after the handler returns. A session from
302+
`Depends(...)`, or from an `async with` block inside the handler, is
303+
already closed by then, so the follow-on row would sit in a transaction
304+
nobody commits. The subscriber refuses to publish it and the inbound row
305+
follows its retry strategy.
306+
307+
To fix it, open the session in a broker middleware so it outlives the
308+
handler, or call `broker.publish(..., session=session)` inside the
309+
handler instead of returning `OutboxResponse`.
310+
311+
See [Publisher § Chained publishing](../usage/publisher.md#chained-publishing).
312+
294313
## `validate_schema()` raises `ImportError` { #validate_schema-raises-importerror }
295314

296315
Calling `await broker.validate_schema()` raises:

‎docs/usage/fastapi.md‎

Lines changed: 6 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -96,9 +96,12 @@ delivery, opened in a `session.begin()` block, committed on handler return,
9696
rolled back on exception.
9797

9898
A handler's `AsyncSession` is therefore resolved exactly as in an HTTP
99-
route (a fresh session per delivery, not a shared instance), and
100-
`OutboxResponse(session=...)` commits the follow-on row with the handler's
101-
domain writes. See [Chained
99+
route (a fresh session per delivery, not a shared instance). Publish
100+
follow-on rows with `router.broker.publish(..., session=session)` inside
101+
the handler so they commit with its domain writes. Returning
102+
`OutboxResponse(session=session)` with this session does not work: the
103+
dependency is torn down before the response is published, so the dispatch
104+
raises and the inbound row is retried. See [Chained
102105
publishing](./publisher.md#chained-publishing).
103106

104107
## Annotated context shortcuts

‎docs/usage/publisher.md‎

Lines changed: 35 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -149,44 +149,56 @@ with your domain writes):
149149

150150
!!! note "The `session` must outlive the handler return"
151151
The returned `OutboxResponse` is published after the handler
152-
returns, so its `session` must still be open at that point. The
153-
requirement is about session *lifetime*, not any particular framework:
154-
provide the session through a dependency that the framework tears down
155-
*after* the response flow. FastAPI's `Depends(get_session)` or
156-
FastStream's own `Depends` / `Context` session both do this. Opening
157-
your own `async with session_factory() as session:` inside the handler
158-
does not work here: that session closes on `return`, before the row
159-
is inserted. In that case, call `broker.publish(..., session=session)`
160-
directly inside the `async with` instead (see
161-
[§ Not a relay decorator](#not-a-relay-decorator)).
152+
returns, so its `session` must still hold an open transaction at that
153+
point. A session from `Depends(...)` does not: FastStream and FastAPI
154+
both tear dependencies down inside the handler call, before the
155+
response is published. The same goes for an
156+
`async with session_factory() as session:` block inside the handler.
157+
In those cases the dispatch raises `RuntimeError` naming the missing
158+
transaction, logs it at ERROR, and retries the inbound row. Either
159+
open the session in a broker middleware, as below, or call
160+
`broker.publish(..., session=session)` inside the handler instead
161+
(see [§ Not a relay decorator](#not-a-relay-decorator)).
162+
163+
A broker middleware's `on_receive` / `after_processed` hooks wrap the
164+
whole dispatch, response publish included, so a session opened there
165+
covers both the handler's writes and the follow-on row. The commit runs
166+
before the ack decision, so a failed commit retries the inbound row:
162167

163168
```python
164-
from fastapi import Depends
169+
from faststream import BaseMiddleware, Context
165170
from sqlalchemy.ext.asyncio import AsyncSession
166171

167-
from faststream_outbox import OutboxResponse
168-
from faststream_outbox.annotations import OutboxMessage
172+
from faststream_outbox import OutboxBroker, OutboxResponse
169173

170-
# `get_session` is your app's session dependency — the same one your HTTP
171-
# routes use. `Depends(...)` resolves inside a handler only under the FastAPI
172-
# integration; see the engine / sessionmaker setup in the FastAPI guide.
174+
175+
class SessionPerMessage(BaseMiddleware):
176+
async def on_receive(self) -> None:
177+
self._begin = session_factory.begin()
178+
self.context.set_local("session", await self._begin.__aenter__())
179+
await super().on_receive()
180+
181+
async def after_processed(self, exc_type=None, exc_val=None, exc_tb=None) -> bool | None:
182+
await self._begin.__aexit__(exc_type, exc_val, exc_tb)
183+
return await super().after_processed(exc_type, exc_val, exc_tb)
184+
185+
186+
broker = OutboxBroker(engine, outbox_table=outbox_table, middlewares=[SessionPerMessage])
173187

174188

175189
@broker.subscriber("orders")
176-
async def handle(
177-
msg: OutboxMessage,
178-
session: AsyncSession = Depends(get_session),
179-
) -> OutboxResponse:
180-
... # process inbound
190+
async def handle(body: dict, session: AsyncSession = Context()) -> OutboxResponse:
191+
... # domain writes on `session`
181192
return OutboxResponse(
182193
body={"chained": True},
183194
queue="downstream",
184195
session=session,
185196
)
186197
```
187198

188-
`correlation_id` propagates from the inbound message if you don't set one
189-
explicitly, which is useful for trace stitching. Plain returns (`None`, `dict`,
199+
`correlation_id` comes from `headers["correlation_id"]` when you set the
200+
header but not the argument, and otherwise from the inbound message, which
201+
is useful for trace stitching. Plain returns (`None`, `dict`,
190202
etc.) are silently skipped, so handlers that don't want to chain just
191203
return normally.
192204

‎faststream_outbox/publisher/fake.py‎

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,7 @@
1919

2020
from faststream.response.publish_type import PublishType
2121

22-
from faststream_outbox.response import OutboxPublishCommand
22+
from faststream_outbox.response import OutboxPublishCommand, _OutboxConfigError
2323

2424

2525
if typing.TYPE_CHECKING:
@@ -43,6 +43,14 @@ async def _publish(
4343
) -> typing.Any:
4444
if not isinstance(cmd, OutboxPublishCommand):
4545
return None
46+
if not cmd.session.in_transaction():
47+
msg = (
48+
"OutboxResponse is published after the handler returns, but its session has no open "
49+
"transaction by then, so the follow-on row would never commit. Open the session and its "
50+
"transaction in a broker middleware so they outlive the handler, or call "
51+
"broker.publish(..., session=session) inside the handler instead."
52+
)
53+
raise _OutboxConfigError(msg)
4654
cmd.publish_type = PublishType.REPLY
4755
# ty diagnostic: ``producer.publish`` narrows to ``OutboxPublishCommand``
4856
# while ``PublisherMiddleware`` is generic over the base ``PublishCommand``.

‎faststream_outbox/response.py‎

Lines changed: 19 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,8 @@
1919
from faststream.response.response import BatchPublishCommand, PublishCommand, Response
2020
from sqlalchemy.ext.asyncio import AsyncSession
2121

22+
from faststream_outbox.message import CORRELATION_ID_HEADER
23+
2224

2325
# Matches the ``queue`` column width in ``make_outbox_table`` (``String(255)``).
2426
_MAX_QUEUE_LENGTH = 255
@@ -68,6 +70,14 @@ def _validate_publish_args(
6870
raise ValueError(msg)
6971

7072

73+
# Marker exception raised by programming guards on the dispatch path (e.g. the
74+
# OutboxResponse + foreign-publisher dual-fire guard). Inherits from
75+
# ``RuntimeError`` so ``pytest.raises(RuntimeError, ...)`` in tests catches it, but
76+
# is a distinct subclass so ``consume()`` and ``dispatch_one`` can re-raise it while
77+
# still swallowing plain handler-raised ``RuntimeError``s.
78+
class _OutboxConfigError(RuntimeError): ...
79+
80+
7181
class OutboxPublishCommand(BatchPublishCommand):
7282
"""Outbox-specific publish command: carries session + scheduling fields end-to-end."""
7383

@@ -166,9 +176,13 @@ class OutboxResponse(Response):
166176
re-runs the same validator on ``as_publish_command()``, so it stays the authoritative
167177
single source of truth and the eager checks can never drift from it.
168178
169-
``correlation_id`` defaults to the inbound message's correlation_id when not set
170-
— FastStream's ``SubscriberUsecase.process_message`` does the inheritance before
171-
publishing the response.
179+
``correlation_id`` defaults to ``headers["correlation_id"]``, then to the inbound
180+
message's correlation_id, which FastStream's ``SubscriberUsecase.process_message``
181+
fills in before publishing the response.
182+
183+
The response is published after the handler returns, so ``session`` must still
184+
hold an open transaction then; otherwise the dispatch raises ``RuntimeError`` and
185+
the inbound row is retried.
172186
"""
173187

174188
def __init__(
@@ -190,6 +204,8 @@ def __init__(
190204
activate_in=activate_in,
191205
activate_at=activate_at,
192206
)
207+
if correlation_id is None and headers:
208+
correlation_id = headers.get(CORRELATION_ID_HEADER)
193209
super().__init__(body=body, headers=headers, correlation_id=correlation_id)
194210
self.queue = queue
195211
self.session = session

‎faststream_outbox/subscriber/usecase.py‎

Lines changed: 24 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -43,7 +43,7 @@
4343
from faststream_outbox.message import ENVELOPE_MANAGED_HEADERS, OutboxInnerMessage, Retry, Terminal
4444
from faststream_outbox.parser.parser import OutboxParser
4545
from faststream_outbox.publisher.fake import OutboxFakePublisher
46-
from faststream_outbox.response import OutboxResponse
46+
from faststream_outbox.response import OutboxResponse, _OutboxConfigError
4747
from faststream_outbox.subscriber.config import OutboxSubscriberConfig, OutboxSubscriberSpecificationConfig
4848

4949

@@ -79,14 +79,6 @@ class _PendingFlush:
7979
tags: dict[str, typing.Any]
8080

8181

82-
# Marker exception raised by programming guards inside ``process_message`` (e.g.
83-
# the OutboxResponse + foreign-publisher dual-fire guard). Inherits from
84-
# ``RuntimeError`` so ``pytest.raises(RuntimeError, ...)`` in tests catches it, but
85-
# is a distinct subclass so ``consume()`` and ``dispatch_one`` can re-raise it while
86-
# still swallowing plain handler-raised ``RuntimeError``s.
87-
class _OutboxConfigError(RuntimeError): ...
88-
89-
9082
# Cap for the ``last_exception`` string written to the DLQ. Some exceptions carry
9183
# huge payloads (validation errors with the full request body, asyncpg ``DataError``
9284
# with the rejected row, etc.). An unbounded ``repr`` would extend the writer
@@ -643,11 +635,11 @@ async def _worker_inner(self, *, writer_conn: "AsyncConnection | None") -> None:
643635
# P18: a config error (e.g. OutboxResponse + foreign publisher) is not a
644636
# connection failure. Letting it propagate to _run_with_reconnect would tear
645637
# down the writer connection and back off (up to 30s), throttling unrelated
646-
# rows. Log it and continue; the row's lease expires and it is reclaimed.
647-
# Fix the configuration to stop the error.
638+
# rows. dispatch_one already wrote the recorded outcome, so the retry
639+
# strategy applies; log it and continue until the configuration is fixed.
648640
self._log(
649641
log_level=logging.ERROR,
650-
message=f"Outbox configuration error (fix required; row left to lease-expiry retry): {e!r}",
642+
message=f"Outbox configuration error (fix required; row retried per its strategy): {e!r}",
651643
exc_info=e,
652644
)
653645
finally:
@@ -722,14 +714,12 @@ async def dispatch_one( # linear pipeline: guard, consume, branch on outcome, f
722714
try:
723715
await self.consume(row)
724716
except _OutboxConfigError:
725-
# _OutboxConfigError escaping consume() is a programming guard (e.g.
726-
# the OutboxResponse + foreign-publisher dual-fire guard). Re-raise so
727-
# callers see the error immediately — sync test dispatch surfaces it
728-
# from outbox.publish; the worker loop's outer except re-raises it via
729-
# _run_with_reconnect so it's logged at ERROR level with a reconnect
730-
# backoff rather than silently ignored.
717+
# A programming guard tripped after the handler ran. Write the outcome the ack
718+
# middleware recorded, then re-raise: sync test dispatch surfaces it from
719+
# outbox.publish, and _worker_inner logs it at ERROR. Inline (buffer=None),
720+
# because a buffered row would be task_done'd twice once the error unwinds.
731721
row.handler_duration_seconds = time.perf_counter() - start_perf
732-
self._emit_dispatch_abandoned(row)
722+
await self._write_outcome(row, base, buffer=None, writer_conn=writer_conn)
733723
raise
734724
except Exception as e: # noqa: BLE001
735725
# No ack/nack metric here: the row was never marked terminal/retry, so
@@ -745,6 +735,18 @@ async def dispatch_one( # linear pipeline: guard, consume, branch on outcome, f
745735
self._emit_dispatch_abandoned(row)
746736
return False
747737
row.handler_duration_seconds = time.perf_counter() - start_perf
738+
return await self._write_outcome(row, base, buffer=buffer, writer_conn=writer_conn)
739+
740+
async def _write_outcome(
741+
self,
742+
row: OutboxInnerMessage,
743+
base: dict[str, typing.Any],
744+
*,
745+
buffer: "list[_PendingFlush] | None",
746+
writer_conn: "AsyncConnection | None",
747+
) -> bool:
748+
"""Write the outcome recorded during consume and emit its metric. Returns True iff buffered."""
749+
logger = self._outer_config.logger.logger.logger if self._outer_config.logger else None
748750
# Shutdown race: SubscriberUsecase.consume() returns None without invoking
749751
# process_message when self.running has been flipped to False by stop().
750752
# Detecting that here lets us preserve the row instead of falling through
@@ -1006,10 +1008,9 @@ async def consume(self, msg: OutboxInnerMessage) -> typing.Any:
10061008
``OutboxResponse + foreign-publisher`` dual-fire check in
10071009
``process_message``) raise ``_OutboxConfigError`` (a ``RuntimeError``
10081010
subclass) so the guard is distinguishable from handler-raised
1009-
``RuntimeError``s. Re-raising here lets ``dispatch_one`` surface it to
1010-
the caller (sync test dispatch exposes it from ``outbox.publish``; the
1011-
worker loop re-raises so the error is logged and the lease expires rather
1012-
than silently swallowing a configuration mistake).
1011+
``RuntimeError``s. Re-raising here lets ``dispatch_one`` write the recorded
1012+
outcome and surface the error: sync test dispatch exposes it from
1013+
``outbox.publish``, and the worker loop logs it at ERROR.
10131014
10141015
# Upstream equivalent (extended):
10151016
# SubscriberUsecase.consume

‎tests/test_fake.py‎

Lines changed: 61 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,7 @@
66
import warnings as _warnings
77
from collections.abc import Awaitable, Callable, Mapping
88
from types import TracebackType
9-
from unittest.mock import AsyncMock, patch
9+
from unittest.mock import AsyncMock, MagicMock, patch
1010

1111
import pytest
1212
from faststream import BaseMiddleware, FastStream, StreamMessage
@@ -2375,3 +2375,63 @@ async def handle(body: str) -> None:
23752375
await _wait_until(lambda: not test_broker.fake_client.rows, timeout=5.0)
23762376

23772377
assert sorted(handled) == sorted(f"m{i}" for i in range(30))
2378+
2379+
2380+
async def test_handler_returning_outbox_response_takes_correlation_id_from_headers() -> None:
2381+
broker = _make_broker()
2382+
downstream_cors: list[str] = []
2383+
2384+
@broker.subscriber("orders")
2385+
async def handle(body: dict) -> OutboxResponse:
2386+
del body
2387+
return OutboxResponse(
2388+
body={"v": 1}, queue="downstream", session=_fake_session(), headers={"correlation_id": "from-header"}
2389+
)
2390+
2391+
@broker.subscriber("downstream")
2392+
async def handle_next(body: dict, correlation_id: str = _Context("message.correlation_id")) -> None:
2393+
del body
2394+
downstream_cors.append(correlation_id)
2395+
2396+
async with TestOutboxBroker(broker):
2397+
await broker.publish({"x": 1}, queue="orders", correlation_id="inbound") # ty: ignore[missing-argument]
2398+
2399+
assert downstream_cors == ["from-header"]
2400+
2401+
2402+
async def test_outbox_response_on_a_session_without_a_transaction_retries_the_inbound_row() -> None:
2403+
broker = _make_broker()
2404+
closed_session = _fake_session()
2405+
closed_session.in_transaction = MagicMock(return_value=False)
2406+
2407+
@broker.subscriber("orders")
2408+
async def handle(body: dict) -> OutboxResponse:
2409+
return OutboxResponse(body=body, queue="downstream", session=closed_session)
2410+
2411+
test_broker = TestOutboxBroker(broker)
2412+
async with test_broker:
2413+
with pytest.raises(RuntimeError, match="transaction"):
2414+
await broker.publish({"x": 1}, queue="orders") # ty: ignore[missing-argument]
2415+
2416+
assert [(r.queue, r.attempts_count, r.acquired_token) for r in test_broker.fake_client.rows] == [
2417+
("orders", 1, None)
2418+
]
2419+
2420+
2421+
async def test_config_error_under_manual_ack_retries_the_row() -> None:
2422+
broker = _make_broker()
2423+
closed_session = _fake_session()
2424+
closed_session.in_transaction = MagicMock(return_value=False)
2425+
2426+
@broker.subscriber("orders", ack_policy=AckPolicy.MANUAL)
2427+
async def handle(body: dict) -> OutboxResponse:
2428+
return OutboxResponse(body=body, queue="downstream", session=closed_session)
2429+
2430+
test_broker = TestOutboxBroker(broker)
2431+
async with test_broker:
2432+
with pytest.raises(RuntimeError, match="transaction"):
2433+
await broker.publish({"x": 1}, queue="orders") # ty: ignore[missing-argument]
2434+
2435+
assert [(r.queue, r.attempts_count, r.acquired_token) for r in test_broker.fake_client.rows] == [
2436+
("orders", 1, None)
2437+
]

0 commit comments

Comments
 (0)