Not getting a message (despite other websocket tools receiving it)

[bachya]

I'm attempting to access a websocket (wss://api.simplisafe.com/socket.io/?... – note that I am omitting extraneous query parameters for simplicity) that, upon being connected to, emits two messages right away:

0{"sid":"xxxxxxxxxxxxxxx_xxxx","upgrades":[],"pingInterval":25000,"pingTimeout":60000}
40

Note that neither message seems to come with an event name. Also that the 0 that prefixes the first message.

When I test this sequence with some other tool (such as this HTML5-based websocket tester), everything works as expected: once I connect to the websocket, I immediately get these responses back.

When I test the same sequence with the latest python-socketio in a simple script:

import asyncio
import logging

from socketio import AsyncClient
from socketio.exceptions import ConnectionError as ConnError, SocketIOError

_LOGGER = logging.getLogger()

def print_data(data):
    """Print data as it is received."""
    _LOGGER.info("Data received: %s", data)

def print_goodbye():
    """Print a simple "goodbye" message."""
    _LOGGER.info("Client has disconnected from the websocket")

def print_hello():
    """Print a simple "hello" message."""
    _LOGGER.info("Client has connected to the websocket")

async def main():
    """Run."""
    logging.basicConfig(level=logging.DEBUG)

    sio = AsyncClient()
    sio.on("connect", print_hello)
    sio.on("data", print_data)
    sio.on("disconnect", print_goodbye)
    sio.on("message", print_data)

    try:
        await sio.connect(
            "wss://api.simplisafe.com/socket.io/?...", transports=["websocket"]
        )
    except (ConnError, SocketIOError) as err:
        _LOGGER.error("There was an error: %s", err)

loop = asyncio.get_event_loop()
loop.run_until_complete(main())

...I get the following results:

INFO:engineio.client:Attempting WebSocket connection to wss://api.simplisafe.com/socket.io/?...&transport=websocket&EIO=3
DEBUG:websockets.protocol:client - state = CONNECTING
DEBUG:websockets.protocol:client - event = connection_made(<asyncio.sslproto._SSLProtocolTransport object at 0x104662410>)
DEBUG:websockets.client:client > GET /socket.io/?...&transport=websocket&EIO=3&t=1573794998.6566882 HTTP/1.1
DEBUG:websockets.client:client > Headers([('Host', 'api.simplisafe.com'), ('Upgrade', 'websocket'), ('Connection', 'Upgrade'), ('Sec-WebSocket-Key', 'xxxxxxxxxxxxxxxxxxxxxxxx'), ('Sec-WebSocket-Version', '13'), ('Sec-WebSocket-Extensions', 'permessage-deflate; client_max_window_bits'), ('User-Agent', 'Python/3.7 websockets/8.1')])
DEBUG:websockets.protocol:client - event = data_received(<404 bytes>)
DEBUG:websockets.protocol:client - event = data_received(<88 bytes>)
DEBUG:websockets.client:client < HTTP/1.1 101 Switching Protocols
DEBUG:websockets.client:client < Headers([('Date', 'Fri, 15 Nov 2019 05:16:39 GMT'), ('Connection', 'upgrade'), ('Set-Cookie', 'AWSALB=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx; Expires=Fri, 22 Nov 2019 05:16:39 GMT; Path=/'), ('Upgrade', 'websocket'), ('Sec-WebSocket-Accept', 'xxxxxxxxxxxxxxxxxxxxxxxxxxxx'), ('Sec-WebSocket-Extensions', 'permessage-deflate')])
DEBUG:websockets.protocol:client - state = OPEN
DEBUG:websockets.protocol:client < Frame(fin=True, opcode=1, data=b'0{"sid":"xxxxxxxxxxxxxxxxxxxx","upgrades":[],"pingInterval":25000,"pingTimeout":60000}', rsv1=False, rsv2=False, rsv3=False)
INFO:engineio.client:WebSocket connection accepted with {'sid': 'xxxxxxxxxxxxxxxxxxxx', 'upgrades': [], 'pingInterval': 25000, 'pingTimeout': 60000}
INFO:socketio.client:Engine.IO connection established
INFO:engineio.client:Received packet MESSAGE data 0
INFO:socketio.client:Namespace / is connected
INFO:root:Client has connected to the websocket
DEBUG:websockets.protocol:client - event = data_received(<3 bytes>)
DEBUG:websockets.protocol:client < Frame(fin=True, opcode=1, data=b'3', rsv1=False, rsv2=False, rsv3=False)
INFO:engineio.client:Received packet PONG data None

