pyTwitchAPI icon indicating copy to clipboard operation
pyTwitchAPI copied to clipboard

When internet is down, library will eventually fail to connect without notifying client

Open adhawkins opened this issue 1 year ago • 4 comments

I have a chat bot based on pytwitchapi. My internet was down for a few hours recently, and it was only when I happened to notice the bot wasn't working when I realised that it had failed to connect to the Twitch API (understandably) and gave up attempting to reconnect:

Jul 17 01:55:13 xcp-dev python[808]: Reached timeout for websocket receive, will attempt a reconnect
Jul 17 01:55:16 xcp-dev python[808]: connection attempt failed, retry in 0s...
Jul 17 01:55:20 xcp-dev python[808]: connection attempt failed, retry in 1s...
Jul 17 01:55:21 xcp-dev python[808]: connection attempt failed, retry in 2s...
Jul 17 01:55:23 xcp-dev python[808]: connection attempt failed, retry in 4s...
Jul 17 01:55:27 xcp-dev python[808]: connection attempt failed, retry in 8s...
Jul 17 01:55:39 xcp-dev python[808]: connection attempt failed, retry in 16s...
Jul 17 01:55:58 xcp-dev python[808]: connection attempt failed, retry in 32s...
Jul 17 01:56:33 xcp-dev python[808]: connection attempt failed, retry in 64s...
Jul 17 01:56:50 xcp-dev python[808]: Reached timeout for websocket receive, will attempt a reconnect
Jul 17 01:56:53 xcp-dev python[808]: connection attempt failed, retry in 0s...
Jul 17 01:56:57 xcp-dev python[808]: connection attempt failed, retry in 1s...
Jul 17 01:56:58 xcp-dev python[808]: connection attempt failed, retry in 2s...
Jul 17 01:57:00 xcp-dev python[808]: connection attempt failed, retry in 4s...
Jul 17 01:57:04 xcp-dev python[808]: connection attempt failed, retry in 8s...
Jul 17 01:57:15 xcp-dev python[808]: connection attempt failed, retry in 16s...
Jul 17 01:57:35 xcp-dev python[808]: connection attempt failed, retry in 32s...
Jul 17 01:57:40 xcp-dev python[808]: connection attempt failed, retry in 128s...
Jul 17 01:58:10 xcp-dev python[808]: connection attempt failed, retry in 64s...
Jul 17 01:59:17 xcp-dev python[808]: connection attempt failed, retry in 128s...
Jul 17 01:59:48 xcp-dev python[808]: Connection to chat websocket lost and unable to reestablish connection!
Jul 17 01:59:48 xcp-dev python[808]: Traceback (most recent call last):
Jul 17 01:59:48 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/aiohttp/client_ws.py", line 244, in receive
Jul 17 01:59:48 xcp-dev python[808]:     msg = await self._reader.read()
Jul 17 01:59:48 xcp-dev python[808]:           ^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 17 01:59:48 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/aiohttp/streams.py", line 681, in read
Jul 17 01:59:48 xcp-dev python[808]:     return await super().read()
Jul 17 01:59:48 xcp-dev python[808]:            ^^^^^^^^^^^^^^^^^^^^
Jul 17 01:59:48 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/aiohttp/streams.py", line 640, in read
Jul 17 01:59:48 xcp-dev python[808]:     await self._waiter
Jul 17 01:59:48 xcp-dev python[808]: asyncio.exceptions.CancelledError
Jul 17 01:59:48 xcp-dev python[808]: During handling of the above exception, another exception occurred:
Jul 17 01:59:48 xcp-dev python[808]: Traceback (most recent call last):
Jul 17 01:59:48 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/twitchAPI/chat/__init__.py", line 913, in __task_receive
Jul 17 01:59:48 xcp-dev python[808]:     message = await self.__connection.receive(timeout=receive_timeout)
Jul 17 01:59:48 xcp-dev python[808]:               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 17 01:59:48 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/aiohttp/client_ws.py", line 243, in receive
Jul 17 01:59:48 xcp-dev python[808]:     async with async_timeout.timeout(timeout or self._receive_timeout):
Jul 17 01:59:48 xcp-dev python[808]:   File "/usr/lib/python3.11/asyncio/timeouts.py", line 98, in __aexit__
Jul 17 01:59:48 xcp-dev python[808]:     raise TimeoutError
Jul 17 01:59:48 xcp-dev python[808]: TimeoutError
Jul 17 01:59:48 xcp-dev python[808]: During handling of the above exception, another exception occurred:
Jul 17 01:59:48 xcp-dev python[808]: Traceback (most recent call last):
Jul 17 01:59:48 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/twitchAPI/chat/__init__.py", line 918, in __task_receive
Jul 17 01:59:48 xcp-dev python[808]:     await self._handle_base_reconnect()
Jul 17 01:59:48 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/twitchAPI/chat/__init__.py", line 956, in _handle_base_reconnect
Jul 17 01:59:48 xcp-dev python[808]:     await self.__connect(is_startup=False)
Jul 17 01:59:48 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/twitchAPI/chat/__init__.py", line 866, in __connect
Jul 17 01:59:48 xcp-dev python[808]:     raise TwitchBackendException('can\'t connect')
Jul 17 01:59:48 xcp-dev python[808]: twitchAPI.type.TwitchBackendException: can't connect
Jul 17 02:01:25 xcp-dev python[808]: Connection to chat websocket lost and unable to reestablish connection!
Jul 17 02:01:25 xcp-dev python[808]: Traceback (most recent call last):
Jul 17 02:01:25 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/aiohttp/client_ws.py", line 244, in receive
Jul 17 02:01:25 xcp-dev python[808]:     msg = await self._reader.read()
Jul 17 02:01:25 xcp-dev python[808]:           ^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 17 02:01:25 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/aiohttp/streams.py", line 681, in read
Jul 17 02:01:25 xcp-dev python[808]:     return await super().read()
Jul 17 02:01:25 xcp-dev python[808]:            ^^^^^^^^^^^^^^^^^^^^
Jul 17 02:01:25 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/aiohttp/streams.py", line 640, in read
Jul 17 02:01:25 xcp-dev python[808]:     await self._waiter
Jul 17 02:01:25 xcp-dev python[808]: asyncio.exceptions.CancelledError
Jul 17 02:01:25 xcp-dev python[808]: During handling of the above exception, another exception occurred:
Jul 17 02:01:25 xcp-dev python[808]: Traceback (most recent call last):
Jul 17 02:01:25 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/twitchAPI/chat/__init__.py", line 913, in __task_receive
Jul 17 02:01:25 xcp-dev python[808]:     message = await self.__connection.receive(timeout=receive_timeout)
Jul 17 02:01:25 xcp-dev python[808]:               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 17 02:01:25 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/aiohttp/client_ws.py", line 243, in receive
Jul 17 02:01:25 xcp-dev python[808]:     async with async_timeout.timeout(timeout or self._receive_timeout):
Jul 17 02:01:25 xcp-dev python[808]:   File "/usr/lib/python3.11/asyncio/timeouts.py", line 98, in __aexit__
Jul 17 02:01:25 xcp-dev python[808]:     raise TimeoutError
Jul 17 02:01:25 xcp-dev python[808]: TimeoutError
Jul 17 02:01:25 xcp-dev python[808]: During handling of the above exception, another exception occurred:
Jul 17 02:01:25 xcp-dev python[808]: Traceback (most recent call last):
Jul 17 02:01:25 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/twitchAPI/chat/__init__.py", line 918, in __task_receive
Jul 17 02:01:25 xcp-dev python[808]:     await self._handle_base_reconnect()
Jul 17 02:01:25 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/twitchAPI/chat/__init__.py", line 956, in _handle_base_reconnect
Jul 17 02:01:25 xcp-dev python[808]:     await self.__connect(is_startup=False)
Jul 17 02:01:25 xcp-dev python[808]:   File "/home/andy/software/pytwitchchatlogger/venv/lib/python3.11/site-packages/twitchAPI/chat/__init__.py", line 866, in __connect
Jul 17 02:01:25 xcp-dev python[808]:     raise TwitchBackendException('can\'t connect')
Jul 17 02:01:25 xcp-dev python[808]: twitchAPI.type.TwitchBackendException: can't connect
Jul 18 10:22:28 xcp-dev systemd[751]: Stopping pytwitchchatlogger.service...

