Running MQTT Demo periodically with OTA Update Demo causes firmware to restart

Namaste @aggarg and Community Members,

I’m using the FreeRTOS V202002.00 downloaded from AWS portal. The MQTT enabled demo was downloaded sometime in the mid of May 2020. Later, by the end of July 2020, I downloaded the OTA enabled demo, again FreeRTOS V202002.00 based. I don’t remember the exact dates when I downloaded the images.

My requirement is to run both MQTT and OTA Update threads in parallel. The OTA Update thread will perform a firmware update whenever initiated from the AWS Cloud. The MQTT thread will periodically publish the application readings to the AWS Cloud and, receive all the messages associated with the topics subscribed for.

My first attempt is to test the existing MQTT Demo and OTA Demo codes, as is. For this, I’ve created two threads for running the two demos.

The code flow is:

  1. app_main() --> DEMO_RUNNER_RunDemos() --> runDemoTask() --> Complete the initialisation and establish Wi-Fi connectivity.

  2. Instead of calling the RunMqttDemo(), I am calling my RunApplicationFunction().

  3. This function creates a thread (pvMqttAndOtaTask), which in-turn creates two more threads (pvOtaUpdateTask and pvMqttTask).

The logic is shared below w/o going into the actual code details.

    void pvMqttAndOtaTask( void * pvParameters )
    {
        /* OTA Update Demo Thread */
        status = (int) Iot_CreateDetachedThread( pvOtaUpdateTask,
                                                 &otaUpdateDemoContext,
                                                 IOT_THREAD_DEFAULT_PRIORITY,
                                                 IOT_THREAD_DEFAULT_STACK_SIZE );

        // Delay the MQTT thread creation for allowing the OTA thread to complete
        // establishing the MQTT connection, which will then be used by the MQTT thread.
        ESP_LOGI(TAG, "INFO : Delay before pvMqttTask() thread creation.");
        vTaskDelay( pdMS_TO_TICKS(15000) );

        while(1)
        {
            /* Mqtt Demo Thread */
            status = (int) Iot_CreateDetachedThread( pvMqttTask,
                                                     &mqttDemoContext,
                                                     IOT_THREAD_DEFAULT_PRIORITY,
                                                     IOT_THREAD_DEFAULT_STACK_SIZE );

            // Run the MQTT demo code every one minute. The MQTT demo completes in about 15 seconds.
            vTaskDelay( pdMS_TO_TICKS(60000) );
        }
    }

Additional points to be noted are:

  • The OTA Demo thread is created first and then, after a 15 second delay, the MQTT Demo thread is created.

  • OTA Demo code flow is pvOtaUpdateTask thread --> vStartOTAUpdateDemoTask() --> vRunOTAUpdateDemo()

  • OTA Update Demo thread is created only once and the OTA Update Demo runs continuously. However, the MQTT Demo thread is created every minute for the MQTT Demo to run periodically.

  • The same MQTT connection is used as suggested, by creating a new IotMqttConnection_t sharedMqttConnection shared by both OTA Update Demo and MQTT Demo.

  • Both the codes are run as is, w/o any major modifications within the demo codes. The only modifications are

    • In the vRunOTAUpdateDemo(), the sharedMqttConnection = xConnection.xMqttConnection; is added.
    • In the RunMqttDemo(), the _establishMqttConnection() is commented and instead, the mqttConnection = sharedMqttConnection; statement is added.

