Skip to content

Commit 84159aa

Browse files
committed
fix(plugin): finish the end dispatch, flush only new work
Two follow-ups to the previous commit, both from its own review. An end hook raising one of the three control exceptions aborted the dispatch loop, so plugins after it lost the hook that is their only chance to finish: Insight would not drain and OTel would leave spans unended. Every plugin the loop reaches has already started, so the first such exception is now held and re-raised once every plugin has been called. No other hook defers, because stopping a start-hook loop early leaves later plugins with nothing to clean up: the pairing rule withholds their end hook too. The flush a refused drain requests is now conditional on a pending record. An exporter whose flush() re-enters a plugin hook arrives at the refused drain from inside a flush, and an unconditional request asked for the next one, which re-entered and requested again for as long as the environment lived. A pending record is what distinguishes the record the re-entering hook queued from that loop.
1 parent 3cbb202 commit 84159aa

4 files changed

Lines changed: 147 additions & 25 deletions

File tree

packages/aws-durable-execution-sdk-python-insight/src/aws_durable_execution_sdk_python_insight/_export_scheduler.py

Lines changed: 25 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -211,14 +211,20 @@ def drain(self, execution: _ExportState) -> None:
211211
"refused rather than deadlocking the invocation; an exporter "
212212
"re-entered a plugin hook"
213213
)
214-
# The refused call still leaves a flush behind. The hook that
215-
# re-entered may have queued a record, and this worker exits its loop
216-
# once nothing is pending and no flush is requested -- so without the
217-
# request the record would be handed to the exporters and the worker
218-
# would stop, leaving a buffering exporter holding an execution's
219-
# terminal telemetry when Lambda freezes the environment. Requesting
220-
# it rather than waiting for it is what keeps the worker unblocked.
221-
self._request_flush()
214+
# The refused call still leaves a flush behind, but only when there is
215+
# something for it to cover. The hook that re-entered may have queued a
216+
# record, and this worker exits its loop once nothing is pending and no
217+
# flush is requested -- so without the request the record would be
218+
# handed to the exporters and the worker would stop, leaving a
219+
# buffering exporter holding an execution's terminal telemetry when
220+
# Lambda freezes the environment.
221+
#
222+
# Requesting one unconditionally would livelock instead: an exporter
223+
# whose flush() re-enters a hook arrives here from inside a flush, and
224+
# an unconditional request would ask for the next one, which re-enters
225+
# again, for as long as the environment lives. A pending record is what
226+
# distinguishes new work from that loop.
227+
self._request_flush_for_pending_records()
222228
return
223229
failed_pending: _Dropped | None = None
224230
start_error: Exception | None = None
@@ -294,15 +300,23 @@ def _is_export_worker(self) -> bool:
294300
with self._condition:
295301
return self._worker is threading.current_thread()
296302

297-
def _request_flush(self) -> None:
298-
"""Ask the worker for a flush covering everything scheduled so far.
303+
def _request_flush_for_pending_records(self) -> None:
304+
"""Ask the worker for a flush, but only if a record is waiting for one.
299305
300306
Returns without waiting, so it is safe to call from the worker itself. The
301307
barrier is raised to the current schedule counter, which is what makes the
302308
flush cover a record queued moments ago rather than running before it.
309+
310+
A pending record is the condition, not a formality. This is called from a
311+
drain refused on the worker thread, and one way to reach that is an
312+
exporter whose ``flush()`` re-enters a plugin hook: the call then arrives
313+
from inside a flush, and requesting the next one unconditionally would
314+
produce a flush that re-enters, requests, and flushes again for as long as
315+
the environment lives -- after the invocation has returned. Nothing is
316+
pending in that case, so nothing is requested.
303317
"""
304318
with self._condition:
305-
if self._disabled:
319+
if self._disabled or not self._pending:
306320
return
307321
self._flush_requested = True
308322
self._flush_barrier = max(self._flush_barrier, self._seq)

packages/aws-durable-execution-sdk-python-insight/tests/test_export_scheduler.py

Lines changed: 63 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -866,22 +866,27 @@ def drain(arn: str) -> None:
866866

867867

868868
class ReentrantDrainExporter(CaptureExporter):
869-
"""Exporter that drains from inside export(), as a plugin hook would.
869+
"""Exporter that queues a record and drains from inside export().
870870
871-
An exporter that re-enters a plugin hook reaches ``on_invocation_end``, and
872-
that hook drains. The re-entry therefore arrives on the export worker thread,
873-
which is the one thread able to serve the wait.
871+
This is what an exporter re-entering a plugin hook produces: the hook emits
872+
its record and then, at an invocation end, drains. Both arrive on the export
873+
worker, which is the one thread able to serve the wait.
874874
"""
875875

