Error in data received via Websocket

[pn2new]

This probably is a bit of a vague question, but I run into the problem that from time to time the data I receive on the micropython side via a websocket is not correct.

On the python side, I have code like this:

@app.route('/xxx')
@with_subscriber
@with_websocket
async def feed(request, ws, **kwargs):
          
        # ...

        try:
            data = await uasyncio.wait_for(ws.receive(), 0.2)
            print("WS-RCV: {}".format(data))
        except uasyncio.TimeoutError:
            pass

@with_subscriber is a decorator that allocates a channel to forward data to subscribers (or receive data from them that are then sent over the web socket). As such, it has nothing to do with the problem that occurs.

def with_subscriber(func):
    async def wrapper_func(*args, **kwargs):
        sub = channel.subscribe(4)
        print("WRAPPER: ^^^^^^^^ -- subscribe")
        await func(*args, sub=sub, **kwargs)
        print("WRAPPER: vvvvvvvv -- unsubscribe")
        channel.unsubscribe(sub)

    return wrapper_func

On the JavaScript side, I have code like so:

ws = new WebSocket('ws://' + location.host + '/xxx');

    (...)

    function do_send(message) {
        try {
            ws.send(message);
        } catch (err) {
            (...)
        }
    }   
    
    var tickn = 1;

    function tick() {
        try {
            do_send('{"tick": ' + tickn.toString()+'}');
            tickn++;
        }
        catch (err) {
            console.log("*** !!! ERROR in tick(): " + err);
        }
    }

    (...)
    
    setInterval(tick, 2000);

    (...)

    function send_params() {        
        var params = {
            xxx: yyy,
        };

        do_send(JSON.stringify(params));
    }

    /* send_params is registered as event handler in several GUI elements */

The problem now is that the received message on my microcontroller (an ESP32 system) from time to time is incorrect, for example like this:

WS-RCV: {"tick": 35}
WS-RCV: { "params": 123,"i":25}
WS-RCV: {"tick": 36}
WS-RCV: {"stop": 1}
WS-RCV: {"params": 123,"i":26}
WS-RCV: {"start": 1}
WS-RCV: {"tick": 37}
WS-RCV: b'\x18S\xc7\x01l:\xdfH:i\x9c\x10 .'
WS-RCV: {"tick": 39}
WS-RCV: {"tick": 40}
WS-RCV: {"tick": 41}

I log the sent message on the JavaScript side, using console.log, and there what was sent was {"tick": 38}, but instead the garbled binary string shown above was received.

What could be the reason for this? Are there communication errors that would need to be handled on the python side but are currently ignored? I would have expected that, if a message arrives, it indeed is correct.

[miguelgrinberg]

If you can provide a complete example that reproduces the problem I can investigate. Receiving a binary string is valid, WebSocket has support for binary payloads. But of course, if the client never sends binary strings I cannot explain why the server gets them.

[pn2new]

Thanks, I am currently trying to find out more about the conditions under which this error occurs.

In the meanwhile, I also got this error:

  File "websocket.py", line 200, in wrapper
  File "<stdin>", line 194, in feed
  File "asyncio/funcs.py", line 1, in wait_for
  File "asyncio/funcs.py", line 1, in _run
  File "asyncio/core.py", line 1, in run_until_complete
  File "websocket.py", line 55, in receive
  File "websocket.py", line 118, in _process_websocket_frame
UnicodeError:

Line 118 is this one:

    def _process_websocket_frame(self, opcode, payload):
        if opcode == self.TEXT:
            payload = payload.decode()   # <-- here      

I inspected the websocket traffic using wireshark, and there the messages look ok. However, I captured the traffic on the LAN of the desktop, not on the WLAN that the ESP32 "sees".
The error does not occur frequently, and my impression is that it occurs when there is more data transferred over the websocket. But I am not sure about this.

Do you have any suggestion how to get more (debugging) info about what happens on the ESP32-side?

[miguelgrinberg]