Observation

  • Both OTA Update Demo and MQTT Demo run in parallel (only once) using the same MQTT connection.
  • The firmware crashes and restarts when the MQTT Demo runs the second time after completing the 1 minute delay.
  • The error is traced back to the Line No. 606 in the iot_mqtt_api.c file --> serializeSubscription = mqttConnection->pSerializer->serialize.subscribe; Below is the code block.
    #if IOT_MQTT_ENABLE_SERIALIZER_OVERRIDES == 1
    if( mqttConnection->pSerializer != NULL )
    {
        if( mqttConnection->pSerializer->serialize.subscribe != NULL )
        {
            serializeSubscription = mqttConnection->pSerializer->serialize.subscribe;
        }
        else
        {
            EMPTY_ELSE_MARKER;
        }
    }
    else
    {
        EMPTY_ELSE_MARKER;
    }
    #endif /* if IOT_MQTT_ENABLE_SERIALIZER_OVERRIDES == 1 */
  • The partial console error log is provided below.
    Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.
        Core 0 register dump:
        PC      : 0x40148a58  PS      : 0x00060e30  A0      : 0x80148be0  A1      : 0x3ffe7e50
        0x40148a58: _subscriptionCommon at D:\gitHub\device\firmware\aws\proj04\FreeRTOS\build/../libraries/c_sdk/standard/mqtt/src/iot_mqtt_api.c:606

Some Analysis

  1. It looks like the mqttConnection->pSerializer->serialize.subscribe parameter is not getting populated from the MQTT connection created via OTA Update.

  2. The below code block is present within the _establishMqttConnection(), which does not get executed because the function is commented as mentioned above.

    #if ( IOT_MQTT_ENABLE_SERIALIZER_OVERRIDES == 1 ) && defined( IOT_DEMO_MQTT_SERIALIZER )
        networkInfo.pMqttSerializer = IOT_DEMO_MQTT_SERIALIZER;
    #endif

Kindly assist in resolving this issue.

Thanks | Regards,
Dipen

Why are you creating a new thread every minute? You probably only want to run demo every minute as opposed to creating a new thread every minute.

Where is the shared connection created and established? Would you be able to share the complete code with your modifications?

Thanks.

I’ve modified my implementation basis your above suggestion. In my custom function MqttBasedCloudCommunication(), I have made the below changes.

    int MqttBasedCloudCommunication ( bool awsIotMqttMode,
                                      const char * pIdentifier,
                                      void * pNetworkServerInfo,
                                      void * pNetworkCredentialInfo,
                                      const IotNetworkInterface_t * pNetworkInterface )
            {
            ...
            ...

            /* Step 1 - Create Pub Sub topics */

            /* Step 2 - Use the sharedMqttConnection created within the OTA Update code */

            /*
            // Below call is commented
            status = _establishMqttConnection( awsIotMqttMode,
                                               pIdentifier,
                                               pNetworkServerInfo,
                                               pNetworkCredentialInfo,
                                               pNetworkInterface,
                                               &mqttConnection );
            */

            mqttConnection = sharedMqttConnection;


            /* Step 3 - _modifySubscriptions() */
            _modifySubscriptions()

            /* Step 4 - while(1) loop */
            while(1)
            {
                /* PUBLISH (and wait) for all messages. */
                status = _publishMqttMessage( mqttConnection,
                                              pTopics );

                vTaskDelayUntil( &xLastWakeTime,
                                 pdMS_TO_TICKS(10000) );
            }

            ...
            ...

            /* Step 5 - Mqtt disconnection logic */
            ...
            ...

    }/* MqttBasedCloudCommunication() ends */

