Client disconnection on empty binary packet

[antmatyjajo]

Hi,

I have run into a problem after updating python-engineio from 4.8.x to 4.9.0. If a python-socketio Client receives a message with some binary attachments, and one of the binary packets happens to be empty, the client will disconnect.

After some hunting around, it seems the changes made in 5b538a7 are responsible, specifically the zero packet length check here.

I don't know enough about websockets/socketio/engineio to know what should be the "correct" behaviour in this case; however in my application there are binary fields in the messages sent from the server and occasionally one or more may be empty, so at least my expected behaviour (what was happening until now) is that the messages will be received in their entirety.

Thank you :)

To reproduce:

Server:

# test_server.py
from flask import Flask
from flask_socketio import SocketIO

app = Flask(__name__)

async_mode = "eventlet"

socketio = SocketIO(
    app,
    async_mode=async_mode,
    ping_timeout=120,
    logger=True,
    engineio_logger=True,
)

@socketio.on("run_sim", namespace="/sim")
def run_sim():
    print("received request")

    socketio.emit(
        "stream_result",
        {
            "data": {
                "id": "test",
                "t": 42,
                "thing": b"42",
                "thing2": b"",
                "thing3": b"42"
            }
        },
        namespace="/sim",
    )

socketio.run(app, port=54321)

Client:

#test_client.py
import socketio

sio = socketio.Client(logger=True, engineio_logger=True)

results = []

@sio.on("disconnect", namespace="/sim")
def handle_disconnect():
    print("DISCONNECTED")

@sio.on("stream_result", namespace="/sim")
def handle_sim_data(msg):
    print("handle data")
    data = msg["data"]
    results.append(data)
    print("data handled")
    
sio.connect(
    "http://localhost:54321/socket.io", namespaces=["/sim"], wait_timeout = 20,
)

sio.emit(
    "run_sim",
    namespace="/sim",
)

sio.wait()

Server log:

$ ./test_server.py
Server initialized for eventlet.
g93NKleouhleIJ9yAAAA: Sending packet OPEN data {'sid': 'g93NKleouhleIJ9yAAAA', 'upgrades': ['websocket'], 'pingTimeout': 120000, 'pingInterval': 25000}
g93NKleouhleIJ9yAAAA: Received request to upgrade to websocket
g93NKleouhleIJ9yAAAA: Upgrade to websocket successful
g93NKleouhleIJ9yAAAA: Received packet MESSAGE data 0/sim,{}
g93NKleouhleIJ9yAAAA: Sending packet MESSAGE data 0/sim,{"sid":"J7b3so8EerULBw-lAAAB"}
g93NKleouhleIJ9yAAAA: Received packet MESSAGE data 2/sim,["run_sim"]
received event "run_sim" from J7b3so8EerULBw-lAAAB [/sim]
received request
emitting event "stream_result" to all [/sim]
g93NKleouhleIJ9yAAAA: Sending packet MESSAGE data 53-/sim,["stream_result",{"data":{"id":"test","t":42,"thing":{"_placeholder":true,"num":0},"thing2":{"_placeholder":true,"num":1},"thing3":{"_placeholder":true,"num":2}}}]
g93NKleouhleIJ9yAAAA: Sending packet MESSAGE data <binary>
g93NKleouhleIJ9yAAAA: Sending packet MESSAGE data <binary>
g93NKleouhleIJ9yAAAA: Sending packet MESSAGE data <binary>
72_zvv_BCcprGOYeAAAC: Sending packet OPEN data {'sid': '72_zvv_BCcprGOYeAAAC', 'upgrades': ['websocket'], 'pingTimeout': 120000, 'pingInterval': 25000}
72_zvv_BCcprGOYeAAAC: Received request to upgrade to websocket
72_zvv_BCcprGOYeAAAC: Upgrade to websocket successful
72_zvv_BCcprGOYeAAAC: Received packet MESSAGE data 0/sim,{}
72_zvv_BCcprGOYeAAAC: Sending packet MESSAGE data 0/sim,{"sid":"lLgnDRVZGlSQ9oF2AAAD"}

Client log:

