MQTT topic received by Espruino sometimes malformed

I have a pixel ring and an Espruino WiFi firmware: 2v07.

I am doing some basics MQTT testing, I send a message from my Raspberry PI via an MQTT broker. It's extremely simple as follows:

topic: heartbeat
message: 0 || 1 driven by an occupancy sensor.

Here's a snippet of where the values are received and output to the WebIDE:

function onInit() {
  wifi.connect(WIFI_NAME, WIFI_OPTIONS, function(err) {
    if (err) {
      return;
    }
    startMQTT();
  });
}

function startMQTT() {
  mqtt = require("MQTT").create(server, options);
  
  mqtt.on('connected', function() {
    mqtt.subscribe("heartbeat");
  });

  mqtt.on('publish', function (pub) {
    console.log(pub.topic, pub.message);
    if(pub.message === '1') {
      lightsOn();
    }else{
      lightsOff();
    }
  });

  mqtt.connect();
}

I'll also include an image from another tool I debug topics/messages on Windows, this doesn't appear to show any malformed topic or message.

What is confusing is that i'm only subscribing to the "heartbeat" topic, so how could it even output something other than heartbeat? Like heartb1 or rtbeat1 as seen below!

Any idea what could be causing this, or where to even start debugging something like this using the MQTT library for Espruino?

Thanks, Neil

2 Attachments

Thanks for all the info. I don't suppose you received a FIFO_FULL message on Espruino's console or something like that? And have you got any other code running in the background?

Just a hunch, but you say pixel ring - do you mean neopixel? Please could you try commenting out the 'neopixel.write' command and see if it still happens?

And if it does, maybe try:

A15.set();
neopixel.write...
A15.reset();

I can't remember for sure but I wonder if the STM32 neopixel code disables interrupts, which would cause the lost characters. A15 is the 'clear to send' pin to the ESP8266, so my flipping it you can tell the ESP8266 to pause comms while Espruino is busy. Assuming that works I can ensure that the code is actually built in for new firmwares.

You can also use wifi.at.debug() to turn on debug info from the WiFi, which will help you see the actual traffic between the WiFi module and the STM32 - if none of the above works it's what I'd recommend as a starting point.

Thank you for using your intuition, I am indeed using the neopixel ring hence the neopixel.write function. You were spot on, after setting and clearing A15 after an hour or so of testing, I see no issues!

I've been trying all kinds of things to solve this, I appreciate your time and effort.

Glad that fixed it! I've just filed an issue for it here: https://github.com/espruino/Espruino/iss­ues/1960

So hopefully I'll get this fixed for the 2v09 release :)

@Gordon

Unfortunately, after adding more subscriptions to other topics, the problem seems to be happening again. Sorry for the delay replying.

I seem to get additional characters now as per below:

Here is my src, just incase there's anything else that could be contributing to this problem. Once again I don't see any issues in the MQTT traffic tool I use on Windows.

const server = "192.168.1.64"; // the ip of your MQTT broker
const options = {
  // ALL OPTIONAL - the defaults are below
  client_id: "random", // the client ID sent to MQTT - it's a good idea to define your own static one based on `getSerial()`
  keep_alive: 60, // keep alive time in seconds
  port: 1883, // port number
  clean_session: true,
  username: "username", // default is undefined
  password: "password", // default is undefined
  protocol_name: "MQTT", // or MQIsdp, etc..
  protocol_level: 4, // protocol level
};

let id = null;
let temp = 0;
let running = false;
const leds = 12;

function onInit() {
  lightsOff();
  lightsOn(getRndColor(), 300);

  wifi.connect(WIFI_NAME, WIFI_OPTIONS, function (err) {
    if (err) {
      return;
    }
    startMQTT();
  });
}

function startMQTT() {
  mqtt = require("MQTT").create(server, options);

  mqtt.on("connected", function () {
    mqtt.subscribe("door");
    mqtt.subscribe("occupancy");
    mqtt.subscribe("temperature");
  });

  mqtt.on("publish", function (pub) {
    console.log(pub.topic, pub.message);
    switch (pub.topic) {
      case "door":
        if (pub.message === "2") {
          lightsOff();
          lightsOn({ r: 80, g: 0, b: 0 }, 50);
        }
        break;

      case "occupancy":
        if (pub.message === "1") {
          lightsOff();
          lightsOn({ r: 0, g: 80, b: 0 }, 100);
        }
        break;

      case "temperature":
        temp = Number(pub.message);
        lightsOff();
        switch (true) {
          case temp <= 18:
            lightsOff();
            lightsOn({ r: 3, g: 171, b: 255 }, 200);
            break;

          case temp > 18 && temp < 20:
            lightsOff();
            lightsOn({ r: 255, g: 162, b: 0 }, 200);
            break;

          case temp >= 20:
            lightsOff();
            lightsOn({ r: 255, g: 0, b: 0 }, 200);
            break;
        }
        break;
    }
  });

  mqtt.connect();
}