Happy to share the log of the working logic, with 2 threads.

  1. OTA Update (every second)
  2. MQTT Publish (every 10 seconds) & Subscribe (received from AWS IoT console at a random interval. I have to manually click Publish for the device to receive the subscribed topic message.)

    81 4519 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    82 4619 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    83 4719 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    84 4819 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    85 4919 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0

    86 4921 [iot_thread] [INFO ][DEMO][49210] Publishing message
    87 4921 [iot_thread] [INFO ][MQTT][49210] (MQTT connection 0x3ffd4e20) MQTT PUBLISH operation queued.
    88 4944 [iot_thread] [INFO ][DEMO][49440] MQTT PUBLISH 0 successfully sent.

    89 5019 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    90 5119 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    91 5219 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    92 5319 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    93 5419 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    94 5519 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    95 5619 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    96 5719 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    97 5819 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    98 5919 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0

    99 5921 [iot_thread] [INFO ][DEMO][59210] Publishing message
    100 5921 [iot_thread] [INFO ][MQTT][59210] (MQTT connection 0x3ffd4e20) MQTT PUBLISH operation queued.
    101 5947 [iot_thread] [INFO ][DEMO][59470] MQTT PUBLISH 0 successfully sent.

    102 6019 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    103 6119 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    104 6219 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    105 6319 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    106 6419 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0

    107 6459 [iot_thread] [INFO ][DEMO][64590] Incoming PUBLISH received:
    Subscription topic filter: iotdemo/topic/stp
    Publish QoS: 0
    Publish payload: {
      "message": "STOP"
    }

    108 6519 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    109 6619 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    110 6719 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    111 6819 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    112 6919 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0

    113 6921 [iot_thread] [INFO ][DEMO][69210] Publishing message
    114 6921 [iot_thread] [INFO ][MQTT][69210] (MQTT connection 0x3ffd4e20) MQTT PUBLISH operation queued.
    115 6951 [iot_thread] [INFO ][DEMO][69510] MQTT PUBLISH 0 successfully sent.

    116 7019 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    117 7119 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    118 7219 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    119 7319 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    120 7419 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    121 7519 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    122 7619 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    123 7719 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    124 7819 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    125 7919 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0

    126 7921 [iot_thread] [INFO ][DEMO][79210] Publishing message
    127 7921 [iot_thread] [INFO ][MQTT][79210] (MQTT connection 0x3ffd4e20) MQTT PUBLISH operation queued.
    128 7954 [iot_thread] [INFO ][DEMO][79540] MQTT PUBLISH 0 successfully sent.

    129 8019 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    130 8119 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    131 8219 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    132 8319 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    133 8419 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    134 8519 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    135 8619 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0

    136 8692 [iot_thread] [INFO ][DEMO][86920] Incoming PUBLISH received:
    Subscription topic filter: iotdemo/topic/stp
    Publish QoS: 0
    Publish payload: {
      "message": "STOP"
    }
    137 8719 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    138 8819 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0
    139 8919 [iot_thread] State: WaitingForJob  Received: 1   Queued: 0   Processed: 0   Dropped: 0

Questions

  1. Is it wrong to create and run Mqtt demo periodically?
  2. When running MqttDemo periodically (every minute), I’ve encountered below errors (refer the error codes in the logs), when creating MQTT connections periodically. Is this an expected behavior?

Console Log 1

    1061 30190 [iot_thread] [INFO ][DEMO][301900] Successfully initialized the demo. Network type for the demo: 1
    1062 30190 [iot_thread] [INFO ][MQTT][301900] MQTT library successfully initialized.
    1063 30190 [iot_thread] [INFO ][DEMO][301900] MQTT demo client identifier is esp32DevKitCBoard01 (length 19).
    E (302806) PKCS11: failed nvs get file size 4354 0
    1064 31342 [iot_thread] ERROR: Handshake failed with error code -29312
    1065 31342 [iot_thread] [ERROR][NET][313420] Failed to establish new connection. Socket status: -1002.
    I (313746) wifi: state: run -> init (0)
    I (313746) wifi: pm stop, total sleep time: 6827951 us / 12609499 us

    I (313746) wifi: new:<6,0>, old:<6,0>, ap:<255,255>, sta:<6,0>, prof:1
    I (313756) WIFI: SYSTEM_EVENT_STA_DISCONNECTED: 8
    1066 31342 [iot_thread] [ERROR][MQTT][313420] Failed to establish new MQTT connection, error NETWORK ERROR.
    1067 31342 [iot_thread] [ERROR][DEMO][313420] MQTT CONNECT returned error NETWORK ERROR.
    1068 31342 [iot_thread] [INFO ][MQTT][313420] MQTT library cleanup done.

