Skip to content

Commit f65283e

Browse files
fix: avoid spurious "exception in shielded future" logs on cancellation (#1624)
* fix: avoid spurious shielded future logs on cancellation * test: move context manager to cover worker shutdown * style: apply ruff formatting fixes --------- Co-authored-by: Tim Conley <tconley1428@gmail.com>
1 parent 1dcced9 commit f65283e

2 files changed

Lines changed: 94 additions & 14 deletions

File tree

temporalio/worker/_workflow_instance.py

Lines changed: 32 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -86,6 +86,17 @@
8686
LOG_IGNORE_DURING_DELETE = False
8787

8888

89+
async def _shield_await(fut: asyncio.Future[Any]) -> Any:
90+
"""Await a future without cancelling it if the awaiting task is cancelled.
91+
92+
This behaves like ``asyncio.shield(fut)`` but avoids the spurious
93+
"exception in shielded future" error log on Python 3.11+ when the
94+
awaiting task is cancelled and the future eventually fails.
95+
"""
96+
await asyncio.wait([fut])
97+
return fut.result()
98+
99+
89100
class WorkflowRunner(ABC):
90101
"""Abstract runner for workflows that creates workflow instances to run.
91102
@@ -1927,9 +1938,10 @@ async def run_activity() -> Any:
19271938
# be marked as unstarted
19281939
handle._started = True
19291940
try:
1930-
# We have to shield because we don't want the underlying
1931-
# result future to be cancelled
1932-
return await asyncio.shield(handle._result_fut)
1941+
# We use _shield_await instead of asyncio.shield to prevent
1942+
# the underlying result future from being cancelled while avoiding
1943+
# a spurious error log on Python 3.11+ (see issue #1600).
1944+
return await _shield_await(handle._result_fut)
19331945
except _ActivityDoBackoffError as err:
19341946
# We have to sleep then reschedule. Note this sleep can be
19351947
# cancelled like any other timer.
@@ -2043,9 +2055,10 @@ def apply_child_cancel_error(err: asyncio.CancelledError) -> None:
20432055
async def run_child() -> Any:
20442056
while True:
20452057
try:
2046-
# We have to shield because we don't want the future itself
2047-
# to be cancelled
2048-
return await asyncio.shield(handle._result_fut)
2058+
# We use _shield_await instead of asyncio.shield to prevent
2059+
# the future itself from being cancelled while avoiding a
2060+
# spurious error log on Python 3.11+ (see issue #1600).
2061+
return await _shield_await(handle._result_fut)
20492062
except asyncio.CancelledError as err:
20502063
apply_child_cancel_error(err)
20512064
# Clear the cancellation counter on Python 3.11+ so the
@@ -2066,9 +2079,10 @@ async def run_child() -> Any:
20662079
# Wait on start before returning
20672080
while True:
20682081
try:
2069-
# We have to shield because we don't want the future itself
2070-
# to be cancelled
2071-
await asyncio.shield(handle._start_fut)
2082+
# We use _shield_await instead of asyncio.shield to prevent
2083+
# the future itself from being cancelled while avoiding a
2084+
# spurious error log on Python 3.11+ (see issue #1600).
2085+
await _shield_await(handle._start_fut)
20722086
return handle
20732087
except asyncio.CancelledError as err:
20742088
apply_child_cancel_error(err)
@@ -2103,7 +2117,7 @@ async def _outbound_start_nexus_operation(
21032117
async def operation_handle_fn() -> OutputT:
21042118
while True:
21052119
try:
2106-
return cast(OutputT, await asyncio.shield(handle._result_fut))
2120+
return cast(OutputT, await _shield_await(handle._result_fut))
21072121
except asyncio.CancelledError:
21082122
cancel_command = self._add_command()
21092123
handle._apply_cancel_command(cancel_command)
@@ -2132,7 +2146,10 @@ async def operation_handle_fn() -> OutputT:
21322146

21332147
while True:
21342148
try:
2135-
await asyncio.shield(handle._start_fut)
2149+
# We use _shield_await instead of asyncio.shield to prevent
2150+
# the future itself from being cancelled while avoiding a
2151+
# spurious error log on Python 3.11+ (see issue #1600).
2152+
await _shield_await(handle._start_fut)
21362153
return handle
21372154
except asyncio.CancelledError:
21382155
cancel_command = self._add_command()
@@ -2671,9 +2688,10 @@ async def _signal_external_workflow(
26712688
# Wait until completed or cancelled
26722689
while True:
26732690
try:
2674-
# We have to shield because we don't want the future itself
2675-
# to be cancelled
2676-
return await asyncio.shield(done_fut)
2691+
# We use _shield_await instead of asyncio.shield to prevent
2692+
# the future itself from being cancelled while avoiding a
2693+
# spurious error log on Python 3.11+ (see issue #1600).
2694+
return await _shield_await(done_fut)
26772695
except asyncio.CancelledError:
26782696
cancel_command = self._add_command()
26792697
cancel_command.cancel_signal_workflow.seq = seq

tests/worker/test_workflow.py

Lines changed: 62 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9488,3 +9488,65 @@ async def test_workflow_uncancel_shield_signal_external(client: Client):
94889488
assert shielded_err is None, (
94899489
f"Unexpected 'exception in shielded future' log: {shielded_err}"
94909490
)
9491+
9492+
9493+
class _SlowActivity:
9494+
def __init__(self) -> None:
9495+
self.started = asyncio.Event()
9496+
9497+
@activity.defn(name="slow_activity")
9498+
async def slow_activity(self) -> None:
9499+
self.started.set()
9500+
await asyncio.sleep(60)
9501+
9502+
9503+
@workflow.defn
9504+
class _CancelInFlightActivityWorkflow:
9505+
@workflow.run
9506+
async def run(self) -> None:
9507+
await asyncio.gather(
9508+
*(
9509+
workflow.execute_activity(
9510+
"slow_activity",
9511+
start_to_close_timeout=timedelta(minutes=2),
9512+
)
9513+
for _ in range(4)
9514+
)
9515+
)
9516+
9517+
9518+
@pytest.mark.asyncio
9519+
async def test_workflow_cancel_no_shielded_future_log(
9520+
client: Client, caplog: pytest.LogCaptureFixture
9521+
):
9522+
activity_inst = _SlowActivity()
9523+
9524+
with caplog.at_level(logging.ERROR):
9525+
async with new_worker(
9526+
client,
9527+
_CancelInFlightActivityWorkflow,
9528+
activities=[activity_inst.slow_activity],
9529+
) as worker:
9530+
handle = await client.start_workflow(
9531+
_CancelInFlightActivityWorkflow.run,
9532+
id=f"workflow-{uuid.uuid4()}",
9533+
task_queue=worker.task_queue,
9534+
execution_timeout=timedelta(minutes=5),
9535+
)
9536+
9537+
# Wait for activities to start
9538+
await asyncio.wait_for(activity_inst.started.wait(), timeout=10)
9539+
9540+
# Ignore worker startup logs
9541+
caplog.clear()
9542+
9543+
await handle.cancel()
9544+
9545+
try:
9546+
await handle.result()
9547+
except WorkflowFailureError as err:
9548+
assert isinstance(err.cause, CancelledError)
9549+
9550+
assert not any(
9551+
"exception in shielded future" in record.message for record in caplog.records
9552+
)

0 commit comments

Comments
 (0)