Namaste Forum Member,
The FreeRTOS version in use for development is V202002.00.
The MQTT Demo runs as desired. However, after the required modifications in my application code, I am getting the below error for the MQTT Publish operation.
MQTT PUBLISH 0 could not be sent. Error NO RESPONSE.
The RunMqttDemo() in the iot_demo_mqtt.c source file has been modified as below.
int RunMqttDemo()
{
...
...
_establishMqttConnection();
_modifySubscriptions();
while(1)
{
if( true == newReadingsAvailable )
{
_publishMessage(OutletOne);
_publishMessage(OutletTwo);
}
}
...
...
}
For debugging purpose, the below #define has been set to 1.
#define PUBLISH_RETRY_LIMIT ( 1 )
With this, the JSON response I get on the AWS IoT console when periodically publishing readings at 15 second interval and, the serial console log are as below.
The Serial Console Log is shared below.
2 14 [iot_thread] [INFO ][DEMO][140] ---------STARTING DEMO---------
I (153) BTDM_INIT: BT controller compile version [9891bc6]
3 14 [iot_thread] [INFO ][INIT][140] SDK successfully initialized.
I (163) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
W (173) phy_init: failed to load RF calibration data (0x1102), falling back to full calibration
I (313) phy: phy_version: 4102, 2fa7a43, Jul 15 2019, 13:06:06, 0, 2
GAP procedure initiated: stop advertising.
GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=480 adv_itvl_max=960
I (613) wifi: wifi driver task: 3ffd91cc, prio:23, stack:3584, core=0
I (613) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (613) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (643) wifi: wifi firmware version: c94f3e6
I (643) wifi: config NVS flash: enabled
I (643) wifi: config nano formating: disabled
I (643) wifi: Init dynamic tx buffer num: 32
I (643) wifi: Init data frame dynamic rx buffer num: 32
I (653) wifi: Init management frame dynamic rx buffer num: 32
I (653) wifi: Init management short buffer num: 32
I (663) wifi: Init static rx buffer size: 1600
I (663) wifi: Init static rx buffer num: 10
I (663) wifi: Init dynamic rx buffer num: 32
I (673) wifi: mode : sta (4c:11:ae:df:af:e8)
I (683) WIFI: SYSTEM_EVENT_STA_START
I (803) wifi: new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
I (1783) wifi: state: init -> auth (b0)
I (1793) wifi: state: auth -> assoc (0)
I (1793) wifi: state: assoc -> run (10)
I (1903) wifi: connected with tkkfnB2, channel 1, BW20, bssid = 14:ae:85:e6:45:86
I (1903) wifi: pm start, type: 1
I (1903) WIFI: SYSTEM_EVENT_STA_CONNECTED
I (2633) event: sta ip: 192.168.29.25, mask: 255.255.255.0, gw: 192.168.29.1
I (2633) WIFI: SYSTEM_EVENT_STA_GOT_IP
I (2633) dual_outlet: INFO : Entering a short (20 seconds) delay for the MQTT CONNECT operation to complete before other threads are started.
4 262 [iot_thread] [INFO ][DEMO][2620] Successfully initialized the demo. Network type for the demo: 1
I (2643) dual_outlet: INFO : Thread pvEsp32GetTimeOverSntp() started.
I (2663) dual_outlet: Time is not set yet. Attempting to get the current time over NTP.
I (2673) dual_outlet: Waiting for system time to be set... (1/10)
I (2643) dual_outlet: INFO : Thread pvMqttTask() started. Delaying task...
I (3133) dual_outlet: Notification of a time synchronization event
I (3683) dual_outlet: Current UNIX EPOCH Time is: 1605296414
I (3683) dual_outlet: Equivalent GMT Date Time is: Fri Nov 13 19:40:14 2020
I (12663) dual_outlet: Current UNIX EPOCH Time is: 1605296423
I (12663) dual_outlet: Equivalent GMT Date Time is: Fri Nov 13 19:40:23 2020
I (17683) dual_outlet: INFO : Thread pvMqttTask() re-started.
5 1767 [iot_thread] [INFO ][MQTT][17670] MQTT library successfully initialized.
6 1767 [iot_thread] [INFO ][DEMO][17670] MQTT demo client identifier is esp32DevKitCBoard01 (length 19).
E (18213) PKCS11: failed nvs get file size 4354 0
I (22643) dual_outlet: INFO : Thread pvEsp32AndEnergyMeterCommunication() started.
I (22643) dual_outlet: INFO : Thread pvCleanupTask() started.
I (22663) dual_outlet: Current UNIX EPOCH Time is: 1605296433
I (22663) dual_outlet: Equivalent GMT Date Time is: Fri Nov 13 19:40:33 2020
I (22743) dual_outlet: Outlet Id = 0
E (22743) dual_outlet: Failed to obtain new readings from the Energy Meter.
I (22843) dual_outlet: Outlet Id = 1
E (22843) dual_outlet: Failed to obtain new readings from the Energy Meter.
E (22843) dual_outlet: INFO : Free Heap size = 62756.
E (22843) dual_outlet: INFO : Minimum Ever Free Heap size = 54604.
7 2297 [iot_thread] [INFO ][MQTT][22970] Establishing new MQTT connection.
8 2298 [iot_thread] [INFO ][MQTT][22980] Anonymous metrics (SDK language, SDK version) will be provided to AWS IoT. Recompile with AWS_IOT_MQTT_ENABLE_METRICS set to 0 to disable.
9 2298 [iot_thread] [INFO ][MQTT][22980] (MQTT connection 0x3ffdf0f0, CONNECT operation 0x3ffdf854) Waiting for operation completion.
10 2338 [iot_thread] [INFO ][MQTT][23380] (MQTT connection 0x3ffdf0f0, CONNECT operation 0x3ffdf854) Wait complete with result SUCCESS.
11 2338 [iot_thread] [INFO ][MQTT][23380] New MQTT connection 0x3ffe3210 established.
12 2338 [iot_thread] [INFO ][MQTT][23380] (MQTT connection 0x3ffdf0f0) SUBSCRIBE operation scheduled.
13 2338 [iot_thread] [INFO ][MQTT][23380] (MQTT connection 0x3ffdf0f0, SUBSCRIBE operation 0x3ffdfb98) Waiting for operation completion.
14 2363 [iot_thread] [INFO ][MQTT][23630] (MQTT connection 0x3ffdf0f0, SUBSCRIBE operation 0x3ffdfb98) Wait complete with result SUCCESS.
15 2363 [iot_thread] [INFO ][DEMO][23630] All demo topic filter subscriptions accepted.
16 2363 [iot_thread] [INFO ][DEMO][23630] WIFI connection is established.
17 2363 [iot_thread] [INFO ][DEMO][23630] Publishing message
18 2363 [iot_thread] [INFO ][DEMO][23630] 114 bytes written.
19 2363 [iot_thread] [INFO ][MQTT][23630] (MQTT connection 0x3ffdf0f0) MQTT PUBLISH operation queued.
20 2363 [iot_thread] [INFO ][DEMO][23630] Publishing message
21 2363 [iot_thread] [INFO ][DEMO][23630] 114 bytes written.
22 2365 [iot_thread] [INFO ][MQTT][23650] (MQTT connection 0x3ffdf0f0) MQTT PUBLISH operation queued.
I (32663) dual_outlet: Current UNIX EPOCH Time is: 1605296443
I (32663) dual_outlet: Equivalent GMT Date Time is: Fri Nov 13 19:40:43 2020
I (37743) dual_outlet: Outlet Id = 0
E (37743) dual_outlet: Failed to obtain new readings from the Energy Meter.
I (37843) dual_outlet: Outlet Id = 1
E (37843) dual_outlet: Failed to obtain new readings from the Energy Meter.
E (37843) dual_outlet: INFO : Free Heap size = 65216.
E (37843) dual_outlet: INFO : Minimum Ever Free Heap size = 54604.
23 3784 [iot_thread] [INFO ][DEMO][37840] WIFI connection is established.
24 3784 [iot_thread] [INFO ][DEMO][37840] Publishing message
25 3784 [iot_thread] [INFO ][DEMO][37840] 114 bytes written.
26 3784 [iot_thread] [INFO ][MQTT][37840] (MQTT connection 0x3ffdf0f0) MQTT PUBLISH operation queued.
27 3784 [iot_thread] [INFO ][DEMO][37840] Publishing message
28 3784 [iot_thread] [INFO ][DEMO][37840] 114 bytes written.
29 3784 [iot_thread] [INFO ][MQTT][37840] (MQTT connection 0x3ffdf0f0) MQTT PUBLISH operation queued.
30 3871 [iot_thread] [ERROR][DEMO][38710] MQTT PUBLISH 0 could not be sent. Error NO RESPONSE.
31 3871 [iot_thread] [ERROR][DEMO][38710] MQTT PUBLISH 0 could not be sent. Error NO RESPONSE.
I (42663) dual_outlet: Current UNIX EPOCH Time is: 1605296453
I (42663) dual_outlet: Equivalent GMT Date Time is: Fri Nov 13 19:40:53 2020
Done
D:\gitHub\..\firmware\aws\proj04\FreeRTOS>
The JSON Log is shared below.
{
"messages": [
{
"format": "json",
"payload": {
"timestamp": "1605296433",
"deviceId": "esp32DevKitCBoard01",
"rfidUid": "a5a5a5a5",
"outletId": "0",
"Vlt": "0000000.00"
},
"qos": 0,
"timestamp": 1605296436682,
"topic": "dualOutlet/topic/kWh"
},
{
"format": "json",
"payload": {
"timestamp": "1605296433",
"deviceId": "esp32DevKitCBoard01",
"rfidUid": "5a5a5a5a",
"outletId": "1",
"Vlt": "0000000.00"
},
"qos": 0,
"timestamp": 1605296437093,
"topic": "dualOutlet/topic/kWh"
},
{
"format": "json",
"payload": {
"timestamp": "1605296433",
"deviceId": "esp32DevKitCBoard01",
"rfidUid": "a5a5a5a5",
"outletId": "0",
"Vlt": "0000000.00"
},
"qos": 0,
"timestamp": 1605296441599,
"topic": "dualOutlet/topic/kWh"
},
{
"format": "json",
"payload": {
"timestamp": "1605296433",
"deviceId": "esp32DevKitCBoard01",
"rfidUid": "5a5a5a5a",
"outletId": "1",
"Vlt": "0000000.00"
},
"qos": 0,
"timestamp": 1605296441803,
"topic": "dualOutlet/topic/kWh"
},
{
"format": "json",
"payload": {
"timestamp": "1605296448",
"deviceId": "esp32DevKitCBoard01",
"rfidUid": "a5a5a5a5",
"outletId": "0",
"Vlt": "0000000.00"
},
"qos": 0,
"timestamp": 1605296450814,
"topic": "dualOutlet/topic/kWh"
},
{
"format": "json",
"payload": {
"timestamp": "1605296448",
"deviceId": "esp32DevKitCBoard01",
"rfidUid": "5a5a5a5a",
"outletId": "1",
"Vlt": "0000000.00"
},
"qos": 0,
"timestamp": 1605296451223,
"topic": "dualOutlet/topic/kWh"
},
{
"format": "json",
"payload": {
"timestamp": "1605296448",
"deviceId": "esp32DevKitCBoard01",
"rfidUid": "a5a5a5a5",
"outletId": "0",
"Vlt": "0000000.00"
},
"qos": 0,
"timestamp": 1605296455934,
"topic": "dualOutlet/topic/kWh"
},
{
"format": "json",
"payload": {
"timestamp": "1605296448",
"deviceId": "esp32DevKitCBoard01",
"rfidUid": "5a5a5a5a",
"outletId": "1",
"Vlt": "0000000.00"
},
"qos": 0,
"timestamp": 1605296456143,
"topic": "dualOutlet/topic/kWh"
}
],
"qos": 0,
"topicFilter": "dualOutlet/#"
}
The timestamp appended, which is part of the Publish payload message has the below values, corresponding to the 15 seconds interval -
"timestamp": "1605296433",
"timestamp": "1605296448",
Every 15 seconds, two MQTT messages are published. Further with the PUBLISH_RETRY_LIMIT set to 1, both these readings are sent again (retry) after which I receive the below message on the serial console.
MQTT PUBLISH 0 could not be sent. Error NO RESPONSE.
Analysing the serial console logs, I realize that the MQTT PUBLISH 0 successfully sent. message is missing, which corresponds to the _operationCompleteCallback() function not getting called.
Requesting assistance to resolve this issue.
PS. Running the firmware for few minutes with PUBLISH_RETRY_LIMIT = 10 along with other application threads results in firmware restart, which as per my analyses is due to the Heap memory deallocation not happening because of the above MQTT Publish error.
Thanks | Regards,
Dipen