search

aws / amazon-freertos

DEPRECATED - See README.md
https://aws.amazon.com/freertos/
MIT License
2.54k stars 1.1k forks source link

Guru Error when calling sendMessageToGGC() #3450

Closed SarahHamed closed 2 years ago

SarahHamed commented 2 years ago

Hello,

This is a follow-up to the issue #3440.

I get the following error Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled. When I call the function sendMessageToGGC(); in the greengrass Demo.

I call this function outside the function discoverGreengrassCore(). I provided the code in the aforementioned issue.

Please let me know if you can help with this.

aggarg commented 2 years ago

Would you please do the 2 things:

  1. Please share the complete log.
  2. Please share your code which shows the problem so that we can also try to repro. May be you can put it in your fork and share a link?

Thanks.

SarahHamed commented 2 years ago

Link to code gg-log.txt

Thank you.

aggarg commented 2 years ago

I tried your code and I was able to run it successfully:

6 451 [iot_thread] [aws_greengrass_discovery_demo.c:537] [INFO] [Greengrass_Discovery_Demo] Attempting automated selection of Greengrass device

E (5817) PKCS11: failed nvs get file size 4354 0
7 852 [iot_thread] JSON file retrieval completed

8 852 [iot_thread] About to close socket.

9 852 [iot_thread] Socket closed.

10 853 [iot_thread] Stack high watermark for discovery helper task: 5736.

13 853 [iot_thread] port 8883

E (9397) PKCS11: failed nvs get file size 4354 0
14 1281 [iot_thread] About to close socket.

15 1282 [iot_thread] Socket closed.

16 1282 [iot_thread] Stack high watermark for discovery helper task: 3048.

17 1282 [iot_thread] [aws_greengrass_discovery_demo.c:547] [INFO] [Greengrass_Discovery_Demo] Greengrass device discovered.

18 1282 [iot_thread] [aws_greengrass_discovery_demo.c:439] [INFO] [Greengrass_Discovery_Demo] Creating a TLS connection to *******************.

E (13657) PKCS11: failed nvs get file size 4354 0
19 1721 [iot_thread] [core_mqtt.c:886] [INFO] [MQTT] Packet received. ReceivedBytes=2.

20 1721 [iot_thread] [core_mqtt_serializer.c:970] [INFO] [MQTT] CONNACK session present bit not set.

21 1722 [iot_thread] [core_mqtt_serializer.c:912] [INFO] [MQTT] Connection accepted.

22 1722 [iot_thread] [core_mqtt.c:1563] [INFO] [MQTT] Received MQTT CONNACK successfully from broker.

23 1722 [iot_thread] [core_mqtt.c:1829] [INFO] [MQTT] MQTT connection established with the broker.

24 1722 [iot_thread] [aws_greengrass_discovery_demo.c:477] [INFO] [Greengrass_Discovery_Demo] An MQTT connection is established with ***************.

25 1722 [iot_thread] Heap low watermark: 84480. Stack high watermark: 3048.

26 1722 [iot_thread] [aws_greengrass_discovery_demo.c:602] [INFO] [Greengrass_Discovery_Demo] starting sendMessageToGGC()

27 1723 [iot_thread] [aws_greengrass_discovery_demo.c:517] [INFO] [Greengrass_Discovery_Demo] MQTT PUBLISH message sent successfully to the broker: Topic=freertos/demos/ggd

28 1873 [iot_thread] [aws_greengrass_discovery_demo.c:517] [INFO] [Greengrass_Discovery_Demo] MQTT PUBLISH message sent successfully to the broker: Topic=freertos/demos/ggd

29 2023 [iot_thread] [aws_greengrass_discovery_demo.c:517] [INFO] [Greengrass_Discovery_Demo] MQTT PUBLISH message sent successfully to the broker: Topic=freertos/demos/ggd

30 2173 [iot_thread] [INFO ][DEMO][21730] memory_metrics::freertos_heap::before::bytes::217896

31 2173 [iot_thread] [INFO ][DEMO][21730] memory_metrics::freertos_heap::after::bytes::84480