Console Log 2

    1080 33166 [iot_thread] [INFO ][DEMO][331660] Successfully initialized the demo. Network type for the demo: 1
    1081 33166 [iot_thread] [INFO ][MQTT][331660] MQTT library successfully initialized.
    1082 33167 [iot_thread] [INFO ][DEMO][331670] MQTT demo client identifier is esp32DevKitCBoard01 (length 19).
    E (332536) PKCS11: failed nvs get file size 4354 0
    1083 33678 [iot_thread] mbedTLS sign failed with error -17168
    1084 33678 [iot_thread] ERROR: Failure in signing callback: 6
    1085 33678 [iot_thread] ERROR: Handshake failed with error code -2003
    I (337106) wifi: state: run -> init (0)
    I (337106) wifi: pm stop, total sleep time: 3531476 us / 5895814 us

    I (337116) wifi: new:<6,0>, old:<6,0>, ap:<255,255>, sta:<6,0>, prof:1
    I (337126) WIFI: SYSTEM_EVENT_STA_DISCONNECTED: 8
    1086 33678 [iot_thread] [ERROR][NET][336780] Failed to establish new connection. Socket status: -1002.
    1087 33679 [iot_thread] [ERROR][MQTT][336790] Failed to establish new MQTT connection, error NETWORK ERROR.
    1088 33679 [iot_thread] [ERROR][DEMO][336790] MQTT CONNECT returned error NETWORK ERROR.
    1089 33679 [iot_thread] [INFO ][MQTT][336790] MQTT library cleanup done.

Console Log 3

    1101 36402 [iot_thread] [INFO ][DEMO][364020] Successfully initialized the demo. Network type for the demo: 1
    1102 36402 [iot_thread] [INFO ][MQTT][364020] MQTT library successfully initialized.
    1103 36403 [iot_thread] [INFO ][DEMO][364020] MQTT demo client identifier is esp32DevKitCBoard01 (length 19).
    E (364856) PKCS11: failed nvs get file size 4354 0
    1104 36701 [iot_thread] ERROR: Handshake failed with error code -16
    1105 36701 [iot_thread] [ERROR][NET][367010] Failed to establish new connection. Socket status: -1002.
    I (367336) wifi: state: run -> init (0)
    I (367336) wifi: pm stop, total sleep time: 3493202 us / 6193608 us

    I (367336) wifi: new:<6,0>, old:<6,0>, ap:<255,255>, sta:<6,0>, prof:1
    I (367346) WIFI: SYSTEM_EVENT_STA_DISCONNECTED: 8
    1106 36701 [iot_thread] [ERROR][MQTT][367010] Failed to establish new MQTT connection, error NETWORK ERROR.
    1107 36701 [iot_thread] [ERROR][DEMO][367010] MQTT CONNECT returned error NETWORK ERROR.
    1108 36701 [iot_thread] [INFO ][MQTT][367010] MQTT library cleanup done.

Thanks | Regards,
Dipen

Is it wrong to create and run Mqtt demo periodically?

It is not wrong but there is no point in re-creating and deleting a task - it is better to put it to sleep when the task has nothing to do.

When running MqttDemo periodically (every minute), I’ve encountered below errors ( refer the error codes in the logs ), when creating MQTT connections periodically. Is this an expected behavior?

This is certainly not expected behavior. Probably you are trying to access creds before those are written. The code flow should be:

  1. Provision credentials.
  2. Connect to WiFi AP.
  3. Establish MQTT Connection.
  4. Create 2 threads - one for OTA and one for MQTT. Both of these threads use the MQTT connection established in step 3.

Would you be able to share your complete code?

Thanks.

Namaste @aggarg,

At the outset, apologies for my delayed replies.

Okay. That does make sense. I suppose re-creating a MQTT task might make sense when the communication is less frequent; for a possible scenario where the established communication remains idle for a significant amount of time as compared to the time when the data/ message is Published to the Cloud. And, for the scenario where only messages need to be Published w/o any Subscriptions.

