MQTT TLS connection drop (Lua 5.3)

[KT819GM]

Expected behaviour

Secured (TLS) MQTT connection stays alive if WiFi is connected.

Actual behaviour

MQTT client will not hold connection and will close it after keep alive timer expire. With insecure config keep_alive_tick is active, with secure - not. There is similar bug report: #2932 but proposed workaround #undef MBEDTLS_SSL_ENCRYPT_THEN_MAC is not the case here, as connection when active (in keep alive time frame) is stable. If needed I can provide exact FW, Lua test code (with direct connection to same server) to recognised developer, because of a security reasons.

Debug info with secure connection:

pm open,type:2 0
MyMqtt.Connect()
enter mqtt_socket_client.
NodeMCU_58459d
length username: 8
length password: 9
MQTT: Init info: cert, secret, secret
leave mqtt_socket_client.
enter mqtt_socket_lwt.
mqtt_socket_lwt.
mqtt_socket_lwt: topic: lwt, message: Disconnected after 120 sec, qos: 0, retain: 1
leave mqtt_socket_lwt.
enter mqtt_socket_close.
leave mqtt_socket_close.
enter mqtt_socket_connect.
TCP ip is set: 255.255.255.255
TCP port is set: 8883.
leave mqtt_socket_connect.
> enter socket_dns_found.
TCP ip is set: superserver
enter socket_connect.
leave socket_connect
leave socket_dns_found.
client handshake start.
enter mqtt_socket_timer.
MQTT not connected
client handshake ok!
enter mqtt_socket_connected.
Send MQTT connection infomation, data len: 72, d[0]=16 
leave mqtt_socket_connectet, heap = 21584.
enter mqtt_socket_sent.
enter mqtt_socket_received (rxlen=4).
MQTT: Connected
enter mqtt_socket_subscribe.
subscribe table
topic: test2 - qos: 0, length: 13
topic: test3 - qos: 0, length: 21
topic: test1 - qos: 0, length: 29
topic: test1 - id: 1 - qos: 1, length: 28
msg_size: 1, event_timeout: 0
Sent: 28
send_if_poss, queue size: 1
subscribe, queue size: 1
leave mqtt_socket_subscribe.
enter mqtt_socket_on.
leave mqtt_socket_on.
enter mqtt_socket_on.
leave mqtt_socket_on.
enter mqtt_socket_on.
leave mqtt_socket_on.
send_if_poss, queue size: 1
leave mqtt_socket_received
enter mqtt_socket_sent.
sent1, queue size: 1
sent2, queue size: 1
leave mqtt_socket_sent.
enter mqtt_socket_received (rxlen=7).
MQTT_DATA: msg length: 7, buffer length: 7
MQTT_DATA: type: 9, qos: 0, msg_id: 1, pending_id: 1, msg length: 7, buffer length: 7
MQTT: Subscribe successful
subscribe success
send_if_poss, queue size: 0
leave mqtt_socket_received
pm open,type:2 0

<<<< After 120 sec >>>>

Reason:[-0x7880]
enter mqtt_socket_disconnected.
mqtt lost! <<<< Custom message on *Offline* event
leave mqtt_socket_disconnected.

Debug info with insecure version

MyMqtt.Connect()
enter mqtt_socket_client.
NodeMCU_58459d
length username: 8
length password: 9
MQTT: Init info: cert, secret, secret
leave mqtt_socket_client.
enter mqtt_socket_lwt.
mqtt_socket_lwt.
mqtt_socket_lwt: topic: lwt, message: Disconnected after 120 sec, qos: 0, retain: 1
leave mqtt_socket_lwt.
enter mqtt_socket_close.
leave mqtt_socket_close.
enter mqtt_socket_connect.
TCP ip is set: 255.255.255.255
TCP port is set: 1883.
leave mqtt_socket_connect.
> enter socket_dns_found.
TCP ip is set: superserver
enter socket_connect.
leave socket_connect
leave socket_dns_found.
enter mqtt_socket_connected.
Send MQTT connection infomation, data len: 72, d[0]=16 
leave mqtt_socket_connectet, heap = 36432.
enter mqtt_socket_sent.
enter mqtt_socket_received (rxlen=4).
MQTT: Connected
enter mqtt_socket_subscribe.
subscribe table
topic: test3 - qos: 0, length: 13
topic: test2 - qos: 0, length: 21
topic: test1 - qos: 0, length: 29
topic: test1 - id: 1 - qos: 1, length: 28
msg_size: 1, event_timeout: 0
Sent: 28
send_if_poss, queue size: 1
subscribe, queue size: 1
leave mqtt_socket_subscribe.
enter mqtt_socket_on.
leave mqtt_socket_on.
enter mqtt_socket_on.
leave mqtt_socket_on.
enter mqtt_socket_on.
leave mqtt_socket_on.
send_if_poss, queue size: 1
leave mqtt_socket_received
enter mqtt_socket_sent.
sent1, queue size: 1
sent2, queue size: 1
leave mqtt_socket_sent.
enter mqtt_socket_received (rxlen=7).
MQTT_DATA: msg length: 7, buffer length: 7
MQTT_DATA: type: 9, qos: 0, msg_id: 1, pending_id: 1, msg length: 7, buffer length: 7
MQTT: Subscribe successful
subscribe success
send_if_poss, queue size: 0
leave mqtt_socket_received
enter mqtt_socket_timer.
timer, queue size: 0
keep_alive_tick: 1
leave mqtt_socket_timer.
enter mqtt_socket_timer.
timer, queue size: 0
keep_alive_tick: 2
leave mqtt_socket_timer.
enter mqtt_socket_timer.
timer, queue size: 0
keep_alive_tick: 3
leave mqtt_socket_timer.

--------//---------

NodeMCU startup banner

	branch: dev
	commit: e60642f14fe2a2bee75e4307801df1a6ea6b6b13
	release: 3.0-master_20200610 +9
	release DTS: 202006142003
	SSL: true
	build type: float
	LFS: 0x20000 bytes total capacity
	modules: adc,ads1115,bit,bme280,cron,crypto,dht,enduser_setup,file,gpio,http,i2c,mdns,mqtt,net,node,ow,pipe,pwm2,rtcmem,rtctime,sjson,sntp,softuart,spi,tls,tmr,uart,u8g2,websocket,wifi
 build 2020-06-15 05:00 powered by Lua 5.3.5 on SDK 3.0.1-dev(fce080e) 

Hardware

Generic ESP-07S

[KT819GM]

Update - code from @nwf repo does not have this issue, added mqtt part to current dev and got successful keep alive on TLS. Still, could not find reason , what is wrong in current dev, but I hope mqtt module from Nathaniel repo will be added to PR.

MQTT: Send keepalive packet
Sent: 2
send_if_poss, queue size: 1
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 (rxlen=2).
MQTT_DATA: msg length: 2, buffer length: 2
MQTT_DATA: type: 13, qos: 0, msg_id: 0, pending_id: 0, msg length: 2, buffer length: 2
MQTT: PINGRESP received
send_if_poss, queue size: 0
leave mqtt_socket_received

[KT819GM]

Does this requires another testing or we it can be closed as fix was committed? @nwf

[nwf]

If it works for you, go ahead and close it. :)