32 2173 [iot_thread] [INFO ][DEMO][21730] memory_metrics::demo_task_stack::before::bytes::8920

33 2173 [iot_thread] [INFO ][DEMO][21730] memory_metrics::demo_task_stack::after::bytes::3048

I (23397) wifi:state: run -> init (0)
I (23397) wifi:pm stop, total sleep time: 14783471 us / 18898568 us

I (23397) wifi:new:<11,0>, old:<11,0>, ap:<255,255>, sta:<11,0>, prof:1
I (23397) WIFI: WIFI_EVENT_STA_DISCONNECTED: 63
34 2273 [iot_thread] [INFO ][DEMO][22730] Demo completed successfully.

E (23407) wifi_init: Wi-Fi not stop
I (23417) WIFI: WIFI_EVENT_STA_STOP
I (23417) wifi:flush txq
I (23417) wifi:stop sw txq
I (23427) wifi:lmac stop hw txq
I (23427) wifi:Deinit lldesc rx mblock:10
GAP procedure initiated: stop advertising.
GAP procedure initiated: stop advertising.
35 2278 [iot_thread] [INFO ][INIT][22780] SDK cleanup done.

36 2278 [iot_thread] [INFO ][DEMO][22780] -------DEMO FINISHED-------

I used Ubuntu OS and ESP32 DevKitC platform. What is the difference in your platform? Can you try with a fresh git clone?

aggarg commented 2 years ago

Here is my command history:

gh repo clone git@github.com:SarahHamed/amazon-freertos.git
cd amazon-freertos/
git submodule update --init --recursive
vendors/espressif/esp-idf/install.sh
. vendors/espressif/esp-idf/export.sh
idf.py -DVENDOR=espressif -DBOARD=esp32_devkitc -DCOMPILER=xtensa-esp32 build
idf.py flash monitor
idf.py monitor
aggarg commented 2 years ago

Also, please apply this patch with additional logs and try again: additional_log.zip

SarahHamed commented 2 years ago

My apologies for the delay. Thank you for your help.

I tried to clone the fork and got no errors either. I get the error when I work with the version I downloaded from the console. Attached below.

It's strange because previously I got the guru cache disabled error when I cloned the repo from here https://github.com/aws/amazon-freertos directly or when I download it from here https://github.com/aws/amazon-freertos/releases/tag/202107.00

I applied the patch file but these two lines weren't printed: ggdconfigPRINT( "GG IP: %s\n", pxHostAddressData->pcHostAddress ); ggdconfigPRINT( "GG Port: %u\n", pxHostAddressData->usPort );

Connect_to_AWSGreengrass-_ESP32-DevKitC.zip https://drive.google.com/file/d/1l3PevzPRzeOzbBTC9ATFZaOIokxfEYBi/view?usp=drive_web

LOG:

2 38 [iot_thread] [INFO ][DEMO][380] ---------STARTING DEMO---------

I (1107) BTDM_INIT: BT controller compile version [a4c513b] 3 39 [iot_thread] [INFO ][INIT][390] SDK successfully initialized.