876876
def __init__(self) -> None:
877877
super().__init__()
878878
self.scheduler: _ArnScheduler | None = None
879879
self.returned = threading.Event()
880+
self._reentered = False
880881

881882
def export(self, record: dict[str, Any]) -> None:
882883
super().export(record)
883884
assert self.scheduler is not None
884-
self.scheduler.drain(ARN_A)
885+
if self._reentered:
886+
return
887+
self._reentered = True
888+
self.scheduler.schedule(ARN_B, _record("r2"))
889+
self.scheduler.drain(ARN_B)
885890
self.returned.set()
886891

887892

@@ -907,11 +912,59 @@ def test_drain_from_the_export_worker_is_refused_rather_than_deadlocking(
907912

908913
assert ("export", "r1") in exporter.calls
909914
# The refused drain still leaves a flush behind, with no external drain to ask
910-
# for one. The re-entering hook may have queued a record, and the worker exits
911-
# once nothing is pending and no flush is requested, so without the request a
915+
# for one. The re-entering hook queued a record, and the worker exits once
916+
# nothing is pending and no flush is requested, so without the request a
912917
# buffering exporter would be holding that record when the environment froze.
913-
assert _wait_until(lambda: ("flush", None) in exporter.calls), (
914-
"a refused drain must request a flush on its way out"
915-
)
918+
assert _wait_until(lambda: ("export", "r2") in exporter.calls)
919+
assert _wait_until(
920+
lambda: exporter.calls.index(("flush", None))
921+
> exporter.calls.index(("export", "r2"))
922+
), "a refused drain must request a flush that covers the record it queued"
916923
# The worker is still serving: a drain from any other thread completes.
917924
scheduler.drain(ARN_B)
925+
926+
927+
class ReentrantFlushExporter(CaptureExporter):
928+
"""Exporter whose flush() drains, as a hook re-entered from a flush would.
929+
930+
An exporter that re-enters a plugin hook from ``flush()`` reaches
931+
``on_invocation_end``, which drains. The drain arrives on the export worker
932+
from inside a flush, with nothing pending.
933+
"""
934+
935+
def __init__(self) -> None:
936+
super().__init__()
937+
self.scheduler: _ArnScheduler | None = None
938+
self.flushes = 0
939+
940+
def flush(self) -> None:
941+
super().flush()
942+
self.flushes += 1
943+
assert self.scheduler is not None
944+
self.scheduler.drain(ARN_A)
945+
946+
947+
def test_a_drain_refused_from_inside_a_flush_does_not_re_arm_it() -> None:
948+
"""A refused drain with nothing pending asks for no further flush.
949+
950+
Requesting one unconditionally would keep the worker flushing for as long as
951+
the environment lived: the flush re-enters the hook, the hook drains, the
952+
refused drain asks for the next flush. A pending record is what distinguishes
953+
new work from that loop, so a drain refused from inside a flush leaves no
954+
request behind.
955+
"""
956+
exporter = ReentrantFlushExporter()
957+
scheduler = _ArnScheduler([exporter])
958+
exporter.scheduler = scheduler
959+
960+
scheduler.schedule(ARN_A, _record("r1"))
961+
scheduler.drain(ARN_A)
962+
963+
flushes_after_drain = exporter.flushes
964+
assert flushes_after_drain >= 1, "the drain must have flushed"
965+
966+
# Give a re-armed flush time to appear. The worker retires when nothing is
967+
# pending and no flush is requested, so a bounded count here is the whole
968+
# assertion: an unconditional request never settles.
969+
assert not _wait_until(lambda: exporter.flushes > flushes_after_drain, timeout=1.0)
970+
assert _wait_until(lambda: not scheduler._worker_alive())

packages/aws-durable-execution-sdk-python/src/aws_durable_execution_sdk_python/plugin.py

Lines changed: 25 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -723,19 +723,40 @@ def execute_plugins(self, info, sync):
723723
A plugin is counted as started before its start hook is dispatched rather
724724
than after, because a hook that begins and then fails may already have
725725
allocated what its end hook releases.
726+
727+
The invocation-end hook is the one hook that finishes dispatching even
728+
when a plugin raises one of those three. Every plugin it reaches has
729+
already started, so cutting the loop short costs a plugin its only chance
730+
to finish: Insight would not drain, and OTel would leave spans unended.
731+
The first such exception is held and re-raised once every plugin has been
732+
called, so the thread still stops and nothing is swallowed. No other hook
733+
defers: stopping a start-hook loop early leaves later plugins with nothing
734+
to clean up, because the pairing rule above then withholds their end hook
735+
too.
726736
"""
727737
if not self._executor:
728738
return
729739
starting = isinstance(info, InvocationStartInfo)
740+
ending = isinstance(info, InvocationEndInfo)
741+
deferred_control: BaseException | None = None
730742
for plugin in self._plugins if starting else self._started:
731743
if starting:
732744
self._started.append(plugin)
733-
if sync:
734-
# this is called synchronously, so plugins will be able to manipulate thread local objects
735-
self._dispatch_plugin(plugin, info)
736-
else:
745+
if not sync:
737746
# this is called asynchronously, so plugins cannot manipulate thread local objects
738747
self._executor.submit(self._dispatch_plugin, plugin, info)
748+
continue
749+
# this is called synchronously, so plugins will be able to manipulate thread local objects
750+
if not ending:
751+
self._dispatch_plugin(plugin, info)
752+
continue
753+
try:
754+
self._dispatch_plugin(plugin, info)
755+
except _PLUGIN_THREAD_CONTROL_EXCEPTIONS as control:
756+
if deferred_control is None:
757+
deferred_control = control
758+
if deferred_control is not None:
759+
raise deferred_control
739760

740761
def _snapshot_operation_infos(
741762
self,

packages/aws-durable-execution-sdk-python/tests/plugin_test.py

Lines changed: 34 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -647,6 +647,40 @@ def create_plugin(self, info: InvocationStartInfo) -> _TrackingPlugin:
647647
self.assertEqual(built[0].calls, ["invocation_start:req-1"])
648648
self.assertEqual(built[1].calls, ["invocation_start:req-2"])
649649

650+
def test_an_end_hook_that_stops_the_thread_still_finishes_the_dispatch(self):
651+
"""Every started plugin receives the end hook, then the thread stops.
652+
653+
The end hook is a plugin's only chance to finish -- Insight drains there
654+
and OTel ends its spans -- so a plugin raising one of the three control
655+
exceptions must not cost the plugins after it in the list their own end
656+
hook. The exception is held and re-raised once every plugin has been
657+
called.
658+
"""
659+
later = _TrackingPlugin()
660+
host = PluginHost(
661+
plugins=[plugin_factory(_ControlOnEndPlugin()), plugin_factory(later)]
662+
)
663+
664+
@host.handle_durable_output
665+
def handler(event, context, plugin_executor):
666+
plugin_executor.on_invocation_start(
667+
execution_arn="arn:exec",
668+
lambda_context=LAMBDA_CTX,
669+
execution_start_time=START_TS,
670+
is_first_invocation=True,
671+
)
672+
return {
673+
"Status": ServiceInvocationStatus.SUCCEEDED.value,
674+
"Result": None,
675+
}
676+
677+
with self.assertRaises(KeyboardInterrupt):
678+
handler({}, LAMBDA_CTX)
679+
680+
self.assertEqual(
681+
later.calls, ["invocation_start:req-1", "invocation_end:req-1"]
682+
)
683+
650684
def test_a_start_hook_that_stops_the_thread_leaves_later_plugins_unpaired(self):
651685
"""A plugin that never received the start hook never receives the end hook.
652686

0 commit comments

Comments
 (0)