NodeMCU and ESP8266: slow mqtt publish

I'm using esp8266 with the firmware produced with Marcel's NodeMCU custom builds http://frightanic.com/nodemcu-custom-build/ I tested the "dev" branch and the "master".

I changed a little bit the "Connect to MQTT Broker" code found here https://github.com/nodemcu/nodemcu-firmware

-- init mqtt client with keepalive timer 120sec
m = mqtt.Client("clientid", 120, "user", "password")

m:on("connect", function(con) print ("connected") end)
m:on("offline", function(con) print ("offline") end)

-- m:connect( host, port, secure, auto_reconnect, function(client) )
-- for secure: m:connect("192.168.11.118", 1880, 1, 0)
-- for auto-reconnect: m:connect("192.168.11.118", 1880, 0, 1)
m:connect("192.168.11.118", 1880, 0, 0, function(conn) print("connected") end)

-- publish a message with data = hello, QoS = 0, retain = 0
local i = 1
while i < 10 do
  m:publish("/topic","hello",0,0, function(conn) print("sent") end)
  i = i + 1
end

m:close();

I'm using mosquitto as a mqtt broker and I have launched a subscriber on all topic #.

The result is: the messages arrives correctly but they are really slow to arrive on the subscriber (around 1 second each)... why?

I tried also to change the mqtt architecture in favor of UDP.. the esp8266 send the 100 messages fast.

UPDATE 1#:

I have done some more experiments:

Testing the broker and the subscriber with an [android phone + a mqtt publisher], the subscriber receive messages immediately
I loaded a nodemcu with "debug" enabled and I have done an interesting discovery: read on

For what I have understood reading debug log and source code.. There is a sort of queue that saves the messages in memory and a timer (I don't know the frequency/interval) reads a message from the queue and it sends it through mqtt. If you try to send 100 messages, the queue increases, but it is not able to deliver messages at the same time (maybe there is a race condition? ).

There is a second problem here, after it has enqueued more than 15 messages, the firmware crash and the device reboots: it seems a symptom of memory no more available.

Solution

It may not be the answer you're looking for but yes, NodeMCU MQTT uses an internal queue for messages. It was added at the end of March 2015. It was added due to the asynchronous nature of the NodeMCU API.

If you have two calls to m.publish in quick succession, remember they're asynchronous, there isn't enough time for the 1st message to be delivered before the 2nd is triggered. Before the introduction of that queue the firmware would simply have crashed if you had published in a loop.

I simplified your code even more and added some debugging statements:

m = mqtt.Client("clientid", 120, "user", "password")

m:connect("m20.cloudmqtt.com", port, 0, function(conn) 
    print("MQTT connected")
    for i=1,10 do
      print("MQTT publishing...")
      m:publish("/topic", "hello", 0, 0, function(conn) 
        print("MQTT message sent")
        print("  heap is " .. node.heap() .. " bytes")
      end)
      print("  heap is " .. node.heap() .. " bytes in loop " .. i)
    end
end)

Knowing that the calls to m.publish are asynchronous the output shouldn't be too surprising:

MQTT connected
MQTT publishing...
  heap is 37784 bytes in loop 1
MQTT publishing...
  heap is 37640 bytes in loop 2
MQTT publishing...
  heap is 37520 bytes in loop 3
MQTT publishing...
  heap is 37448 bytes in loop 4
MQTT publishing...
  heap is 37344 bytes in loop 5
MQTT publishing...
  heap is 37264 bytes in loop 6
MQTT publishing...
  heap is 37192 bytes in loop 7
MQTT publishing...
  heap is 37120 bytes in loop 8
MQTT publishing...
  heap is 37048 bytes in loop 9
MQTT publishing...
  heap is 36976 bytes in loop 10
sent
  heap is 38704 bytes
sent
  heap is 38792 bytes
sent
  heap is 38856 bytes
sent
  heap is 38928 bytes
sent
  heap is 39032 bytes
sent
  heap is 39112 bytes
sent
  heap is 39184 bytes
sent
  heap is 39256 bytes
sent
  heap is 39328 bytes
sent
  heap is 39400 bytes

You see that the available heap space is decreasing while publishing and increasing again as the queue is emptied.