I (1107) system_api: Base MAC address is not set I (1117) system_api: read default base MAC address from EFUSE I (1127) phy_init: phy_version 4660,0162888,Dec 23 2020 GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=187 adv_itvl_max=375 I (1537) wifi:wifi driver task: 3ffd88f0, prio:23, stack:6656, core=0 I (1537) wifi:wifi firmware version: c44a5e7 I (1537) wifi:wifi certification version: v7.0 I (1537) wifi:config NVS flash: enabled I (1537) wifi:config nano formating: disabled I (1547) wifi:Init data frame dynamic rx buffer num: 32 I (1547) wifi:Init management frame dynamic rx buffer num: 32 I (1557) wifi:Init management short buffer num: 32 I (1557) wifi:Init dynamic tx buffer num: 32 I (1567) wifi:Init static rx buffer size: 1600 I (1567) wifi:Init static rx buffer num: 10 I (1567) wifi:Init dynamic rx buffer num: 32 I (1577) wifi_init: rx ba win: 6 I (1577) wifi_init: tcpip mbox: 32 I (1587) wifi_init: udp mbox: 6 I (1587) wifi_init: tcp mbox: 6 I (1587) wifi_init: tcp tx win: 5744 I (1597) wifi_init: tcp rx win: 5744 I (1597) wifi_init: tcp mss: 1440 I (1607) wifi_init: WiFi IRAM OP enabled I (1607) wifi_init: WiFi RX IRAM OP enabled I (1617) phy_init: phy_version 4660,0162888,Dec 23 2020 I (1627) wifi:mode : sta (30:ae:a4:f1:4c:f8) I (1627) WIFI: WIFI_EVENT_STA_START I (4077) wifi:new:<11,0>, old:<1,0>, ap:<255,255>, sta:<11,0>, prof:1 I (4627) wifi:state: init -> auth (b0) I (4647) wifi:state: auth -> assoc (0) I (4657) wifi:state: assoc -> run (10) I (4677) wifi:connected with Galaxy A71B900, aid = 25, channel 11, BW20, bssid = 4a:31:95:23:d0:bb I (4677) wifi:security: WPA2-PSK, phy: bgn, rssi: -52 I (4687) wifi:pm start, type: 1

I (4687) WIFI: WIFI_EVENT_STA_CONNECTED I (4687) wifi:AP's beacon interval = 102400 us, DTIM period = 2 I (5727) esp_netif_handlers: sta ip: 192.168.119.183, mask: 255.255.255.0, gw: 192.168.119.174 I (5727) WIFI: SYSTEM_EVENT_STA_GOT_IP 4 501 [sys_evt] [INFO ][DEMO][5010] Connected to WiFi access point, ip address: 255.255.255.0.

5 502 [iot_thread] [INFO ][DEMO][5020] Successfully initialized the demo. Network type for the demo: 1

6 502 [iot_thread] [aws_greengrass_discovery_demo.c:537] [INFO] [Greengrass_Discovery_Demo] Attempting automated selection of Greengrass device

E (6977) PKCS11: failed nvs get file size 4354 0 7 1086 [iot_thread] JSON file retrieval completed

8 1086 [iot_thread] About to close socket.

9 1087 [iot_thread] Socket closed.

10 1087 [iot_thread] Stack high watermark for discovery helper task: 5800.

E (12177) PKCS11: failed nvs get file size 4354 0 11 1590 [iot_thread] About to close socket.

12 1591 [iot_thread] Socket closed.

13 1591 [iot_thread] Stack high watermark for discovery helper task: 3192.

14 1591 [iot_thread] [aws_greengrass_discovery_demo.c:547] [INFO] [Greengrass_Discovery_Demo] Greengrass device discovered.

15 1591 [iot_thread] [aws_greengrass_discovery_demo.c:439] [INFO] [Greengrass_Discovery_Demo] Creating a TLS connection to 192.168.119.216:8883.

E (16987) PKCS11: failed nvs get file size 4354 0 Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled.

Core 0 register dump: PC : 0x400da221 PS : 0x00060430 A0 : 0x800d8126 A1 : 0x3ffb4780
0x400da221: SecureSocketsTransport_Send at /home/sarah/Desktop/send_msg/Connect_to_AWSGreengrass-_ESP32-DevKitC/FreeRTOS/build/../libraries/abstractions/transport/secure_sockets/transport_secure_sockets.c:131

A2 : 0x3ffb4a34 A3 : 0x3ffc472c A4 : 0x00000016 A5 : 0x3ffc4704
A6 : 0x00000000 A7 : 0x00000038 A8 : 0x00000014 A9 : 0x00000000
A10 : 0x00000000 A11 : 0x3f401b9c A12 : 0x00000038 A13 : 0x3f4076e8
A14 : 0x00000040 A15 : 0x0fffffe9 SAR : 0x00000004 EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000014 LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0x00000000

