Skip to content

Commit 3cbb202

Browse files
committed
fix(plugin): pair the end hook with the start hook
A start hook raising one of the three exceptions that instruct the calling thread to stop propagates out of the dispatch loop, so plugins later in the list never receive their start hook. The invocation-end hook that the propagating exception then triggers reached them anyway, leaving a plugin to tear down state it had never been told to build. Hooks after the start hook are now dispatched to the plugins that received the start hook, which makes the pairing an invariant rather than a coincidence. A plugin counts as started before its hook is dispatched, because a hook that begins and then fails may already have allocated what its end hook releases. A refused drain also requests a flush now. An exporter that re-enters a plugin hook can queue a record from the export worker, and drain() refuses the wait that hook makes. The worker exits its loop once nothing is pending and no flush is requested, so the record reached the exporters and the worker stopped, leaving a buffering exporter holding an execution's terminal telemetry when Lambda froze the environment. The request is made without waiting, so the worker stays unblocked, and its barrier covers the record just queued.
1 parent ac786f6 commit 3cbb202

4 files changed

Lines changed: 92 additions & 5 deletions

File tree

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

Lines changed: 24 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -201,8 +201,8 @@ def drain(self, execution: _ExportState) -> None:
201201
exporter re-enters a plugin hook and the hook reaches an invocation end.
202202
The call is refused and reported rather than deadlocking the invocation;
203203
the record stays queued and this same worker exports it once it resumes
204-
its loop. (Mirrors the Java
205-
``ExportScheduler.refuseWaitThatWouldBlockThePump``.)
204+
its loop, and a flush covering it is requested on the way out. (Mirrors
205+
the Java ``ExportScheduler.refuseWaitThatWouldBlockThePump``.)
206206
"""
207207
if self._is_export_worker():
208208
_logger.warning(
@@ -211,6 +211,14 @@ 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()
214222
return
215223
failed_pending: _Dropped | None = None
216224
start_error: Exception | None = None
@@ -286,6 +294,20 @@ def _is_export_worker(self) -> bool:
286294
with self._condition:
287295
return self._worker is threading.current_thread()
288296

297+
def _request_flush(self) -> None:
298+
"""Ask the worker for a flush covering everything scheduled so far.
299+
300+
Returns without waiting, so it is safe to call from the worker itself. The
301+
barrier is raised to the current schedule counter, which is what makes the
302+
flush cover a record queued moments ago rather than running before it.
303+
"""
304+
with self._condition:
305+
if self._disabled:
306+
return
307+
self._flush_requested = True
308+
self._flush_barrier = max(self._flush_barrier, self._seq)
309+
self._condition.notify_all()
310+
289311
def _disable_locked(self) -> _Dropped:
290312
"""Latch asynchronous export off for good and surrender everything queued.
291313

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

Lines changed: 8 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -903,9 +903,15 @@ def test_drain_from_the_export_worker_is_refused_rather_than_deadlocking(
903903
scheduler.schedule(ARN_A, _record("r1"))
904904

905905
assert exporter.returned.wait(timeout=10), "the refused drain must return"
906+
assert _wait_until(lambda: "refused rather than deadlocking" in caplog.text)
906907

907908
assert ("export", "r1") in exporter.calls
908-
assert "refused rather than deadlocking" in caplog.text
909+
# 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
912+
# 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+
)
909916
# The worker is still serving: a drain from any other thread completes.
910917
scheduler.drain(ARN_B)
911-
assert ("flush", None) in exporter.calls

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

