MQTT keepalive ticker

[xfoldvar]

Hello everyone! I think that i found a bug inside of MQTT Lua module. Keepalive ticker is set to 60sec and setting it to different value doesnt affect the behavior at all.

Expected behavior

If i set the keepalive timer to 120s for example, the PINGREQ should be sent after 120s.

Actual behavior

PINGREQ is sent to broker each 60s and doesnt respect the setting entered while creating client.

Test code

I think that example from docs can reproduce the problem, but i will paste my code here anyway.

local m = nil
local mqttReconnectTimer = tmr.create()
local dataTimer = tmr.create()
local function handle_mqtt_error(client, reason)
    config.MQTT['connected'] = false
    client:close()  
    mqttReconnectTimer:start()
end
local function handle_mqtt_connect(client)
     config.printInfo('constructConnection', 'connected to '..config.MQTT['ip'],1)
     client:on("offline", handle_mqtt_error)
     client:on("message", messageArrived)
     client:lwt(config.MQTT['lw_topic'],config.MQTT['lw_message'],config.MQTT['qos'],0)    
     subscribe(client, config.MQTTSub)
     config.MQTT['connected'] = true
     publishMessage(client,config.callbacks['identify'].topic, config.callbacks['identify'].func())
     publishData(client)   
end
local function mqtt_connect(client)
    client:close()
    client:connect(config.MQTT["ip"], config.MQTT["port"],config.MQTT["tls"], 0, handle_mqtt_connect, handle_mqtt_error)
    config.printInfo('mqtt_connect', "connecting to broker, heap: " .. node.heap() ,1)    
    reconnectAttempts = reconnectAttempts + 1
    collectgarbage()   
end
function module.start()
     package.loaded['new_setup'] = nil
     --value of config.MQTT['keepalive'] is set to 120
     m = mqtt.Client(config.ID, config.MQTT['keepalive'], config.MQTT['user'], config.MQTT['pwd'])
     mqttReconnectTimer:register(1000, tmr.ALARM_SEMI, function() 
         mqtt_connect(m) 
     end)
     mqttReconnectTimer:start()
     dataTimer:register(config.data_timer, tmr.ALARM_AUTO, function()
         publishData(m)
     end)
     dataTimer:start()
end

NodeMCU version

I tested latest DEV and MASTER, but behavior is same on both. Now im running this: NodeMCU custom build by frightanic.com branch: master commit: 67027c0d05f7e8d1b97104e05a3715f6ebc8d07f SSL: false modules: crypto,dht,file,i2c,mqtt,node,si7021,sjson,tcs34725,tmr,tsl2561,wifi build created on 2018-04-18 19:21 powered by Lua 5.1.4 on SDK 2.2.1(cfd48f3)

Hardware

ESP8266-12s from Adafruit

[FrankX0]

I cannot reproduce what you are seeing. With debug enabled I can see that, a keepalive packet is sent after 120 keepalive ticks of 1 second.

Can you check if config.MQTT['keepalive'] actually is set to 120? If it e.g. is set to nil, the keepalive timer will be set to the default 60 seconds.

@xfoldvar : were you able to verify my suggestion?

[KT819GM]

Not exactly same problem, but question to same direction: is client:on("offline", .....) callback working for you? commit: cfd48f3 Lost hope already to handle connection when mqtt broker connection is unstable. When Wi-Fi connection lost everything works perfectly. Thank you!

[xfoldvar]

Hey guys.

@FrankX0 Yeah i double checked if config.MQTT['keepalive'] is not nil and actually it was 120. I also tried enter a hard-coded value like 30, 300, 120 etc. The keepalive ticker was still ticking in 60s intervals. I will do some more testing, there was some changes in internal timers API, so i will do some tests a get back to this conversation.

@KT819GM It WAS working on build 67027c0. I will build latest dev and master and test it. Can you provide some code snippet?

[KT819GM]

Thank you for reply. You can test on same code you've posted, simply check if the state of config.MQTT['connected'] will change to false, after you "cut off" mqtt server, but leave Wi-Fi working. Fastest check would be to remove WAN cable from router (or making firewall rule to DROP) after successful connection to mqtt broker.

[edit] I'm sorry for mistake, just now saw that I wrote branch not commit, commit I've testing now and having difficulties is 67027c0, so same as you, but, as I wrote, I'm not getting offline callback if firewall is set to DROP connection or if Wan connection lost, and Wi-Fi stay's stable.

[FrankX0]

@xfoldvar Still cannot reproduce what you are seeing. I just generated a dev build with debug enabled. When setting the keep alive time to 10, the debug output shows correct behaviour:

keep_alive_tick: 9
leave mqtt_socket_timer.
enter mqtt_socket_timer.
timer, queue size: 0
keep_alive_tick: 10
leave mqtt_socket_timer.
enter mqtt_socket_timer.
timer, queue size: 0

MQTT: Send keepalive packet
Sent: 2
send_if_poss, queue size: 1
keep_alive_tick: 0
leave mqtt_socket_timer.
enter mqtt_socket_sent.
sent1, queue size: 1
send_if_poss, queue size: 0
sent2, queue size: 0
leave mqtt_socket_sent.
enter mqtt_socket_received.
MQTT_DATA: type: 13, qos: 0, msg_id: 0, pending_id: 0
MQTT: PINGRESP received
send_if_poss, queue size: 0
leave mqtt_socket_received.
enter mqtt_socket_timer.
timer, queue size: 0
keep_alive_tick: 1

Can you try the same?

[FrankX0]

@xfoldvar were you able to perform your test with a debug build?

[FrankX0]

@marcelstoer As the issue cannot be reproduced and there is no further response from the reporter, I suggest to close this issue.