There apparently isn't a way that this exception could be caught so that the client can tell the library to initiate a re-connect.

Posting here at Lena's request (from Discord)

adhawkins avatar Jul 18 '24 15:07 adhawkins

Workaround, we can increase reconnect_delay_steps, to some high value. This is will increase chance to reconnect automatically. https://github.com/Teekeks/pyTwitchAPI/blob/2b90657491108cec172578afa0967c88282eddd0/twitchAPI/chat/init.py#L589C9-L589C81

Modify Chat instance, some like this:

chat = await Chat(twitch)
reconnect_steps = [i*i for i in range(50)]  # 11 hours
print(f"Hours to reconnect: {sum(reconnect_steps) // 3600}")  # replace to logger
chat.reconnect_delay_steps = reconnect_steps

I not verified this, but it can work.

There apparently isn't a way that this exception could be caught

So except TwitchBackendException: ... not working? According to logs this is possible.

iturdikulov avatar Sep 27 '24 05:09 iturdikulov

correct, thats what that var is for

Teekeks avatar Sep 27 '24 05:09 Teekeks

Have this same issue with eventsub the exception is never called and handled in except TwitchBackendException: in my try block. Stopped the websocket and api using a KeyboardInterrupt to call the .stop() and .close() functions.

12:41:01 WARNING  keepalive missed, connection lost. reconnecting...
12:41:01 DEBUG    reconnecting using wss://eventsub.wss.twitch.tv/ws...
12:41:01 WARNING  connection attempt failed, retry in 0 seconds...
12:41:01 WARNING  connection attempt failed, retry in 1 seconds...
12:41:02 WARNING  connection attempt failed, retry in 2 seconds...
12:41:04 WARNING  connection attempt failed, retry in 4 seconds...
12:41:08 WARNING  connection attempt failed, retry in 8 seconds...
12:41:11 DEBUG    websocket is closing
12:41:16 WARNING  connection attempt failed, retry in 16 seconds...
12:41:32 WARNING  connection attempt failed, retry in 32 seconds...
12:42:10 WARNING  connection attempt failed, retry in 64 seconds...
12:43:14 WARNING  connection attempt failed, retry in 128 seconds...