Backtrace:0x400da21e:0x3ffb4780 0x400d8123:0x3ffb47b0 0x400d84f4:0x3ffb47e0 0x400d8aa1:0x3ffb4800 0x400d4e74:0x3ffb4830 0x400d4ecc:0x3ffb4a60 0x400d49d6:0x3ffb4a80 0x400dcee5:0x3ffb4ab0 0x4008fc95:0x3ffb4ad0 0x400da21e: SecureSocketsTransport_Send at /home/sarah/Desktop/send_msg/Connect_to_AWSGreengrass-_ESP32-DevKitC/FreeRTOS/build/../libraries/abstractions/transport/secure_sockets/transport_secure_sockets.c:129

0x400d8123: sendPacket at /home/sarah/Desktop/send_msg/Connect_to_AWSGreengrass-_ESP32-DevKitC/FreeRTOS/build/../libraries/coreMQTT/source/core_mqtt.c:619

0x400d84f4: sendPublish at /home/sarah/Desktop/send_msg/Connect_to_AWSGreengrass-_ESP32-DevKitC/FreeRTOS/build/../libraries/coreMQTT/source/core_mqtt.c:1408

0x400d8aa1: MQTT_Publish at /home/sarah/Desktop/send_msg/Connect_to_AWSGreengrass-_ESP32-DevKitC/FreeRTOS/build/../libraries/coreMQTT/source/core_mqtt.c:1945

0x400d4e74: sendMessageToGGC at /home/sarah/Desktop/send_msg/Connect_to_AWSGreengrass-_ESP32-DevKitC/FreeRTOS/build/../demos/greengrass_connectivity/aws_greengrass_discovery_demo.c:508

0x400d4ecc: vStartGreenGrassDiscoveryTask at /home/sarah/Desktop/send_msg/Connect_to_AWSGreengrass-_ESP32-DevKitC/FreeRTOS/build/../demos/greengrass_connectivity/aws_greengrass_discovery_demo.c:604

0x400d49d6: runDemoTask at /home/sarah/Desktop/send_msg/Connect_to_AWSGreengrass-_ESP32-DevKitC/FreeRTOS/build/../demos/demo_runner/iot_demo_freertos.c:313

0x400dcee5: _threadRoutineWrapper at /home/sarah/Desktop/send_msg/Connect_to_AWSGreengrass-_ESP32-DevKitC/FreeRTOS/build/../libraries/abstractions/platform/freertos/iot_threads_freertos.c:85

0x4008fc95: vPortTaskWrapper at /home/sarah/Desktop/send_msg/Connect_to_AWSGreengrass-_ESP32-DevKitC/FreeRTOS/build/../freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/port.c:154

ELF file SHA256: 0024499154854a8c

Rebooting... ets Jun 8 2016 00:22:57

aggarg commented 2 years ago

I tried to clone the fork and got no errors either.

Great!

I applied the patch file but these two lines weren't printed: ggdconfigPRINT( "GG IP: %s\n", pxHostAddressData->pcHostAddress ); ggdconfigPRINT( "GG Port: %u\n", pxHostAddressData->usPort );

This is strange. While I try your bundle, can you add a log to dump the retrieved JSON file: https://github.com/aws/amazon-freertos/blob/main/libraries/freertos_plus/aws/greengrass/src/aws_greengrass_discovery.c#L460

ggdconfigPRINT( "JSON: %s\n", pcBuffer );

Thanks.

aggarg commented 2 years ago

I do not have access to the Google Drive link you shared but I tried the 202107.00 tag and it works. Here is my command history:

git clone git@github.com:aws/amazon-freertos.git
cd amazon-freertos/
git checkout tags/202107.00
git submodule update --init --recursive 
vendors/espressif/esp-idf/install.sh
. vendors/espressif/esp-idf/export.sh
idf.py -DVENDOR=espressif -DBOARD=esp32_devkitc -DCOMPILER=xtensa-esp32 build
idf.py flash monitor

Here is the output:

