Ready is not being re-dispatched after disconnects

[Gobot1234]

Summary

After (forcefully) disconnecting from the WS we fail to dispatch the ready event

Reproduction Steps

Disconnect and reconnect to a CM, wait 60s and then the bot will crash after timing out fetching the friends list causing ready to not be redispatched

Expected Results

No crashing to occur

Actual Results

It crashes in SteamWebsocket.fetch_users after timing out waiting for a refresh.

System Information

v1.0.0 on 82e7482

Checklist

• I have searched the issues for duplicates.
• I have shown the entire traceback, if possible.
• I have removed my username/password/secrets from display, if visible.

[Gobot1234]

I might have a fix for this, will need testing

[truenicoco]

I'm not sure it's the same bug, but when I login from my VPS, I am quickly disconnected:

Probably irrelevant logs:

May 15 05:09:53 vps-9bd6f395 steam[2673158]: INFO:slidge.core.gateway.base:Login success for <User nicoco@slidge.im>
May 15 05:09:53 vps-9bd6f395 steam[2673158]: INFO:steam.protobufs.msg:Received an unknown EMsg.ServiceMethodResponse b'M\x00\x00\x00\t \xa9H\x05\x01\x00\x10\x01\x10\x8a\xfc\x97\xdc\xfa\xff\xff\xff\xff\x01Y\x05\x00\x00\x00\x00\x00\x00\x00b)SteamNotification.MarkNotificationsRead#1h\x02\x88\x01e' (SteamNotification.MarkNotificationsRead#1)

Relevant logs

May 15 05:12:22 vps-9bd6f395 steam[2673158]: INFO:steam.state:Websocket closed, cannot reconnect.
May 15 05:12:22 vps-9bd6f395 steam[2673158]: INFO:steam.client:Attempting to connect to another CM in 8s
May 15 05:12:31 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext1-par1.steamserver.net:27031 (load: 5.525591)
May 15 05:12:41 vps-9bd6f395 steam[2673158]: INFO:steam.state:Websocket closed, cannot reconnect.

Trying to send a steam chat message

May 15 05:12:41 vps-9bd6f395 steam[2673158]: Traceback (most recent call last):
May 15 05:12:41 vps-9bd6f395 steam[2673158]: File "/venv/lib/python3.11/site-packages/steam/gateway.py", line 778, in send
May 15 05:12:41 vps-9bd6f395 steam[2673158]: await self.socket.send_bytes(data)
May 15 05:12:41 vps-9bd6f395 steam[2673158]: File "/venv/lib/python3.11/site-packages/aiohttp/client_ws.py", line 170, in send_bytes
May 15 05:12:41 vps-9bd6f395 steam[2673158]: await self._writer.send(data, binary=True, compress=compress)
May 15 05:12:41 vps-9bd6f395 steam[2673158]: File "/venv/lib/python3.11/site-packages/aiohttp/http_websocket.py", line 727, in send
May 15 05:12:41 vps-9bd6f395 steam[2673158]: await self._send_frame(message, WSMsgType.BINARY, compress)
May 15 05:12:41 vps-9bd6f395 steam[2673158]: File "/venv/lib/python3.11/site-packages/aiohttp/http_websocket.py", line 628, in _send_frame
May 15 05:12:41 vps-9bd6f395 steam[2673158]: raise ConnectionResetError("Cannot write to closing transport")
May 15 05:12:41 vps-9bd6f395 steam[2673158]: ConnectionResetError: Cannot write to closing transport
May 15 05:12:41 vps-9bd6f395 steam[2673158]:
May 15 05:12:41 vps-9bd6f395 steam[2673158]: During handling of the above exception, another exception occurred:
May 15 05:12:41 vps-9bd6f395 steam[2673158]:
May 15 05:12:41 vps-9bd6f395 steam[2673158]: Traceback (most recent call last):
May 15 05:12:41 vps-9bd6f395 steam[2673158]: File "/venv/lib/python3.11/site-packages/slidge/core/gateway/session_dispatcher.py", line 775, in wrapped
May 15 05:12:41 vps-9bd6f395 steam[2673158]: await cb(stanza)
May 15 05:12:41 vps-9bd6f395 steam[2673158]: File "/venv/lib/python3.11/site-packages/slidge/core/gateway/session_dispatcher.py", line 383, in on_chatstate_composing
May 15 05:12:41 vps-9bd6f395 steam[2673158]: await session.on_composing(entity, thread)
May 15 05:12:41 vps-9bd6f395 steam[2673158]: File "/venv/lib/python3.11/site-packages/legacy_module/session.py", line 47, in on_composing
May 15 05:12:41 vps-9bd6f395 steam[2673158]: await user.trigger_typing()
May 15 05:12:41 vps-9bd6f395 steam[2673158]: File "/venv/lib/python3.11/site-packages/steam/user.py", line 316, in trigger_typing
May 15 05:12:41 vps-9bd6f395 steam[2673158]: await self._state.send_user_typing(self.id64)
May 15 05:12:41 vps-9bd6f395 steam[2673158]: File "/venv/lib/python3.11/site-packages/steam/state.py", line 527, in send_user_typing
May 15 05:12:41 vps-9bd6f395 steam[2673158]: msg: friend_messages.SendMessageResponse = await self.ws.send_um_and_wait(
May 15 05:12:41 vps-9bd6f395 steam[2673158]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
May 15 05:12:41 vps-9bd6f395 steam[2673158]: File "/venv/lib/python3.11/site-packages/steam/gateway.py", line 832, in send_um_and_wait
May 15 05:12:41 vps-9bd6f395 steam[2673158]: await self.send_proto(um)
May 15 05:12:41 vps-9bd6f395 steam[2673158]: File "/venv/lib/python3.11/site-packages/steam/gateway.py", line 786, in send_proto
May 15 05:12:41 vps-9bd6f395 steam[2673158]: await self.send(bytes(message))
May 15 05:12:41 vps-9bd6f395 steam[2673158]: File "/venv/lib/python3.11/site-packages/steam/gateway.py", line 780, in send
May 15 05:12:41 vps-9bd6f395 steam[2673158]: await self._state.handle_close()
May 15 05:12:41 vps-9bd6f395 steam[2673158]: File "/venv/lib/python3.11/site-packages/steam/state.py", line 2979, in handle_close
May 15 05:12:41 vps-9bd6f395 steam[2673158]: raise ConnectionClosed(self.ws.cm)
May 15 05:12:41 vps-9bd6f395 steam[2673158]: steam.gateway.ConnectionClosed: Connection to ext2-par1.steamserver.net:27024, has closed.

Further relevant logs:

May 15 05:12:53 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext1-par1.steamserver.net:27034 (load: 9.016203)
May 15 05:12:53 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext2-par1.steamserver.net:27021 (load: 10.155653)
May 15 05:12:53 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext2-par1.steamserver.net:27031 (load: 10.960157)
May 15 05:12:53 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext1-par1.steamserver.net:27025 (load: 11.219608)
May 15 05:12:53 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext2-par1.steamserver.net:27029 (load: 11.420700)
May 15 05:12:53 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext2-par1.steamserver.net:27036 (load: 11.856837)
May 15 05:12:53 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext2-par1.steamserver.net:27028 (load: 13.450985)
May 15 05:12:53 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext2-par1.steamserver.net:27034 (load: 13.631458)
May 15 05:12:53 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext1-par1.steamserver.net:27036 (load: 13.631645)
May 15 05:12:53 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext2-par1.steamserver.net:27032 (load: 14.754802)
May 15 05:12:53 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext2-par1.steamserver.net:27035 (load: 14.798056)
May 15 05:12:53 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext1-par1.steamserver.net:27038 (load: 40.635271)
May 15 05:12:54 vps-9bd6f395 steam[2673158]: INFO:steam.state:Websocket closed, cannot reconnect.
May 15 05:13:31 vps-9bd6f395 steam[2673158]: INFO:steam.client:Attempting to connect to another CM in 12s
May 15 05:13:44 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext1-par1.steamserver.net:27024 (load: 43.881148)
May 15 05:13:44 vps-9bd6f395 steam[2673158]: INFO:steam.state:Websocket closed, cannot reconnect.
May 15 05:13:44 vps-9bd6f395 steam[2673158]: INFO:steam.state:Websocket closed, cannot reconnect.
May 15 05:14:44 vps-9bd6f395 steam[2673158]: INFO:steam.client:Attempting to connect to another CM in 12s
May 15 05:14:56 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext1-par1.steamserver.net:27023 (load: 44.196537)
May 15 05:14:57 vps-9bd6f395 steam[2673158]: INFO:steam.state:Websocket closed, cannot reconnect.
May 15 05:14:57 vps-9bd6f395 steam[2673158]: INFO:steam.state:Websocket closed, cannot reconnect.
May 15 05:15:57 vps-9bd6f395 steam[2673158]: INFO:steam.client:Attempting to connect to another CM in 12s
May 15 05:16:09 vps-9bd6f395 steam[2673158]: INFO:steam.gateway:Attempting to create a websocket connection to ext1-par1.steamserver.net:27028 (load: 45.389177)
May 15 05:16:10 vps-9bd6f395 steam[2673158]: INFO:steam.state:Websocket closed, cannot reconnect.
May 15 05:16:10 vps-9bd6f395 steam[2673158]: INFO:steam.state:Websocket closed, cannot reconnect.

Let me know if I should open another issue for this @Gobot1234

[truenicoco]

Some more logs, maybe useful? The bad thing about this is that no event is raised, so I have no way (or didn't find out how?) to know that the client died until I actually try to send something.

When the connection died:

May 17 23:10:49 vps-9bd6f395 steam[2735737]: DEBUG:steam.gateway:Socket has received CMsgClientFriendsGroupsList(bremoval=False, bincremental=False) from the websocket.
May 17 23:10:49 vps-9bd6f395 steam[2735737]: DEBUG:steam.gateway:Ignoring CMsgClientFriendsGroupsList(bremoval=False, bincremental=False), no event handler
May 17 23:11:48 vps-9bd6f395 steam[2735737]: INFO:steam.client:Attempting to connect to another CM in 12s
May 17 23:12:28 vps-9bd6f395 steam[2735737]: DEBUG:steam.gateway:Received WSMessage(type=<WSMsgType.CLOSE: 8>, data=1000, extra='')
May 17 23:12:28 vps-9bd6f395 steam[2735737]: INFO:steam.state:Websocket closed, cannot reconnect.

When I noticed it by trying to send a message:

May 18 06:40:35 vps-9bd6f395 steam[2735737]: Traceback (most recent call last):
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/steam/gateway.py", line 778, in send
May 18 06:40:35 vps-9bd6f395 steam[2735737]: await self.socket.send_bytes(data)
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/aiohttp/client_ws.py", line 170, in send_bytes
May 18 06:40:35 vps-9bd6f395 steam[2735737]: await self._writer.send(data, binary=True, compress=compress)
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/aiohttp/http_websocket.py", line 727, in send
May 18 06:40:35 vps-9bd6f395 steam[2735737]: await self._send_frame(message, WSMsgType.BINARY, compress)
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/aiohttp/http_websocket.py", line 628, in _send_frame
May 18 06:40:35 vps-9bd6f395 steam[2735737]: raise ConnectionResetError("Cannot write to closing transport")
May 18 06:40:35 vps-9bd6f395 steam[2735737]: ConnectionResetError: Cannot write to closing transport
May 18 06:40:35 vps-9bd6f395 steam[2735737]:
May 18 06:40:35 vps-9bd6f395 steam[2735737]: During handling of the above exception, another exception occurred:
May 18 06:40:35 vps-9bd6f395 steam[2735737]:
May 18 06:40:35 vps-9bd6f395 steam[2735737]: Traceback (most recent call last):
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/slidge/core/gateway/session_dispatcher.py", line 784, in wrapped
May 18 06:40:35 vps-9bd6f395 steam[2735737]: await cb(stanza)
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/slidge/core/gateway/session_dispatcher.py", line 237, in on_legacy_message
May 18 06:40:35 vps-9bd6f395 steam[2735737]: legacy_msg_id = await session.on_text(e, text, **kwargs)
May 18 06:40:35 vps-9bd6f395 steam[2735737]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/legacy_module/session.py", line 51, in on_text
May 18 06:40:35 vps-9bd6f395 steam[2735737]: mid = await self.steam.send(recipient, text)
May 18 06:40:35 vps-9bd6f395 steam[2735737]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/legacy_module/client.py", line 210, in send
May 18 06:40:35 vps-9bd6f395 steam[2735737]: message = await recipient.send(text)
May 18 06:40:35 vps-9bd6f395 steam[2735737]: ^^^^^^^^^^^^^^^^^^^^^^^^^^
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/steam/user.py", line 203, in send
May 18 06:40:35 vps-9bd6f395 steam[2735737]: message = await super_send(content, media=media)
May 18 06:40:35 vps-9bd6f395 steam[2735737]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/steam/abc.py", line 952, in send
May 18 06:40:35 vps-9bd6f395 steam[2735737]: message = None if content is MISSING else await self._send_message(str(content))
May 18 06:40:35 vps-9bd6f395 steam[2735737]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/steam/state.py", line 496, in send_user_message
May 18 06:40:35 vps-9bd6f395 steam[2735737]: msg: friend_messages.SendMessageResponse = await self.ws.send_um_and_wait(
May 18 06:40:35 vps-9bd6f395 steam[2735737]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/steam/gateway.py", line 832, in send_um_and_wait
May 18 06:40:35 vps-9bd6f395 steam[2735737]: await self.send_proto(um)
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/steam/gateway.py", line 786, in send_proto
May 18 06:40:35 vps-9bd6f395 steam[2735737]: await self.send(bytes(message))
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/steam/gateway.py", line 780, in send
May 18 06:40:35 vps-9bd6f395 steam[2735737]: await self._state.handle_close()
May 18 06:40:35 vps-9bd6f395 steam[2735737]: File "/venv/lib/python3.11/site-packages/steam/state.py", line 2979, in handle_close
May 18 06:40:35 vps-9bd6f395 steam[2735737]: raise ConnectionClosed(self.ws.cm)
May 18 06:40:35 vps-9bd6f395 steam[2735737]: steam.gateway.ConnectionClosed: Connection to ext2-par1.steamserver.net:27019, has closed.