Connection to mqtt broker is closed (LWMQTT_MISSING_OR_WRONG_PACKET) when an external callback is executed

[mrdc]

Hello,

I'm experiencing a bug when mqtt connection is closed (error LWMQTT_MISSING_OR_WRONG_PACKET) as soon as external callback is executed. It looks like WiFiClientSecure which arduino-mqtt uses under the hood, is not async, that's why tls connection is interrupted by this callback. The same code, which I use for a long time, works fine with asyncmqtt, which is uses asynctcp under the hood. I've decided to switch to arduino-mqtt, because it's maintained and has support for client certificates.

WiFiClientSecure network;
MQTTClient mqtt_client(512);

void messageReceivedAdvance(MQTTClient *client, char topic[], char bytes[], int length) {
Serial.printf("Topic: %s , Payload: %s, Size: %d\n", topic, bytes, length);
}

void my_external_callback(){
...
}

void setup()
{
...
network.setCACert(CA);
network.setCertificate(cert);
network.setPrivateKey(key);

mqtt_client.onMessageAdvanced(messageReceivedAdvance);
mqtt_client.setWill(lwt_buff, "Msg", false, 1);
mqtt_client.setHost(ADDRESS, PORT);
mqtt_client.begin(network);
...
}

void mqtt_connect()
{
if (mqtt_client.connect("id", USERNAME, PASSWORD))
  {
    Serial.println("connected!");
  }
}

void loop()
{
...
if(!mqtt_client.connected()){
    Serial.printf("\nMQTT error: %d\n", mqtt_client.lastError());
    mqtt_connect();
 }

...
}

[ 13013][V][ssl_client.cpp:59] start_ssl_client(): Free internal heap before TLS 130475
[ 13013][V][ssl_client.cpp:65] start_ssl_client(): Starting socket
[ 13206][V][ssl_client.cpp:141] start_ssl_client(): Seeding the random number generator
[ 13209][V][ssl_client.cpp:150] start_ssl_client(): Setting up the SSL/TLS structure...
[ 13212][V][ssl_client.cpp:166] start_ssl_client(): Loading CA cert
[ 13253][V][ssl_client.cpp:215] start_ssl_client(): Loading CRT cert
[ 13285][V][ssl_client.cpp:224] start_ssl_client(): Loading private key
[ 13340][V][ssl_client.cpp:234] start_ssl_client(): Setting hostname for TLS session...
[ 13341][V][ssl_client.cpp:249] start_ssl_client(): Performing the SSL/TLS handshake...
[ 14982][D][ssl_client.cpp:262] start_ssl_client(): Protocol is TLSv1.2 Ciphersuite is TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
[ 14983][D][ssl_client.cpp:264] start_ssl_client(): Record expansion is 29
[ 14989][V][ssl_client.cpp:270] start_ssl_client(): Verifying peer X.509 certificate...
[ 14997][V][ssl_client.cpp:279] start_ssl_client(): Certificate verified.
[ 15004][V][ssl_client.cpp:294] start_ssl_client(): Free internal heap after TLS 91435
[ 15011][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 175 bytes...
[ 15078][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 15 bytes...
[ 15180][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 60 bytes...
[ 15270][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 102 bytes...
[ 15276][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 76 bytes...
[ 15443][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 71 bytes...
[ 15521][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 96 bytes...

Omitted 56 messages: [V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 96 bytes...

---> here I have a callback and then mqtt connection is dropped and then tls session is re-established.

[130671][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 138 bytes...
[130691][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 101 bytes...
[130700][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 73 bytes...
[131753][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 96 bytes...
[132764][V][ssl_client.cpp:302] stop_ssl_socket(): Cleaning SSL connection.
[132881][V][ssl_client.cpp:302] stop_ssl_socket(): Cleaning SSL connection.
[132927][V][ssl_client.cpp:59] start_ssl_client(): Free internal heap before TLS 130475
[132932][V][ssl_client.cpp:65] start_ssl_client(): Starting socket
[133100][V][ssl_client.cpp:141] start_ssl_client(): Seeding the random number generator
[133102][V][ssl_client.cpp:150] start_ssl_client(): Setting up the SSL/TLS structure...
[133104][V][ssl_client.cpp:166] start_ssl_client(): Loading CA cert
[133146][V][ssl_client.cpp:215] start_ssl_client(): Loading CRT cert
[133178][V][ssl_client.cpp:224] start_ssl_client(): Loading private key
[133233][V][ssl_client.cpp:234] start_ssl_client(): Setting hostname for TLS session...
[133233][V][ssl_client.cpp:249] start_ssl_client(): Performing the SSL/TLS handshake...
[134870][D][ssl_client.cpp:262] start_ssl_client(): Protocol is TLSv1.2 Ciphersuite is TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
[134871][D][ssl_client.cpp:264] start_ssl_client(): Record expansion is 29
[134877][V][ssl_client.cpp:270] start_ssl_client(): Verifying peer X.509 certificate...
[134885][V][ssl_client.cpp:279] start_ssl_client(): Certificate verified.
[134891][V][ssl_client.cpp:294] start_ssl_client(): Free internal heap after TLS 91435
[134899][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 175 bytes...
[134967][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 15 bytes...
[135042][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 60 bytes...
[135084][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 102 bytes...
[135091][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 76 bytes...
[135174][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 73 bytes...
[135274][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 96 bytes...
[137276][V][ssl_client.cpp:332] send_ssl_data(): Writing HTTP request with 96 bytes...

[256dpi]

What does the "my_external_callback" do?

[mrdc]

What does the "my_external_callback" do?

It processes received data triggered by an interrupt. No IO operations with network etc. Ah, it also sends data via mqtt after processing:

void mqtt_publish(String data, String topic){
    mqtt_client.publish(data, topic);
}

void my_external_callback(){
...here we process incoming data

at the end we call 
mqtt_publish(data, topic);
return;
}

[newHagen]

Processing data is not exactly recommended within the interrupt handler and should be avoided.

Publishing data is more within the region "don't even consider it".

Excecuting the interrupt handler does suspend the loop and any other task the processor is doing. A save method to handle the interrupt is to store the received data somewhere - like a global variable - and to set a flag that stuff has to be done.

In the loop you can check this flag, process the data and publish the result. When you're done, reset the flag.

[mrdc]

Excecuting the interrupt handler does suspend the loop and any other task the processor is doing.

I think in my case it was a callback with some data processing, not the real interrupt. But it's also possible that under the hood it used some sort of interrupt that's why it affected this mqtt library. The issue is in the library, because asyncmqtt worked fine w/o any issues.

[256dpi]

The library is not interrupt- or thread-safe. You need to ensure that no other operation is using the client when using in parallel.

Closing for now, please reopen if the issue persists.