I (5102) WIFI: WIFI_EVENT_STA_CONNECTED
I (5172) wifi:AP's beacon interval = 102400 us, DTIM period = 2
I (5732) esp_netif_handlers: sta ip: 192.168.154.193, mask: 255.255.255.0, gw: 192.168.154.34
I (5732) WIFI: SYSTEM_EVENT_STA_GOT_IP
5 500 [sys_evt] [INFO ][DEMO][5000] Connected to WiFi access point, ip address: 255.255.255.0.

6 500 [iot_thread] [INFO ][DEMO][5000] Successfully initialized the demo. Network type for the demo: 1

7 500 [iot_thread] [aws_greengrass_discovery_demo.c:541] [INFO] [Greengrass_Discovery_Demo] Attempting automated selection of Greengrass device

8 503 [NetworkManager] [INFO ][DEMO][5030] Invoked callback for network state change event.

9 505 [NetworkManager] [INFO ][DEMO][5050] Invoked callback for network state change event.

GAP procedure initiated: stop advertising.
GAP procedure initiated: stop advertising.
E (6612) PKCS11: failed nvs get file size 4354 0
10 916 [iot_thread] JSON file retrieval completed

11 916 [iot_thread] About to close socket.

12 917 [iot_thread] Socket closed.

13 917 [iot_thread] Stack high watermark for discovery helper task: 5576.

15 917 [iot_thread] GG IP: **************

16 917 [iot_thread] GG Port: 8883

E (10262) PKCS11: failed nvs get file size 4354 0
17 1387 [iot_thread] About to close socket.

18 1388 [iot_thread] Socket closed.

19 1388 [iot_thread] Stack high watermark for discovery helper task: 3080.

20 1388 [iot_thread] [aws_greengrass_discovery_demo.c:551] [INFO] [Greengrass_Discovery_Demo] Greengrass device discovered.

21 1388 [iot_thread] [aws_greengrass_discovery_demo.c:440] [INFO] [Greengrass_Discovery_Demo] Creating a TLS connection to ******************.

E (14872) PKCS11: failed nvs get file size 4354 0
22 1858 [iot_thread] [core_mqtt.c:886] [INFO] [MQTT] Packet received. ReceivedBytes=2.

23 1858 [iot_thread] [core_mqtt_serializer.c:970] [INFO] [MQTT] CONNACK session present bit not set.

24 1858 [iot_thread] [core_mqtt_serializer.c:912] [INFO] [MQTT] Connection accepted.

25 1858 [iot_thread] [core_mqtt.c:1563] [INFO] [MQTT] Received MQTT CONNACK successfully from broker.

26 1858 [iot_thread] [core_mqtt.c:1829] [INFO] [MQTT] MQTT connection established with the broker.

27 1858 [iot_thread] [aws_greengrass_discovery_demo.c:478] [INFO] [Greengrass_Discovery_Demo] An MQTT connection is established with ******************.

28 1859 [iot_thread] [aws_greengrass_discovery_demo.c:520] [INFO] [Greengrass_Discovery_Demo] MQTT PUBLISH message sent successfully to the broker: Topic=freertos/demos/ggd

29 2009 [iot_thread] [aws_greengrass_discovery_demo.c:520] [INFO] [Greengrass_Discovery_Demo] MQTT PUBLISH message sent successfully to the broker: Topic=freertos/demos/ggd

30 2159 [iot_thread] [aws_greengrass_discovery_demo.c:520] [INFO] [Greengrass_Discovery_Demo] MQTT PUBLISH message sent successfully to the broker: Topic=freertos/demos/ggd

31 2309 [iot_thread] [aws_greengrass_discovery_demo.c:575] [INFO] [Greengrass_Discovery_Demo] Disconnecting from broker.

32 2309 [iot_thread] [core_mqtt.c:2149] [INFO] [MQTT] Disconnected from the broker.

33 2310 [iot_thread] [aws_greengrass_discovery_demo.c:597] [INFO] [Greengrass_Discovery_Demo] Disconnected from the broker.

34 2310 [iot_thread] Heap low watermark: 116896. Stack high watermark: 3080.

