Skip to content

Commit fe082f1

Browse files
committed
fix: refine events websocket reconnect error handling and logging
After the first successful connection, delegate to the default `websockets` transient/fatal classification instead of retrying every error. Log graceful and abnormal closes (with close code and reason) as well as reconnect success, and cover both close paths with parametrized tests.
1 parent 474ad67 commit fe082f1

2 files changed

Lines changed: 81 additions & 47 deletions

File tree

src/apify/events/_apify_event_manager.py

Lines changed: 30 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -92,8 +92,8 @@ async def __aexit__(
9292
exc_value: BaseException | None,
9393
exc_traceback: TracebackType | None,
9494
) -> None:
95-
# Cancel the message-processing task first so that closing the websocket below is not treated
96-
# as a dropped connection and followed by a reconnect attempt.
95+
# Cancel the task before closing the websocket so that the closed connection is not treated as a drop
96+
# and followed by a reconnect attempt.
9797
if self._process_platform_messages_task and not self._process_platform_messages_task.done():
9898
self._process_platform_messages_task.cancel()
9999
with contextlib.suppress(asyncio.CancelledError):
@@ -104,21 +104,28 @@ async def __aexit__(
104104

105105
await super().__aexit__(exc_type, exc_value, exc_traceback)
106106

107-
async def _process_platform_messages(self, ws_url: str) -> None:
108-
def process_exception(exc: Exception) -> Exception | None:
109-
# Until the first connection succeeds, treat every error as fatal so that `__aenter__` fails fast.
110-
# Afterwards, treat every error as transient — the reconnect iterator keeps retrying with backoff
111-
# so that platform events (e.g. `MIGRATING`) are not missed for the rest of the run.
112-
if self._connected_to_platform_websocket is None or not self._connected_to_platform_websocket.done():
113-
return exc
114-
return None
107+
def _process_connection_exception(self, exc: Exception) -> Exception | None:
108+
"""Decide whether a failed connection attempt to the platform websocket should be retried.
109+
110+
Before the first successful connection, every error is fatal so that `__aenter__` fails fast. After that,
111+
the default `websockets` behavior decides which errors are transient and retried with exponential backoff.
112+
"""
113+
if self._connected_to_platform_websocket and self._connected_to_platform_websocket.done():
114+
return websockets.asyncio.client.process_exception(exc)
115+
return exc
115116

117+
async def _process_platform_messages(self, ws_url: str) -> None:
116118
try:
117-
async for websocket in websockets.asyncio.client.connect(ws_url, process_exception=process_exception):
119+
# Used as an async iterator, `connect` reconnects with exponential backoff whenever a connection
120+
# attempt fails with a transient error.
121+
async for websocket in websockets.asyncio.client.connect(
122+
ws_url, process_exception=self._process_connection_exception
123+
):
118124
self._platform_events_websocket = websocket
119-
connected_future = self._connected_to_platform_websocket
120-
if connected_future is not None and not connected_future.done():
121-
connected_future.set_result(True)
125+
if self._connected_to_platform_websocket and not self._connected_to_platform_websocket.done():
126+
self._connected_to_platform_websocket.set_result(True)
127+
else:
128+
logger.info('Reconnected to the platform events websocket.')
122129

123130
try:
124131
async for message in websocket:
@@ -150,12 +157,15 @@ def process_exception(exc: Exception) -> Exception | None:
150157
except Exception:
151158
logger.exception('Cannot parse Actor event', extra={'raw_message': message})
152159
except websockets.exceptions.ConnectionClosed:
153-
pass
154-
155-
logger.warning(
156-
f'Connection to platform events websocket was closed '
157-
f'(code={websocket.close_code}, reason={websocket.close_reason!r}), reconnecting...'
158-
)
160+
logger.warning(
161+
f'Connection to platform events websocket was lost '
162+
f'(code={websocket.close_code}, reason={websocket.close_reason!r}), reconnecting...'
163+
)
164+
else:
165+
logger.info(
166+
f'Connection to platform events websocket was closed '
167+
f'(code={websocket.close_code}, reason={websocket.close_reason!r}), reconnecting...'
168+
)
159169
except Exception:
160170
logger.exception('Error in websocket connection')
161171
if self._connected_to_platform_websocket is not None and not self._connected_to_platform_websocket.done():

tests/unit/events/test_apify_event_manager.py

Lines changed: 51 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,18 @@
2525
from collections.abc import AsyncGenerator, Callable
2626

2727

28+
DUMMY_SYSTEM_INFO = {
29+
'memAvgBytes': 19328860.328293584,
30+
'memCurrentBytes': 65171456,
31+
'memMaxBytes': 65171456,
32+
'cpuAvgUsage': 2.0761105633130397,
33+
'cpuMaxUsage': 53.941134593993326,
34+
'cpuCurrentUsage': 8.45549815498155,
35+
'isCpuOverloaded': False,
36+
'createdAt': '2024-08-09T16:04:16.161Z',
37+
}
38+
39+
2840
@contextlib.asynccontextmanager
2941
async def _platform_ws_server(
3042
monkeypatch: pytest.MonkeyPatch,
@@ -188,17 +200,7 @@ async def send_platform_event(event_name: Event, data: Any = None) -> None:
188200

189201
websockets.broadcast(connected_ws_clients, json.dumps(message))
190202

191-
dummy_system_info = {
192-
'memAvgBytes': 19328860.328293584,
193-
'memCurrentBytes': 65171456,
194-
'memMaxBytes': 65171456,
195-
'cpuAvgUsage': 2.0761105633130397,
196-
'cpuMaxUsage': 53.941134593993326,
197-
'cpuCurrentUsage': 8.45549815498155,
198-
'isCpuOverloaded': False,
199-
'createdAt': '2024-08-09T16:04:16.161Z',
200-
}
201-
SystemInfoEventData.model_validate(dummy_system_info)
203+
SystemInfoEventData.model_validate(DUMMY_SYSTEM_INFO)
202204

203205
async with ApifyEventManager(Configuration.get_global_configuration()) as event_manager:
204206
await client_connected.wait()
@@ -210,7 +212,7 @@ def listener(data: Any) -> None:
210212
event_manager.on(event=Event.SYSTEM_INFO, listener=listener)
211213

212214
# Test sending event with data
213-
await send_platform_event(Event.SYSTEM_INFO, dummy_system_info)
215+
await send_platform_event(Event.SYSTEM_INFO, DUMMY_SYSTEM_INFO)
214216
await poll_until_condition(lambda: len(event_calls) == 1, poll_interval=0.05)
215217
assert len(event_calls) == 1
216218
assert event_calls[0] is not None
@@ -319,32 +321,54 @@ def migrating_listener(data: Any) -> None:
319321
assert len(migration_persist_events) >= 1
320322

321323

322-
async def test_websocket_reconnects_after_connection_drop(monkeypatch: pytest.MonkeyPatch) -> None:
323-
"""Test that after a mid-stream websocket drop, the manager reconnects and keeps receiving platform events."""
324+
@pytest.mark.parametrize(
325+
('close_code', 'expected_log'),
326+
[
327+
pytest.param(1000, 'Connection to platform events websocket was closed (code=1000', id='graceful_close'),
328+
pytest.param(1011, 'Connection to platform events websocket was lost (code=1011', id='abnormal_close'),
329+
],
330+
)
331+
async def test_websocket_reconnects_after_connection_drop(
332+
monkeypatch: pytest.MonkeyPatch, caplog: pytest.LogCaptureFixture, close_code: int, expected_log: str
333+
) -> None:
334+
"""Test that the event manager logs a websocket drop, reconnects, and keeps receiving platform events.
335+
336+
Also a regression test for the resolved `_connected_to_platform_websocket` future: a mid-stream disconnect
337+
must not kill the message-processing task with `InvalidStateError`.
338+
"""
339+
caplog.set_level(logging.INFO, logger='apify')
324340
async with (
325341
_platform_ws_server(monkeypatch) as (connected_ws_clients, client_connected),
326342
ApifyEventManager(Configuration.get_global_configuration()) as event_manager,
327343
):
328344
await client_connected.wait()
329-
aborting_calls: list[Any] = []
330-
331-
def listener(data: Any) -> None:
332-
aborting_calls.append(data)
345+
assert len(connected_ws_clients) == 1
333346

334-
event_manager.on(event=Event.ABORTING, listener=listener)
347+
event_calls: list[Any] = []
348+
event_manager.on(event=Event.SYSTEM_INFO, listener=event_calls.append)
335349

336-
# Drop the connection abnormally from the server side.
350+
# Drop the connection from the server side and wait for the client to reconnect.
337351
client_connected.clear()
338352
for ws in list(connected_ws_clients):
339-
await ws.close(code=1011, reason='Simulated server error')
353+
await ws.close(code=close_code, reason='Simulated connection drop')
354+
await asyncio.wait_for(client_connected.wait(), timeout=10)
355+
# Poll because the old server-side handler may not have deregistered its connection yet.
356+
await poll_until_condition(lambda: len(connected_ws_clients) == 1, poll_interval=0.05)
357+
assert len(connected_ws_clients) == 1
358+
359+
# The message-processing task must have survived the drop.
360+
task = event_manager._process_platform_messages_task
361+
assert task is not None
362+
assert not task.done()
340363

341-
# The event manager should reconnect on its own.
342-
await asyncio.wait_for(client_connected.wait(), timeout=5.0)
364+
# Events sent over the new connection must still be emitted.
365+
websockets.broadcast(connected_ws_clients, json.dumps({'name': 'systemInfo', 'data': DUMMY_SYSTEM_INFO}))
366+
await poll_until_condition(lambda: len(event_calls) == 1, poll_interval=0.05)
367+
assert len(event_calls) == 1
343368

344-
# Events sent over the new connection must still be received.
345-
websockets.broadcast(connected_ws_clients, json.dumps({'name': 'aborting'}))
346-
await poll_until_condition(lambda: bool(aborting_calls), poll_interval=0.05)
347-
assert len(aborting_calls) == 1
369+
# Both the drop and the successful reconnect must be logged.
370+
assert expected_log in caplog.text
371+
assert 'Reconnected to the platform events websocket.' in caplog.text
348372

349373

350374
async def test_malformed_message_logs_exception(

0 commit comments

Comments
 (0)