It looks like my connect handler gets called, but the handler that's supposed to respond to either data or message events doesn't.

Am I missing something? I know this likely isn't a bug with python-socketio, so I appreciate your help diagnosing what's going on.

[miguelgrinberg]

These are not Socket.IO messages, they are from Engine.IO, the lower level transport library used by Socket.IO.

The first character is the packet type. 0 is the open packet. 4 is the message packet. More info here: https://github.com/socketio/engine.io-protocol#packet.

The payload for the open packet is a JSON with connection parameters. Looks like the engine.io and socket.io layers of the client both accepted that:

INFO:engineio.client:WebSocket connection accepted with {'sid': 'xxxxxxxxxxxxxxxxxxxx', 'upgrades': [], 'pingInterval': 25000, 'pingTimeout': 60000}
INFO:socketio.client:Engine.IO connection established

The payload for the message packet is a Socket.IO packet. A 0 packet is for connect. More info here: https://github.com/socketio/socket.io-protocol#packet. This packet also appears to have been accepted, again at both layers:

INFO:engineio.client:Received packet MESSAGE data 0
INFO:socketio.client:Namespace / is connected

So as far as I can see this is working perfectly fine.

[bachya]

Got it. Let's take this a step further – after connecting to the socket, I am supposed to emit a "subscription" message in the form of a string (for simplicity, let's call it MY_MESSAGE). When I emit it via that previously-mentioned HTML5-based tester, I get a response back:

42/v1/user/ACCOUNT_ID,["confirm-registered",["ACCOUNT_ID"]]

However, when I emit it via my script above, no such response seems to come back:

INFO:engineio.client:Attempting WebSocket connection to wss://api.simplisafe.com/socket.io/?...&transport=websocket&EIO=3
INFO:engineio.client:WebSocket connection accepted with {'sid': 'xxxxxxxxxxxxxxx', 'upgrades': [], 'pingInterval': 25000, 'pingTimeout': 60000}
INFO:socketio.client:Engine.IO connection established
INFO:engineio.client:Sending packet PING data None
INFO:engineio.client:Received packet MESSAGE data 0
INFO:socketio.client:Namespace / is connected
INFO:root:Client has connected to the websocket
INFO:engineio.client:Received packet PONG data None
INFO:socketio.client:Emitting event "MY_MESSAGE" [/]
INFO:engineio.client:Sending packet MESSAGE data 2["MY_MESSAGE"]
INFO:engineio.client:Sending packet PING data None
INFO:engineio.client:Received packet PONG data None

I know that's sparse info, but again, any thoughts?

[miguelgrinberg]

@bachya do you have the packet that you are sending with the client that works? The response that you are getting indicates the server is responding through a namespace, so I suspect this thing that you called MY_MESSAGE is more complex than what you make it.

[bachya]

You bet – it's a string in this form:

40/v1/user/{USER ID}?ns=/v1/user/{USER ID}&{URL-ENCODED API KEY}

[miguelgrinberg]

Right, this is a 0 packet, which is a connect. You were sending a message, which is a 2.

Your other client is connecting to a namespace on that second packet. The problem is that the namespace has a dynamic part with the user id, which is kind of unusual. It means that you will need to have handlers to receive events in potentially lots of namespaces, one per user. This server that you are connecting to abuses the concept of namespaces in my opinion.

[bachya]

I see. Thanks for the help and explanation. I'll continue to tinker and will close this.