function lightsOn(color, speed) {
  if (running) return;

  let rgb = new Uint8ClampedArray(leds * 3);
  let pos = 0;

  function getPattern() {
    pos = (pos + 1) % leds;

    rgb[pos * 3 + 0] = color.g;
    rgb[pos * 3 + 1] = color.r;
    rgb[pos * 3 + 2] = color.b;

    for (var i = 0; i < leds * 3; i++) rgb[i] *= 8 / leds;

    return rgb;
  }

  id = setInterval(function () {
    A15.set();
    require("neopixel").write(B15, getPattern());
    A15.reset();
  }, speed);
  running = true;
}

function lightsOff() {
  clearInterval(id);
  let rgb = new Uint8ClampedArray(leds * 3);

  function getReset() {
    for (let i = 0; i < rgb.length; ) {
      rgb[i++] = 0;
      rgb[i++] = 0;
      rgb[i++] = 0;
    }
    return rgb;
  }

  A15.set();
  require("neopixel").write(B15, getReset());
  A15.reset();
  running = false;
}

function getRndColor() {
  let color = {
    r: Math.round(Math.random() * 255 + 25),
    g: Math.round(Math.random() * 255 + 25),
    b: Math.round(Math.random() * 255 + 25),
  };
  return color;
}

onInit();

1 Attachment

Wow, this code is hard to read. What about linking to a gist?

Ok, you fixed it 😉

Can you run a test with tinyMQTT?

With tinyMQTT library I get the following chars:

1 Attachment

@Gordon

I've commented out the calls to update the neopixel and I'm still getting strange chars appearing. Although it did fix my issue with the basic example, oddly I can still replicate this without the neopixel writes.

I am debugging the wifi data and these chars do come through there it seems:

\u0007\u0000\u0004door1\u0090\u0003\u00F­BJ\u00001\f\u0000\toccupancy0\u0090\u000­3\u00FBK\u00001\u0012\u0000\u000Btempera­ture19.27

Which when decoded:

door1ûJ1	occupancy0ûK1temperature19.27

1 Attachment

Hmm, can use MQTT Box or some other tool and subscribe to topic '#' to sniff the traffic.

@MaBe There's a screenshot in my original post, which is from MQTT Explorer which is on Windows, this shows the values as correct that arrive from the broker.

In my latest screenshot, on the left in white is the output from node-red which also looks correct. Do you think that this could indicate corruption somewhere on the Espruino side?

Hmm - this seems like it's a different issue.

I'd advise against using tinyMQTT for exactly this reason. @MaBe I forget where it was but I'd posted up an issue about this (and a fix iirc) but can't find it now - tinyMQTT assumes that each data event from the socket contains one (and only one) full MQTT frame. It completely fails when sent more than one MQTT frame or a frame spread over multiple data events.

Do you have some simple code I could run here that would show the problem here?

My gut feeling looking at what you show is coming through WiFi is that you're getting more than one MQTT frame per network packet. The MQTT module should handle this, but it looks almost like it's off by one for the data packet's length.

I may see the issue, but without being able to reproduce here I don't want to poke around changing stuff :)

I'd advise against using tinyMQTT for exactly this reason. @MaBe I forget where it was but I'd posted up an issue about this (and a fix iirc) but can't find it now

looks like it got lost when @Ollie did the transfer.

... ok, I can reproduce it using a little node.js app. Will have a fix soon I hope

Ok, if you re-upload now I should have updated the MQTT module and hopefully this is fixed.

I did make a few other changes to tidy it up so hopefully nothing else got broken - but I gave it a quick test and it all looks fine

@MaBe the bit you'd need to add to fix tinyMQTT is this: https://github.com/espruino/EspruinoDocs­/blob/c47196bab8f2e3e8e18d1242f2b57639f8­04dc88/modules/MQTT.js#L174-L192

Tested for a half hour here, I assume I picked up the latest MQTT with my require statement. All looks good to me Gordon, thank you for taking the time to fix this.

No problem - thanks for such in-depth reporting of the problem, it makes it far easier for me to find and fix it.

Honestly I'm just amazed nobody reported this sooner as the MQTT module has been in use for ages

... ok, I can reproduce it using a little node.js app. Will have a fix soon I hope

Do you mind sharing the litte node.js app?

It was just this:

var mqtt = require('mqtt')
var client  = mqtt.connect('mqtt://localhost')
 
function go() {
  client.publish('random', ""+Math.round(Math.random()*10))
}
 
setInterval(function() {
go();go();go();go();
}, 5000);

Basically sending a bunch of MQTT info at once so it is bundled up and sent in one packet.

Just committed a fix for tinyMQTT

Thanks!