13:39:21 DEBUG    stopping websocket EventSub...
13:39:22 ERROR    Task exception was never retrieved
future: <Task finished name='Task-17' coro=<EventSubWebsocket._task_reconnect_handler() done, defined at /home/scott/.local/lib/python3.12/site-packages/twitchAPI/eventsub/websocket.py:303> exception=TwitchBackendException("can't connect to EventSub websocket wss://eventsub.wss.twitch.tv/ws")>
Traceback (most recent call last):
  File "/home/scott/.local/lib/python3.12/site-packages/twitchAPI/eventsub/websocket.py", line 312, in _task_reconnect_handler
    await self._connect(is_startup=False)
  File "/home/scott/.local/lib/python3.12/site-packages/twitchAPI/eventsub/websocket.py", line 275, in _connect
    raise TwitchBackendException(f'can\'t connect to EventSub websocket {self.connection_url}')
twitchAPI.type.TwitchBackendException: can't connect to EventSub websocket wss://eventsub.wss.twitch.tv/ws

Got around it by modifying .reconnect_delay_steps from https://github.com/Teekeks/pyTwitchAPI/issues/318#issuecomment-2378449708 so far, at least it keeps retrying after when it would do the 128sec wait.

ToastedWookiee avatar Dec 18 '24 00:12 ToastedWookiee

thinking more about this: it does not really make sense to stop retrying if the error is a connection problem.

I will probably change it to retry indefinitely with the period of the longest entry in that list

Teekeks avatar Dec 19 '24 03:12 Teekeks