$ ./test_client.py
Attempting polling connection to http://localhost:54321/socket.io/?transport=polling&EIO=4
Polling connection accepted with {'sid': 'g93NKleouhleIJ9yAAAA', 'upgrades': ['websocket'], 'pingTimeout': 120000, 'pingInterval': 25000}
Engine.IO connection established
Sending packet MESSAGE data 0/sim,{}
Attempting WebSocket upgrade to ws://localhost:54321/socket.io/?transport=websocket&EIO=4
WebSocket upgrade was successful
Received packet NOOP data 
Received packet MESSAGE data 0/sim,{"sid":"J7b3so8EerULBw-lAAAB"}
Namespace /sim is connected
Emitting event "run_sim" [/sim]
Sending packet MESSAGE data 2/sim,["run_sim"]
Received packet MESSAGE data 53-/sim,["stream_result",{"data":{"id":"test","t":42,"thing":{"_placeholder":true,"num":0},"thing2":{"_placeholder":true,"num":1},"thing3":{"_placeholder":true,"num":2}}}]
Received packet MESSAGE data <binary>
WebSocket connection was closed, aborting
Waiting for write loop task to end
Exiting write loop task
Engine.IO connection dropped
DISCONNECTED
Connection failed, new attempt in 1.01 seconds
Exiting read loop task
Attempting polling connection to http://localhost:54321/socket.io/?transport=polling&EIO=4
Polling connection accepted with {'sid': '72_zvv_BCcprGOYeAAAC', 'upgrades': ['websocket'], 'pingTimeout': 120000, 'pingInterval': 25000}
Engine.IO connection established
Sending packet MESSAGE data 0/sim,{}
Attempting WebSocket upgrade to ws://localhost:54321/socket.io/?transport=websocket&EIO=4
WebSocket upgrade was successful
Received packet NOOP data 
Received packet MESSAGE data 0/sim,{"sid":"lLgnDRVZGlSQ9oF2AAAD"}
Namespace /sim is connected
Reconnection successful

[miguelgrinberg]

Unfortunately the websocket client used by this package indicates a closed connection with an empty payload. Closed connections weren't detected accurately before and this change addresses that.

Would it be possible to switch those empty binary fields to regular strings?

[antmatyjajo]

OK, thanks for your explanation. Sorry for my misunderstanding, but I think I am missing something fundamental - yes I can see that the client sends a close packet with an empty payload, for example after the server sends it a disconnect, but this doesn't seem to be the case with the server? I.e., the server is sending a non-empty disconnect message... Just trying to get a deeper understanding of what's going on under the hood.

Would it be possible to switch those empty binary fields to regular strings?

Yes, maybe. We have a python client but also a js client in a web app.

My example above was a bit contrived. In reality the fields containing binary content are coming from another source on the server providing binary data frames. There is a stream of results that the client is receiving as opposed to the single one in the example. The binary fields are arrays, and for a given results frame there is a possibility that one or more arrays might be empty, unfortunately that's the nature of the data.

As such it is convenient to keep the binary data as it can be very nicely directly unpacked into numpy arrays, Float32Array, ... without going through intermediate processing and conversion.

In the case of switching the binary fields to strings, it would necessitate extra data conversion steps on both my client and server sides. Maybe it would be easier for me to add some checks on my server for empty data and do something conditional on that, or change the structure of the data we are sending a bit, I'll look into it!

[miguelgrinberg]

yes I can see that the client sends a close packet with an empty payload

That is not the issue here. The websocket client (package websocket-client, a dependency of this Socket.IO client) has a read function that does not have a mechanism to report a connection closed. The function returns a string, and when the server responds with something unexpected (such as a close packet) this function returns a zero-length payload, instead of the something more normal such as raising an exception.

[antmatyjajo]

Thanks for clarifying, now I do understand the situation.

Out of curiosity would something like

if (len(p) == 0) and (not self.ws.connected):

or

if (len(p) == 0) and (self.state == 'disconnecting'):

provide a viable solution to this situation (differentiate between content that happens to be empty intentionally, and the websocket's close payload)? Or is that likely to introduce further problems?

[miguelgrinberg]

The second suggestion would not work. The first one I'm not sure. Maybe. I'll need to test that out.

[miguelgrinberg]

@antmatyjajo please install python-engineio from the main branch and let me know if it addresses your issue.

[antmatyjajo]

Can confirm that all seems good - thank you