Lines changed: 24 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -569,6 +569,10 @@ def __init__(self, plugins: list[DurableInstrumentationPluginFactory] | None):
569569
# on_invocation_start and emptied when the invocation scope exits.
570570
self._plugin_factories = list(plugins or [])
571571
self._plugins: list[DurableInstrumentationPlugin] = []
572+
# The subset of _plugins whose invocation-start hook has been dispatched.
573+
# Every later hook is dispatched to this list, so a plugin that never
574+
# received its start hook never receives its end hook.
575+
self._started: list[DurableInstrumentationPlugin] = []
572576
self._executor: ThreadPoolExecutor | None = None
573577
self._invocation_status: InvocationStartInfo | None = None
574578
self._operations_provider: Callable[[], Mapping[str, Operation]] | None = None
@@ -611,6 +615,7 @@ class exists to prevent; failing loudly here keeps the bug from
611615
# drained, so no queued dispatch still holds one: nothing outlives
612616
# the invocation.
613617
self._plugins = []
618+
self._started = []
614619

615620
def _create_plugins(self, info: InvocationStartInfo) -> None:
616621
"""Build this invocation's plugin instances from its start info.
@@ -704,9 +709,27 @@ def _dispatch_plugin(plugin: DurableInstrumentationPlugin, info) -> None:
704709
logger.exception("Plugin %s exception ignored", plugin.__class__.__name__)
705710

706711
def execute_plugins(self, info, sync):
712+
"""Dispatch one hook to this invocation's plugins.
713+
714+
A plugin receives a hook only once it has received the invocation-start
715+
hook, which makes the pairing an invariant rather than a coincidence.
716+
Without it one dispatch order breaks the pairing: a start hook that raises
717+
one of the three exceptions :data:`_PLUGIN_THREAD_CONTROL_EXCEPTIONS`
718+
names propagates out of this loop, so plugins later in the list never
719+
receive their start hook -- and the invocation-end hook that the
720+
propagating exception then triggers used to reach them anyway, leaving a
721+
plugin to tear down state it had never been told to build.
722+
723+
A plugin is counted as started before its start hook is dispatched rather
724+
than after, because a hook that begins and then fails may already have
725+
allocated what its end hook releases.
726+
"""
707727
if not self._executor:
708728
return
709-
for plugin in self._plugins:
729+
starting = isinstance(info, InvocationStartInfo)
730+
for plugin in self._plugins if starting else self._started:
731+
if starting:
732+
self._started.append(plugin)
710733
if sync:
711734
# this is called synchronously, so plugins will be able to manipulate thread local objects
712735
self._dispatch_plugin(plugin, info)

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

Lines changed: 36 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -647,6 +647,35 @@ 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_a_start_hook_that_stops_the_thread_leaves_later_plugins_unpaired(self):
651+
"""A plugin that never received the start hook never receives the end hook.
652+
653+
A start hook raising one of the three control exceptions propagates out of
654+
the dispatch loop, so plugins after it in the list never receive their
655+
start hook. The invocation-end hook that the propagating exception then
656+
triggers used to reach them anyway, leaving a plugin to tear down state it
657+
had never been told to build.
658+
"""
659+
later = _TrackingPlugin()
660+
host = PluginHost(
661+
plugins=[plugin_factory(_ControlOnStartPlugin()), 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+
raise AssertionError("unreachable: the start hook stops the thread")
673+
674+
with self.assertRaises(KeyboardInterrupt):
675+
handler({}, LAMBDA_CTX)
676+
677+
self.assertEqual(later.calls, [])
678+
650679
def test_an_end_hook_that_stops_the_thread_is_not_reported_twice(self):
651680
"""Exactly one end notification per invocation, whatever the hook does.
652681
@@ -2335,6 +2364,13 @@ def on_invocation_end(self, info: InvocationEndInfo) -> None:
23352364
raise KeyboardInterrupt
23362365

23372366

2367+
class _ControlOnStartPlugin(DurableInstrumentationPlugin):
2368+
"""Plugin whose start hook stops the thread, so later plugins never start."""
2369+
2370+
def on_invocation_start(self, info: InvocationStartInfo) -> None:
2371+
raise KeyboardInterrupt
2372+
2373+
23382374
class _FailingPlugin(DurableInstrumentationPlugin):
23392375
"""Plugin that raises on every hook call."""
23402376

0 commit comments

Comments
 (0)