Most importantly, closing a MQTT connection would disable Subscription i.e., receiving the messages associated with the topics subscribed for.

Your suggested steps 3 and 4 might be different from what has been implemented in my application. The difference being, the MQTT connection is being established when running the OTA Update demo after creating the OTA Update thread. The created MQTT connection is then saved as sharedMqttConnection, which is then used by the MQTT demo, over a second thread.

I’ll surely share the code at the earliest.

Thanks | Regards,
Dipen

I suppose re-creating a MQTT task might make sense when the communication is less frequent;

A task which is not in “Ready” state, does not consume any CPU. So I do not think re-creating provides any benefit even in less frequent communication scenario. You should rather put the task to sleep using vTaskDelay or vTaskDelayUntil.

The difference being, the MQTT connection is being established when running the OTA Update demo after creating the OTA Update thread. The created MQTT connection is then saved as sharedMqttConnection, which is then used by the MQTT demo, over a second thread.

That should work too as long as you ensure that the MQTT task does not access sharedMqttConnection until the OTA task has created it.

Thanks.

Yes, I am making use of the vTaskDelayUntil to put the task to sleep and, also achieve the periodic behavior.

In order to ensure this, I am calling the vTaskDelay immediately on thread creation and then running the MQTT Demo. A delay of 15 seconds serves the purpose.

/*
  * Delay the MQTT thread immediately upon creation and, let the
  * OTA thread complete establishing the MQTT connection, which will then be
  * used by this thread.
  */
vTaskDelay( pdMS_TO_TICKS(15000) );

...
...

/* Call the MQTT Demo function */
status = pContext->demoFunction( true,
                                 clientcredentialIOT_THING_NAME,
                                 pConnectionParams,
                                 pCredentials,
                                 pNetworkInterface );

Thanks | Regards,
Dipen

Relying on a delay for synchronization is not a good idea for a production system. Either use some synchronization primitive (task notification/semaphore) or consider the flow I mentioned in one of the above post.

Thanks.

Namaste @aggarg,

Point taken! Thank you for highlighting this potential issue. :+1: for bringing this to my attention.

When creating Threads with Iot_CreateDetachedThread, it’s not possible to get the TaskHandle_t required for leveraging Task Notifications. In this earlier post of mine on this matter, you had recommended creating tasks using xTaskCreate().

I’m leveraging the AWS IoT Device SDK C, so I suppose I will have to use the IoTMutex_xxx and IoTSemaphore_xxx APIs for ensuring the synchronisation.

I shall look in to your suggested flow of creating an MQTT connection first and, then creating the two threads.

Thanks | Regards,
Dipen

Namaste @aggarg,

Thank you for your patience.

source_and_header_files.zip (30.4 KB)

Enclosed is the set of the files, which have been modified for my application. A diff view with the corresponding FreeRTOS V202002.00 files should help you view the differences. Do let me know if you require any further inputs from my side.

Do share your review comments.

Thanks | Regards,
Dipen

I looked at the code you shared and the approach seems okay. You need to ensure that:

  • MQTT demo starts after the shared connection is ready (this I mentioned in my previous comments too).
  • MQTT demo does not disconnect as the OTA is also using the same connection.

Let me know if you still see any issue after these changes.

Thanks.

Namaste @aggarg,

Many thanks for reviewing my source code. Appreciated! :+1:

Yes, I have made a note of all your valuable comments. I’m well aware that almost all of the comments need to be implemented, in order to ensure an efficient and bug free programming logic for my product under development. Nevertheless, I’m happy to share that it’s been a wonderful experience integrating Amazon FreeRTOS with ESP32.

Thanks | Regards,
Dipen

1 Like

Glad to hear that you had a good experience. Let us know if you face any other issue.

Thanks.

1 Like