aisstream / issues

7 stars 3 forks source link

Error related with websockets (Python) #4

Closed berbaba closed 1 year ago

berbaba commented 1 year ago

Thanks for your help in advance. When running the Python example, after some undetermined time (sometimes 1h, sometimes 45 min...) it crashes. The error can be also reproduced just manually disconnecting and waiting for 50 seconds or so. The error is the following:

  File "/home/.../anaconda3/lib/python3.8/site-packages/websockets/legacy/protocol.py", line 968, in transfer_data
    message = await self.read_message()
  File "/home/.../anaconda3/lib/python3.8/site-packages/websockets/legacy/protocol.py", line 1038, in read_message
    frame = await self.read_data_frame(max_size=self.max_size)
  File "/home/.../anaconda3/lib/python3.8/site-packages/websockets/legacy/protocol.py", line 1113, in read_data_frame
    frame = await self.read_frame(max_size)
  File "/home/.../anaconda3/lib/python3.8/site-packages/websockets/legacy/protocol.py", line 1170, in read_frame
    frame = await Frame.read(
  File "/home/.../anaconda3/lib/python3.8/site-packages/websockets/legacy/framing.py", line 99, in read
    data = await reader(length)
  File "/home/.../anaconda3/lib/python3.8/asyncio/streams.py", line 723, in readexactly
    await self._wait_for_data('readexactly')
  File "/home/.../anaconda3/lib/python3.8/asyncio/streams.py", line 517, in _wait_for_data
    await self._waiter
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/.../AISStream.io/example.py", line 24, in <module>
    asyncio.run(asyncio.run(connect_ais_stream()))
  File "/home/.../anaconda3/lib/python3.8/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/home/.../anaconda3/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/home/.../AISStream.io/example.py", line 14, in connect_ais_stream
    async for message_json in websocket:
  File "/home/.../anaconda3/lib/python3.8/site-packages/websockets/legacy/protocol.py", line 497, in __aiter__
    yield await self.recv()
  File "/home/.../anaconda3/lib/python3.8/site-packages/websockets/legacy/protocol.py", line 568, in recv
    await self.ensure_open()
  File "/home/.../anaconda3/lib/python3.8/site-packages/websockets/legacy/protocol.py", line 953, in ensure_open
    raise self.connection_closed_exc()
websockets.exceptions.ConnectionClosedError: sent 1011 (unexpected error) keepalive ping timeout; no close frame received 

Looking for solutions I stumbled upon this one that suggests setting the ping interval to None (I'm guessing the value is by default set by the server to those 50s) in: async with websockets.connect("wss://stream.aisstream.io/v0/stream", ping_interval=None) as websocket:

This seems to work, loosing connection just pauses the stream (I guess all messages until the connection is restablished are lost) and then resumes without a problem. But I don't know if there's a catch I don't know about and if this solution should be used (My goal is to keep the connection up as long as possible and reconnect automatically if the connection is lost). If it's fine, could be added to the code. Thank you.

aisstream commented 1 year ago

Hello, thanks for the issue.

It appears on my end like we are not closing connections cleanly in certain cases or not responding how the websocket library expects PINGs to be handled. I will have to look into why PING keep alive messages are timing out.

You should be fine to disable the ping_interval in the meantime.

It is possible we are closing the connection on our end for a variety of reasons (clearly not cleanly as you have demonstrated which we should fix). The two most likely reasons are you are not reading the messages fast enough. We close connections with full write buffers ( tcp buffer + 2 mb additional write buffer ) to reduce noisy neighbour issues and prevent slow clients from affecting other users. We also throttle subscription updates to 1/sec and close connections after sending an error message if they exceed it.

Thanks for opening the issue. I will try and reproduce this myself in the coming days.

aisstream commented 1 year ago

I looked into our logs and in your case it does not appear to be us closing the connection. So you can ignore the advice about slow clients or throttling.

What appears to be happening is as follows:

  1. For some PING requests we are not providing a response fast enough
  2. The websocket library closes the connection ( During this process it sends a close message to our service)
  3. We are not sending a close response to cleanly close the connection which causes the second error to be thrown.

At the moment why we are not responding to PINGs in a timely manner is not known but it will be looked into.

aisstream commented 1 year ago

Closing due to inactivity.