Skip to content

Commit 48f5037

Browse files
vdusekclaude
andauthored
fix: don't block StatusMessageWatcher exit with 6s sleep on exception (#753)
## Summary `StatusMessageWatcher` sleeps 6 seconds on exit to let the final status/status-message propagate. Two issues with the current placement: - **API asymmetry**: the sync `stop()` does the sleep itself, while the async twin does it in `__aexit__`. So manual sync `stop()` paid the 6s even though manual `await stop()` did not. - **Exceptional exits were delayed**: both `__exit__` and `__aexit__` ignored the `exc_type` they receive, so a `Ctrl+C` or any exception bubbling out of `with`/`async with` was held up 6 seconds. This change: - Moves `time.sleep(self._final_sleep_time_s)` out of sync `stop()` into `__exit__` (matches async shape). - Gates the sleep in both `__exit__` and `__aexit__` on `exc_type is None` so exceptional exits propagate immediately. Normal-exit behavior (the final-message capture window) is preserved. Co-authored-by: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
1 parent 69dde64 commit 48f5037

2 files changed

Lines changed: 69 additions & 2 deletions

File tree

src/apify_client/_status_message_watcher.py

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -115,7 +115,8 @@ async def __aexit__(
115115
self, exc_type: type[BaseException] | None, exc_val: BaseException | None, exc_tb: TracebackType | None
116116
) -> None:
117117
"""Cancel the logging task."""
118-
await asyncio.sleep(self._final_sleep_time_s)
118+
if exc_type is None:
119+
await asyncio.sleep(self._final_sleep_time_s)
119120
await self.stop()
120121

121122
async def _log_changed_status_message(self) -> None:
@@ -169,7 +170,6 @@ def stop(self) -> None:
169170
"""Signal the logging thread to stop logging and wait for it to finish."""
170171
if not self._logging_thread:
171172
raise RuntimeError('Logging thread is not active')
172-
time.sleep(self._final_sleep_time_s)
173173
self._stop_logging = True
174174
self._logging_thread.join()
175175
self._logging_thread = None
@@ -184,6 +184,8 @@ def __exit__(
184184
self, exc_type: type[BaseException] | None, exc_val: BaseException | None, exc_tb: TracebackType | None
185185
) -> None:
186186
"""Stop the logging thread."""
187+
if exc_type is None:
188+
time.sleep(self._final_sleep_time_s)
187189
self.stop()
188190

189191
def _log_changed_status_message(self) -> None:

tests/unit/test_logging.py

Lines changed: 65 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -44,6 +44,10 @@
4444
)
4545
_EXISTING_LOGS_BEFORE_REDIRECT_ATTACH = 3
4646

47+
# Large enough that a real sleep is clearly detectable against `_FAST_EXIT_THRESHOLD_S`.
48+
_PATCHED_FINAL_SLEEP_S = 5
49+
_FAST_EXIT_THRESHOLD_S = 1.0
50+
4751
_EXPECTED_MESSAGES_AND_LEVELS = (
4852
('2025-05-13T07:24:12.588Z ACTOR: Pulling Docker image of build.', logging.INFO),
4953
('2025-05-13T07:24:12.686Z ACTOR: Creating Docker container.', logging.INFO),
@@ -652,3 +656,64 @@ async def test_status_message_watcher_async_restart_after_normal_completion(http
652656
assert task2 is not task # New task created
653657
await task2 # Let it complete (will hit terminal status again)
654658
assert task2.done()
659+
660+
661+
@pytest.mark.usefixtures('mock_api')
662+
def test_sync_watcher_manual_stop_skips_final_sleep(
663+
httpserver: HTTPServer,
664+
monkeypatch: pytest.MonkeyPatch,
665+
) -> None:
666+
"""Manual `stop()` on the sync watcher must not pay the final sleep — only `__exit__` should."""
667+
monkeypatch.setattr(StatusMessageWatcherBase, '_final_sleep_time_s', _PATCHED_FINAL_SLEEP_S)
668+
669+
api_url = httpserver.url_for('/').removesuffix('/')
670+
run_client = ApifyClient(token='mocked_token', api_url=api_url).run(run_id=_MOCKED_RUN_ID)
671+
watcher = run_client.get_status_message_watcher(check_period=timedelta(seconds=0))
672+
673+
watcher.start()
674+
start = time.monotonic()
675+
watcher.stop()
676+
elapsed = time.monotonic() - start
677+
678+
assert elapsed < _FAST_EXIT_THRESHOLD_S, f'stop() should not sleep, took {elapsed:.2f}s'
679+
680+
681+
@pytest.mark.usefixtures('mock_api')
682+
def test_sync_watcher_exit_skips_final_sleep_on_exception(
683+
httpserver: HTTPServer,
684+
monkeypatch: pytest.MonkeyPatch,
685+
) -> None:
686+
"""Exceptional `with`-exit must not pay the final sleep so exceptions propagate immediately."""
687+
monkeypatch.setattr(StatusMessageWatcherBase, '_final_sleep_time_s', _PATCHED_FINAL_SLEEP_S)
688+
689+
api_url = httpserver.url_for('/').removesuffix('/')
690+
run_client = ApifyClient(token='mocked_token', api_url=api_url).run(run_id=_MOCKED_RUN_ID)
691+
watcher = run_client.get_status_message_watcher(check_period=timedelta(seconds=0))
692+
693+
start = time.monotonic()
694+
with pytest.raises(RuntimeError, match='boom'), watcher:
695+
raise RuntimeError('boom')
696+
elapsed = time.monotonic() - start
697+
698+
assert elapsed < _FAST_EXIT_THRESHOLD_S, f'__exit__ should skip final sleep on exception, took {elapsed:.2f}s'
699+
700+
701+
@pytest.mark.usefixtures('mock_api')
702+
async def test_async_watcher_aexit_skips_final_sleep_on_exception(
703+
httpserver: HTTPServer,
704+
monkeypatch: pytest.MonkeyPatch,
705+
) -> None:
706+
"""Exceptional `async with`-exit must not pay the final sleep so exceptions propagate immediately."""
707+
monkeypatch.setattr(StatusMessageWatcherBase, '_final_sleep_time_s', _PATCHED_FINAL_SLEEP_S)
708+
709+
api_url = httpserver.url_for('/').removesuffix('/')
710+
run_client = ApifyClientAsync(token='mocked_token', api_url=api_url).run(run_id=_MOCKED_RUN_ID)
711+
watcher = await run_client.get_status_message_watcher(check_period=timedelta(seconds=0))
712+
713+
start = time.monotonic()
714+
with pytest.raises(RuntimeError, match='boom'):
715+
async with watcher:
716+
raise RuntimeError('boom')
717+
elapsed = time.monotonic() - start
718+
719+
assert elapsed < _FAST_EXIT_THRESHOLD_S, f'__aexit__ should skip final sleep on exception, took {elapsed:.2f}s'

0 commit comments

Comments
 (0)