35 2310 [iot_thread] [INFO ][DEMO][23100] memory_metrics::freertos_heap::before::bytes::217836

36 2310 [iot_thread] [INFO ][DEMO][23100] memory_metrics::freertos_heap::after::bytes::116896

37 2310 [iot_thread] [INFO ][DEMO][23100] memory_metrics::demo_task_stack::before::bytes::8920

38 2310 [iot_thread] [INFO ][DEMO][23100] memory_metrics::demo_task_stack::after::bytes::3080

I (24832) wifi:state: run -> init (0)
I (24832) wifi:pm stop, total sleep time: 15697466 us / 19734676 us

I (24832) wifi:new:<8,0>, old:<8,0>, ap:<255,255>, sta:<8,0>, prof:1
I (24832) WIFI: WIFI_EVENT_STA_DISCONNECTED: 63
39 2410 [iot_thread] [INFO ][DEMO][24100] Demo completed successfully.

E (24842) wifi_init: Wi-Fi not stop
I (24852) WIFI: WIFI_EVENT_STA_STOP
I (24852) wifi:flush txq
I (24852) wifi:stop sw txq
I (24862) wifi:lmac stop hw txq
I (24862) wifi:Deinit lldesc rx mblock:10
40 2414 [iot_thread] [INFO ][INIT][24140] SDK cleanup done.

41 2414 [iot_thread] [INFO ][DEMO][24140] -------DEMO FINISHED-------

Can you also try the same commands?

Thanks.

aggarg commented 2 years ago

I applied the patch file but these two lines weren't printed: ggdconfigPRINT( "GG IP: %s\n", pxHostAddressData->pcHostAddress ); ggdconfigPRINT( "GG Port: %u\n", pxHostAddressData->usPort );

A possibility is that what are you editing and what you are compiling are different. A quick way to confirm is to put some non-compilable code and verify that the compilation fails.

SarahHamed commented 2 years ago

I tried the same commands and printed the additional logs. gg-log3.txt

My apologies, I adjusted the access to the link. amazon-freertos

Thank you.

SarahHamed commented 2 years ago

Note, I tried the same commands on the project I attached its link but not the repo "github.com:aws/amazon-freertos.git"

. vendors/espressif/esp-idf/export.sh
idf.py -DVENDOR=espressif -DBOARD=esp32_devkitc -DCOMPILER=xtensa-esp32 build
idf.py flash monitor
aggarg commented 2 years ago

but not the repo "github.com:aws/amazon-freertos.git".

Would you please try that.

SarahHamed commented 2 years ago

I tried to run this command but I don't have a public ssh key so it failed.

I used the HTTPS method instead. All the commands that I used in the terminal:


git init
git clone git@github.com:aws/amazon-freertos.git (failed)
git clone https://github.com/aws/amazon-freertos.git --recurse-submodules
cd amazon-freertos/
git checkout tags/202107.00
git submodule update --init --recursive
vendors/espressif/esp-idf/install.sh
. vendors/espressif/esp-idf/export.sh

I switched the file "aws_greengrass_discovery_demo.c" to the new one that I am trying, then I built it.

idf.py -DVENDOR=espressif -DBOARD=esp32_devkitc -DCOMPILER=xtensa-esp32 build
idf.py flash  monitor

Unfortunately, I got the guru error again. log-gg.txt

aggarg commented 2 years ago

I am finally able to repro the issue. The root cause is that the address of xNetworkContext variable is stored in the MQTT context which in-turn stores the address of secureSocketsTransportParams. Both of these variables are local to the function discoverGreengrassCore and therefore, go out-of-scope as soon as the function returns. Later when these are accessed in MQTT_Publish call in sendMessageToGGC, these result in invalid memory access leading to LoadStoreError panic. The solution is simple - declare secureSocketsTransportParams and xNetworkContext as file global just as you have declared xMQTTContext.

Thanks.

SarahHamed commented 2 years ago

Thank you so much for your help. I tried it and it's working.

I am gonna close it now.

Thank you.