[v4.4.2] Doing start + stop + start triggers an error (IDFGH-8543)

[KonssnoK]

As per title,

if i do
esp_mqtt_client_start
esp_mqtt_client_stop
esp_mqtt_client_start

the last start returns an error.

I had to modify the code to see what was the error (please make significant error messages).

The internal state machine of the MQTT client is stuck on MQTT_STATE_WAIT_RECONNECT.

the issue is in esp_mqtt_client_stop, where the state of the machine is put before waiting for the task to end, which means that any call to esp_mqtt_abort_connection() will put the reconnect status after being disconnected.

W (15:02:29.494) network: Network disconnected. Halt MQTT: 1
W (15:02:29.499) mesh_main: Start checking for FIXED ROOT handover
E (15:02:29.499) TRANSPORT_BASE: poll_read select error 113, errno = Software caused connection abort, fd = 62
E (15:02:29.509) TRANSPORT_BASE: poll_write select error 0, errno = Success, fd = 62
E (15:02:29.519) MQTT_CLIENT: Poll read error: 119, aborting connection
W (15:02:29.528) TRANSPORT_BASE: Poll timeout or error, errno=Success, fd=62, timeout_ms=10000
E (15:02:29.542) MQTT_CLIENT: Writing failed: errno=0
I (15:02:29.547) mqtt_app: MQTT_EVENT_ERROR
E (15:02:29.552) MQTT_CLIENT: Error sending disconnect message
I (15:02:29.560) mqtt_app: MQTT_EVENT_DISCONNECTED
I (15:02:44.259) network: network:: routing table update

I (15:02:44.740) processor: send status... (60494ms)
W (15:02:59.506) mesh_main: Triggering FIXED ROOT handover

I (15:03:06.246) esp-netif_lwip-ppp: Connected
W (15:03:06.255) network: GOT IP from ppp_sta
W (84460) wifi:Haven't to connect to a suitable AP now!
I (15:03:06.264) mesh_netif: Interface AP
W (84474) wifi:Haven't to connect to a suitable AP now!
I (15:03:06.275) mesh_netif: Clearing interface <sta>
I (15:03:06.281) mesh_netif: It was a wifi station, removing handlers
I (15:03:06.288) mesh_netif: Interface PPP
I (15:03:06.292) modem_comm: Modem connected to PPP server
I (15:03:06.300) network: Network connected
E (15:03:06.302) MQTT_CLIENT: Client has started 3

[KonssnoK]

Example of workaround

[KonssnoK]

any feedback?

[euripedesrocha]

Hi @KonssnoK thanks for reporting.
I'm investigating the issue and for clarification:

• The client was in MQTT_STATE_WAIT_RECONNNECT when the esp_mqtt_client_stop was called?
• The call for esp_mqtt_client_stop returned ESP_OK?

[KonssnoK]

hello @euripedesrocha ,

• Yes, it's visible in the logs E (15:03:06.302) MQTT_CLIENT: Client has started 3
• Yes, ESP_OK

W (14:29:53.363) network: Network disconnected. Halt MQTT: 1

-- > HERE STOP IS CALLED

E (14:29:53.371) TRANSPORT_BASE: poll_read select error 113, errno = Software caused connection abort, fd = 62
E (14:29:53.385) MQTT_CLIENT: Poll read error: 119, aborting connection
W (14:29:53.407) TRANSPORT_BASE: Poll timeout or error, errno=Success, fd=62, timeout_ms=10000
E (14:29:53.421) MQTT_CLIENT: Writing failed: errno=0

void mqtt_app_stop()
{
    if (!self->client) {
        ESP_LOGW(TAG, "MQTT Client not allocated!");
        return;
    }

    ESP_ERROR_CHECK_WITHOUT_ABORT(esp_mqtt_client_stop(self->client));
}

[euripedesrocha]

Hi @KonssnoK, from your information we identified the issue, and we have a fix for it. Yet I wasn't able to reproduce the scenario. Could you share more about your configuration and client usage? Do you have API_LOCKS disabled?

[KonssnoK]

no, standard configuration.

We have a MESH networking,
on Parent disconnection we trigger

void mqtt_app_stop()
{
    if (!self->client) {
        ESP_LOGW(TAG, "MQTT Client not allocated!");
        return;
    }

    esp_mqtt_client_stop(self->client);
}

on IP received we do

void mqtt_app_start(void)
{
    if (!self->client) {
        ESP_LOGW(TAG, "MQTT Client not allocated!");
        return;
    }

    // Starts MQTT
    esp_mqtt_client_start(self->client);
}

once we do

    esp_mqtt_client_config_t mqtt_cfg = {
        .uri = server,
        .cert_pem = (const char*)server_crt,
        .client_cert_pem = (const char*)client_crt,
        .client_key_pem = NULL,
        .ds_data = ds_data,
        .username = user,
        .password = pass,
        .client_id = client_id,
        .task_prio = TASK_PRIORITY_DEFAULT,
        .task_stack = TASK_STACK_DEPTH_DEFAULT
    };

    self->client = esp_mqtt_client_init(&mqtt_cfg);
    esp_mqtt_client_register_event(self->client, ESP_EVENT_ANY_ID, mqtt_event_handler, self->client);

[KonssnoK]

@david-cermak could you please notify when the esp-mqtt component is pushed on esp-idf v4.4?
thanks!

[david-cermak]

@KonssnoK Will reference this fix in IDF release/v4.4 together with the other issue you posted in IDF espressif/esp-idf#9492. As a subscriber to that issue, you should receive an automatic notification when we close it and that would also mean that this fix is available as well.

So, does the af58f5f fix your issue? Please comment or reopen if not.

[KonssnoK]

@david-cermak we haven't checked yet, working on other issues with your colleagues.
Sure I'll reopen in case i see any issue :)

[AxelLin]

So, does the af58f5f fix your issue? Please comment or reopen if not.

I cannot find the fix in esp-idf v4.x branches (v4.4 and v4.3), would you please update the esp-idf submodule and push the fix?

[euripedesrocha]

@AxelLin the back porting process is ongoing. It takes a little to be available due to the testing process to avoid regressions.

[AxelLin]

@AxelLin the back porting process is ongoing. It takes a little to be available due to the testing process to avoid regressions.

esp-idf-v4.3 still does not include this one-line-fix.