MQTT client subscribe crashes after some 30 seconds

[xal88]

Describe the bug Can subscribe to a mqtt_topic and read some values. Crashes after some 30 seconds every time. No other app is running in this ESP32. Tried on 2 different ESPs.

To reproduce

• Code from git example

  
  import mqtt
  import net

main: socket := net.open.tcp_connect "172.21.14.253" 1883 client := mqtt.Client "toit-client-id" mqtt.TcpTransport socket

task:: client.handle: | topic/string payload/ByteArray | print "$Time.now.utc Received message on topic '$topic': $payload"

client.subscribe "device/events" --qos=1

client.publish "device/data" "Hello World".to_byte_array

* log result:

[mqtt_example.toit] 2021-10-16T11:20:37.533479Z: [mqtt_example.toit] 2021-10-16T11:20:37 Received message on topic 'device/events': #[0x32] [mqtt_example.toit] 2021-10-16T11:21:29 Received message on topic 'device/events': #[0x31, 0x39] [mqtt_example.toit] 2021-10-16T11:22:01 Received message on topic 'device/events': #[0x31, 0x31] [mqtt_example.toit] 2021-10-16T11:22:08.469751Z: [mqtt_example.toit] EXCEPTION error. [mqtt_example.toit] UNEXPECTED_END_OF_READER [mqtt_example.toit] 0: BufferedReader.ensure. /reader.toit:92:16 [mqttexample.toit] 1: BufferedReader.ensure /reader.toit:61:27 [mqtt_example.toit] 2: BufferedReader.ensure /reader.toit:92:5 [mqtt_example.toit] 3: BufferedReader.byte /reader.toit:151:5 [mqtt_example.toit] 4: BufferedReader.read_byte /reader.toit:426:10 [mqtt_example.toit] 5: Packet.deserialize /packets.toit:21:21 [mqtt_example.toit] 6: TcpTransport.receive /tcp.toit:31:18 [mqttexample.toit] 7: Client.run /client.toit:145:28 [mqtt_example.toit] 8: Client... /client.toit:52:11 [mqtt_example.toit] 9: catch. /core/exceptions.toit:111:10 [mqtt_example.toit] 10: catch /core/exceptions.toit:109:1 [mqtt_example.toit] 11: catch /core/exceptions.toit:60:10 [mqtt_example.toit] 12: Client.. /client.toit:51:9 [mqtt_example.toit] 13: Client. /client.toit:49:30 [mqtt_example.toit] [mqtt_example.toit] [mqtt_example.toit] [mqtt_example.toit] 2021-10-16T11:22:08.519444Z: <process terminated - exit code: 0>

**Expected behavior**
working stable for hours...

**SDK and console version (please complete the following information):**
FW 1.4.1 
MQTT client 1.1.1
+---------+------------+
| v1.12.0 | 2021-10-08 |
+---------+------------+

[andersjohnsen]

I can mirror this behavior locally. I suspect a missing ping/pong handler. I'll go ahead and add that.

[andersjohnsen]

Fixed and released as mqtt v1.1.2.

[xal88]

Hi, used MQTT 1.1.2 to test. This is better, but still crashed after ~20 minutes.

[andersjohnsen]

Limited information here, but it looks like the device lost Wifi connectivity. Let me know if it continues to behave like this.

[xal88]

deploy onto a second ESP32 very close to the AP with 100% signal, running for 2h now w/o reboots. First ESP has only 20% network signal. Stopping the WLAN crashes both. Will report longterm test...

[andersjohnsen]

Hi xal88,

Just to be sure we agree on the expected behavior, but the exception reported above will most likely result in the device restarting the application (perhaps after a very short deep sleep, under 5s).

Would you expect something else to happen? Because from my perspective, this is working as intended :)

Cheers,

• Anders

[xal88]

Hi Anders, the device restart is acceptable behavior, now that I know. ( makes no difference if reconnect or restart app ) The mqtt 1.1.2 subscribe is still not stable. After ~2,5 hours the whole [system] crashes. Was just subscribed to one topic without update messages, and one retained message.

• Software reset via esp_restart. crashes=2 out-of-memory=1

Can be reproduced every time the Wifi connection is stable more than 2,5 hours. What con I do to provide more information? regards Alf

import mqtt
import net
import device

HOST      ::= "172.21.14.253"
PORT      ::= 1883
CLIENT_ID ::= "($device.name)_MQTTtest"
TOPIC ::= "device/($device.name)/test"

main:
  socket_mqtt := net.open.tcp_connect "172.21.14.253" 1883
  client_mqtt := mqtt.Client
    CLIENT_ID
    mqtt.TcpTransport socket_mqtt

  task::
    client_mqtt.handle: | topic/string payload/ByteArray |
      print "$Time.now.utc Received message on topic '$topic': $payload.to_string"

  client_mqtt.subscribe  "$TOPIC/+" --qos=1

  client_mqtt.publish "$TOPIC/msg" "Hello World".to_byte_array