Add a try/except block around the payload.decode line, and when the error occurs, print the payload variable to see what's in it. Given that this is a text packet, the data must be encoded in UTF-8. The error indicates that whatever the other side sent was not UTF-8, so this would point to an issue in the WebSocket implementation that is on the other side.

[pn2new]

The error occurs only sporadically. I checked the data sent from the interfacing webpage using FireFox' WebDeveloper ("F12"), and captured the web traffic on the computer's network interface on which Firefox runs, using WireShark.
The data looks ok, both in WebDeveloper and in what I capture with Wireshark, but it seems what arrives on the ESP32-side is crippled.

Here is an example section of the websocket traffic that I print when receiving or sending on the ESP32-side:

WS-RCV: {"tick": 59}
WS-SND: {"tock": 1}
WS-SND: {"y": [5.13, 5.16, 5.13, 5.12, 5.07, 4.98, 4.94, 4.87, 4.81, 4.81, 4.75, 4.7], "x": [0.8, 2.1, 3.9, 4.6, 6.4, 8.1, 9.7, 11.5, 13.1, 14.8, 16.4, 17.1]}
WS-SND: {"y": [5.13, 5.16, 5.13, 5.12, 5.07, 4.98, 4.94, 4.87, 4.81, 4.81, 4.75, 4.7, 4.72], "x": [0.8, 2.1, 3.9, 4.6, 6.4, 8.1, 9.7, 11.5, 13.1, 14.8, 16.4, 17.1, 18.7]}
WS-SND: {"y": [5.13, 5.16, 5.13, 5.12, 5.07, 4.98, 4.94, 4.87, 4.81, 4.81, 4.75, 4.7, 4.72, 4.65], "x": [0.8, 2.1, 3.9, 4.6, 6.4, 8.1, 9.7, 11.5, 13.1, 14.8, 16.4, 17.1, 18.7, 20.5]}
WS-SND: {"y": [5.13, 5.16, 5.13, 5.12, 5.07, 4.98, 4.94, 4.87, 4.81, 4.81, 4.75, 4.7, 4.72, 4.65, 4.62], "x": [0.8, 2.1, 3.9, 4.6, 6.4, 8.1, 9.7, 11.5, 13.1, 14.8, 16.4, 17.1, 18.7, 20.5, 22.0]}
WS-SND: {"y": [5.13, 5.16, 5.13, 5.12, 5.07, 4.98, 4.94, 4.87, 4.81, 4.81, 4.75], "x": [0.8, 2.1, 3.9, 4.6, 6.4, 8.1, 9.7, 11.5, 13.1, 14.8, 16.4]}
WS-SND: {"y": [5.13, 5.16, 5.13, 5.12, 5.07, 4.98, 4.94, 4.87, 4.81, 4.81, 4.75, 4.7, 4.72, 4.65, 4.62, 4.52], "x": [0.8, 2.1, 3.9, 4.6, 6.4, 8.1, 9.7, 11.5, 13.1, 14.8, 16.4, 17.1, 18.7, 20.5, 22.0, 24.5]}
WS-SND: {"y": [5.13, 5.16, 5.13, 5.12, 5.07, 4.98, 4.94, 4.87, 4.81, 4.81, 4.75, 4.7, 4.72, 4.65, 4.62, 4.52, 4.52], "x": [0.8, 2.1, 3.9, 4.6, 6.4, 8.1, 9.7, 11.5, 13.1, 14.8, 16.4, 17.1, 18.7, 20.5, 22.0, 24.5, 26.1]}
WS-SND: {"y": [5.13, 5.16, 5.13, 5.12, 5.07, 4.98, 4.94, 4.87, 4.81, 4.81, 4.75, 4.7, 4.72, 4.65, 4.62, 4.52, 4.52, 4.41], "x": [0.8, 2.1, 3.9, 4.6, 6.4, 8.1, 9.7, 11.5, 13.1, 14.8, 16.4, 17.1, 18.7, 20.5, 22.0, 24.5, 26.1, 27.6]}
WS-RCV: b'VSC'
##### Exception during JSON deserialization: syntax error in JSON
WS-SND: {"y": [5.13, 5.16, 5.13, 5.12, 5.07, 4.98, 4.94, 4.87, 4.81, 4.81, 4.75, 4.7, 4.72, 4.65, 4.62, 4.52, 4.52, 4.41, 4.38], "x": [0.8, 2.1, 3.9, 4.6, 6.4, 8.1, 9.7, 11.5, 13.1, 14.8, 16.4, 17.1, 18.7, 20.5, 22.0, 24.5, 26.1, 27.6, 29.0]}
WS-RCV: {"tick": 61}
WS-SND: {"tock": 1}

