search

Danielhiversen / PyGraphqlWebsocketManager

Python code for graphql websocket client
GNU General Public License v3.0
0 stars 2 forks source link

Race condition? #33

Open ztamas83 opened 1 year ago

ztamas83 commented 1 year ago

When there's a loss of connection the manager tries to re-initiate the connection. I may be wrong due to my knowledge on the asyncio and event loop handling but for me it seems that the subscribe() function can be called before the running() function actually creates the websocket connection.

In this case we can end up with a timeout here that would go unnoticed and no active subscriptions created: https://github.com/Danielhiversen/PyGraphqlWebsocketManager/blob/ee7b05f5485cacdbe03b02fd262cebcc514c87ad/graphql_subscription_manager/__init__.py#L152

while time() - start_time < timeout:
            if self.websocket is None or not self.websocket.open or not self.is_running:
                await asyncio.sleep(0.1)
                continue

            await self.websocket.send(json_subscription)
            _LOGGER.debug("New subscription %s", current_session_id)
            return current_session_id
 return None
ztamas83 commented 1 year ago

Here's the problem, too many open connections and then there is no retry, just dead

2022-11-09 09:57:55.906 DEBUG (MainThread) [graphql_subscription_manager] Start state None.
2022-11-09 09:57:55.908 DEBUG (MainThread) [graphql_subscription_manager] websocket is None
2022-11-09 09:57:55.920 DEBUG (MainThread) [graphql_subscription_manager] Starting
2022-11-09 09:57:56.251 DEBUG (MainThread) [websockets.client] = connection is CONNECTING
2022-11-09 09:57:56.349 DEBUG (MainThread) [websockets.client] > GET /v1-beta/gql/subscriptions HTTP/1.1
2022-11-09 09:57:56.349 DEBUG (MainThread) [websockets.client] > Host: api.tibber.com
2022-11-09 09:57:56.349 DEBUG (MainThread) [websockets.client] > Upgrade: websocket
2022-11-09 09:57:56.350 DEBUG (MainThread) [websockets.client] > Connection: Upgrade
2022-11-09 09:57:56.350 DEBUG (MainThread) [websockets.client] > Sec-WebSocket-Key: 0+B/Cpeprd9/QbKElbZYmw==
2022-11-09 09:57:56.350 DEBUG (MainThread) [websockets.client] > Sec-WebSocket-Version: 13
2022-11-09 09:57:56.350 DEBUG (MainThread) [websockets.client] > Sec-WebSocket-Extensions: permessage-deflate; client_max_window_bits
2022-11-09 09:57:56.350 DEBUG (MainThread) [websockets.client] > Sec-WebSocket-Protocol: graphql-transport-ws
2022-11-09 09:57:56.350 DEBUG (MainThread) [websockets.client] > User-Agent: HomeAssistant/2022.12.0.dev0 aiohttp/3.8.1 Python/3.9 pyTibber/0.25.7b graphql-subscription-manager/0.6.1
2022-11-09 09:57:56.407 DEBUG (MainThread) [websockets.client] < HTTP/1.1 101 Switching Protocols
2022-11-09 09:57:56.407 DEBUG (MainThread) [websockets.client] < Date: Wed, 09 Nov 2022 09:57:56 GMT
2022-11-09 09:57:56.407 DEBUG (MainThread) [websockets.client] < Upgrade: websocket
2022-11-09 09:57:56.407 DEBUG (MainThread) [websockets.client] < Sec-WebSocket-Accept: gKqnxDWleQRbURozAAY+kYgzADs=
2022-11-09 09:57:56.408 DEBUG (MainThread) [websockets.client] < Sec-WebSocket-Protocol: graphql-transport-ws
2022-11-09 09:57:56.408 DEBUG (MainThread) [websockets.client] = connection is OPEN
2022-11-09 09:57:56.430 DEBUG (MainThread) [websockets.client] > TEXT '{"type": "connection_init", "payload": {"token"..."}}' [96 bytes]
2022-11-09 09:57:56.478 DEBUG (MainThread) [websockets.client] < CLOSE 4429 (private use) Too many open connections on this server: 1 [45 bytes]
2022-11-09 09:57:56.478 DEBUG (MainThread) [websockets.client] = connection is CLOSING
2022-11-09 09:57:56.478 DEBUG (MainThread) [websockets.client] > CLOSE 4429 (private use) Too many open connections on this server: 1 [45 bytes]
2022-11-09 09:57:56.525 DEBUG (MainThread) [websockets.client] = connection is CLOSED
2022-11-09 09:57:56.534 DEBUG (MainThread) [websockets.client] x closing TCP connection