Below is what is shown in Firefox WebDeveloper (and which is identical to what I see in wireshark when capturing the LAN-traffic):

So what is received as b'VSC' should have been {"tick": 60}.

The "tick" heartbeat is sent like this:

    function do_send(message) {
        console.log("do_send: " + message);
        try {
            ws.send(message);
        } catch (err) {
            console.log("do_send: ERROR" + err);
        }
    }   
    
    var tickn = 1;
    
    function tick() {
        try {
            do_send('{"tick": ' + tickn.toString()+'}');
            tickn++;
        }
        catch (err) {
            console.log("*** !!! ERROR in tick(): " + err);
        }
    }
    
    setInterval(tick, 2000);

As I understand JS, there should not be any concurrency issues with and the writing to the websocket in the tick function called regularly (setInterval) should not interfere with the receiving of data through the websocket...

[miguelgrinberg]

This is different than your initial problem. Here you have an unexpected binary packet that got inserted in the stream. The previous issue was with text packets that were not valid UTF-8 strings.

Is there any significance to the VSC characters? I suppose it is your application that breaks in this case, trying to decode JSON from the binary payload?

[pn2new]

vsc is not anything I ever send, and it is received "instead" of the "tick" message sent by the browser.

To me these errors all look like the same phenomenon: some "crippled" data that emerges from somewhere and then causes an error when being processed. Note that the first error I posted in this thread was the same (a binary data sequence).

Since the network traffic I capture with wireshark always looks correct, and corresponds to what Firefox displays as websocket traffic in the debugging console, I start to wonder whether there is a problem somewhere at a "deeper layer" (e.g. Wifi stack, or Wifi errors that are not handled correctly in the layers above), but this is beyond my capabilities to inspect.

The error frequency is low, and I have not found a way to trigger the errors reproducibly. But as far as I see it always is one of the "tick" JSON messages that does not arrive correctly on the receiver (Python) side, and this often (walways?) occurs when data are being sent approximately at the same time from the ESP32 to the browser.

Here is another example, first the traffic shown in the firefox debug window (not the {"tick": 1371}...

---and what is received by the ESP32. Here the binary string occurs instead of this tick message.

WS-SND: {"y": [5.16, 5.1, 5.04, 5.0, 5.0], "x": [0.9, 2.4, 4.7, 6.5, 8.9]}
WS-SND: {"y": [5.16, 5.1, 5.04, 5.0, 5.0, 4.95, 4.84, 4.78], "x": [0.9, 2.4, 4.7, 6.5, 8.9, 10.7, 13.2, 15.9]}
WS-RCV: b'\x10\xed\xff\x1cd\x84\xe7U2\xd7\xa4\x0f#\xda\xb5C'
WS-SND: {"y": [5.16, 5.1, 5.04, 5.0, 5.0, 4.95, 4.84], "x": [0.9, 2.4, 4.7, 6.5, 8.9, 10.7, 13.2]}
##### Exception during JSON deserialization: syntax error in JSON
WS-SND: {"y": [5.16, 5.1, 5.04, 5.0, 5.0, 4.95, 4.84, 4.78, 4.76], "x": [0.9, 2.4, 4.7, 6.5, 8.9, 10.7, 13.2, 15.9, 17.4]}
WS-SND: {"y": [5.16], "x": [0.9]}
WS-RCV: {"stop": 1}

I do understand that it is difficult to help me with that, of course, but nevertheless wanted to report this here. I will try later to make a reduced version of the code to demonstrate the problem, but it will take me a while, not least since the error occurs quite rarely.