search

aws / amazon-freertos

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

Greengrass demo on ESP32 returns eMQTTClientGotDisconnected #143

Closed fast4break closed 5 years ago

fast4break commented 5 years ago

Run AWS FreeRTOS on a esp32 board, the greengrass demo can not pass.
----Log: 44 2468 [IoT_GGD] MQTT Agent Publishing Message start. 47 2468 [IoT_GGD] Sending command Event Type = 5 51 2471 [IoT_GGD] Woken by a notification message 56 2471 [IoT_GGD] mqttNOTIFICATION_CODE == 34 (eMQTTClientGotDisconnected) 57 2471 [IoT_GGD] MQTT_AGENT_Publish command returns failure.

59 3621 [IoT_GGD] MQTT Agent Publishing Message start. 62 3621 [IoT_GGD] Sending command Event Type = 5 66 3623 [IoT_GGD] Woken by a notification message 71 3623 [IoT_GGD] mqttNOTIFICATION_CODE == 12 (eMQTTPUBCouldNotBeSent) 72 3623 [IoT_GGD] MQTT_AGENT_Publish command returns failure.

74 4773 [IoT_GGD] MQTT Agent Publishing Message start. 77 4773 [IoT_GGD] Sending command Event Type = 5 81 4775 [IoT_GGD] Woken by a notification message 86 4775 [IoT_GGD] mqttNOTIFICATION_CODE == 12(eMQTTPUBCouldNotBeSent) 87 4775 [IoT_GGD] MQTT_AGENT_Publish command returns failure. 119 8229 [IoT_GGD] Disconnecting from broker...... 122 8229 [IoT_GGD] Sending command Event Type = 2 126 8231 [IoT_GGD] Woken by a notification message 131 8231 [IoT_GGD] mqttNOTIFICATION_CODE == 8(eMQTTDISCONNSent) 132 8231 [IoT_GGD] Disconnected from the broker. 133 8231 [IoT_GGD] Deleted Client. 134 8231 [IoT_GGD] Heap low watermark: 95892. Stack high watermark: 216. 135 8231 [IoT_GGD] ----Demo finished----

While sending MQTT message, function xQueueSendToBack returns pdTrue, but notification message recieved from queue shows there is a problem on MQTT connection. Thanks.

gordonwang0 commented 5 years ago

Hi @fast4break,

Apologies for the delayed response. I have seen something similar if the GG core crashes (i.e. it can be discovered but connection fails). Can you ensure that your GG core is running?

fast4break commented 5 years ago

GG core is running since I can recieve messages from HelloWorld_Publisher(Module 4 of DG). And ESP32 board can get correct IP address of the GG core whenever I change the GG core address(I tried different subnetworks). Not sure if GG core's CA is the problem, I just assume the example code will do things right. Can figure out what I am missing here.

gordonwang0 commented 5 years ago

Can you also check that you have configured your GG subscriptions and AWS IoT policy?

Are you able to connect to this GG core using another client?

fast4break commented 5 years ago

test1: IoT Cloud<------>GG core on Pi<------->publisher/subscriber on laptop =>Pub and sub can talk with each other through GG core

test2: IoT Cloud<------>esp32 =>esp32 can send and recieve echo message to IoT Cloud

test3: IoT Cloud<------>GG core on Pi<------->esp32 =>esp32 can find the correct IP address, but always recieve MQTT Disconnect error code(34) then error code 12 after invoking function prvSendCommandToMQTTTask.

GG Subscribption: esp32-wrover -----------------> Local Shadow Service Local Shadow Service -------------------> IoT Cloud

Policy for esp32: { "Effect": "Allow", "Action": "iot:Connect", "Resource": "arn:aws:iot:us-east-1:xxxxxxxx:" }, { "Effect": "Allow", "Action": "iot:Publish", "Resource": "arn:aws:iot:us-east-1:xxxxxxxx:" }, { "Effect": "Allow", "Action": "iot:Subscribe", "Resource": "arn:aws:iot:us-east-1:xxxxxxxx:" }, { "Effect": "Allow", "Action": "iot:Receive", "Resource": "arn:aws:iot:us-east-1:xxxxxxxx:" }, { "Effect": "Allow", "Action": "greengrass:", "Resource": "arn:aws:iot:us-east-1:xxxxxxxx:" }

sarenameas commented 5 years ago

Hello fast4break,

  1. To re-iterate what gordonwang0 said, please make sure that the Greengrass core has not crashed. Inside of the {...}/greengrass folder on my core, I know it has crashed when I find a non-empty "crash.log". Just to make sure we can go ahead and restart the core: 
    
[ec2-user@ip-XXX-XXX-XXX-XXX greengrass]$ sudo ./greengrassd restart
Stopping greengrass daemon of PID: 14508
Waiting........
Stopped greengrass daemon, exiting with success
Setting up greengrass daemon
Validating execution environment
Found cgroup subsystem: cpuset
Found cgroup subsystem: cpu
Found cgroup subsystem: cpuacct
Found cgroup subsystem: blkio
Found cgroup subsystem: memory
Found cgroup subsystem: devices
Found cgroup subsystem: freezer
Found cgroup subsystem: net_cls
Found cgroup subsystem: perf_event
Found cgroup subsystem: net_prio
Found cgroup subsystem: hugetlb
Found cgroup subsystem: pids

Starting greengrass daemon..... Greengrass daemon started with PID: 3503 [ec2-user@ip-XXX-XXX-XXX-XXX greengrass]$ ps -a PID TTY TIME CMD 3503 pts/0 00:00:00 daemon 3598 pts/0 00:00:00 ps


2. In {...}/greengrass/configuration/config.json verify the contents are the expected certificate and iotHost to connect to the AWS IoT core:

[ec2-user@ip-XXX-XXX-XXX-XXX greengrass]$ cd configuration/ [ec2-user@ip-XXX-XXX-XXX-XXX configuration]$ ls certs config.json group [ec2-user@ip-1XXX-XXX-XXX-XXX configuration]$ cat config.json { "coreThing": { "caPath": "root-certificate.pem", "certPath": "XXXX-certificate.pem.crt.txt", "keyPath": "XXXX-private.pem.key", "thingArn": "Greengrass core ARN", "iotHost": "YOUR AWS IoT Core endpoint", "ggHost": "greengrass.iot.us-west-2.amazonaws.com" }, "runtime": { "cgroup": { "useSystemd": "yes" } } }


2. In your Greengrass group in AWS IoT core please verify: 
- That your device is added to the list of devices
![capture](https://user-images.githubusercontent.com/6563840/50366501-e29bb300-052e-11e9-8a65-6bee3cd963c8.JPG)
- That you have allowed subscriptions to either all topics (#) or the "freertos/demos/echo" topic. I have subscribed to all topics.
![image](https://user-images.githubusercontent.com/6563840/50366591-6ce41700-052f-11e9-889c-ac47805a213c.png)

3. Make sure your have the proper permissions on resources in your thing's certificate's policy:
```json
{
    "Version": "2012-10-17",
    "Statement": [
    {
        "Effect": "Allow",
        "Action": "iot:Connect",
        "Resource":"arn:aws:iot:<aws-region>:<aws-account-id>:*"
    }, 
    {
        "Effect": "Allow",
        "Action": "iot:Publish",
        "Resource": "arn:aws:iot:<aws-region>:<aws-account-id>:*"
    },
    {
         "Effect": "Allow",
         "Action": "iot:Subscribe",
         "Resource": "arn:aws:iot:<aws-region>>:<aws-account-id>:*"
    },
    {
         "Effect": "Allow",
         "Action": "iot:Receive",
         "Resource": "arn:aws:iot:<aws-region>:<aws-account-id>:*"
    },
    {
         "Effect": "Allow",
         "Action": "greengrass:*",
         "Resource": "arn:aws:iot:<aws-region>:<aws-account-id>:*"
    }
    ]
}
  1. On ESP32, if you have run previous code with different certificates or the OTA demo, sometimes the MQTT fails to connect. Please try running "make erase_flash" before "make flash monitor".

The only files I have update for the Greengrass demo using the latest code in amazon-freertos are aws_demo_runner.c, aws_clientcredential.h, aws_clientcredential_keys.h, and sdkconfig (for serial port only). Here is a successful demo output:

sarem@DOMAIN MINGW32 /c/amazon-freertos/demos/espressif/esp32_devkitc_esp_wrover_kit/make
$ make flash monitor
Flashing binaries to serial port COM31 (app at offset 0x20000)...
esptool.py v2.2.1
Connecting....
Chip is ESP32D0WDQ5 (revision 0)
Uploading stub...
Running stub...
Stub running...
Configuring flash size...
Auto-detected Flash size: 4MB
Flash params set to 0x0220
Compressed 21872 bytes to 13022...
Wrote 21872 bytes (13022 compressed) at 0x00001000 in 1.1 seconds (effective 152.5 kbit/s)...
Hash of data verified.
Compressed 598384 bytes to 379635...
Wrote 598384 bytes (379635 compressed) at 0x00020000 in 33.6 seconds (effective 142.6 kbit/s)...
Hash of data verified.
Compressed 3072 bytes to 119...
Wrote 3072 bytes (119 compressed) at 0x00008000 in 0.0 seconds (effective 1361.7 kbit/s)...
Hash of data verified.

Leaving...
Hard resetting...
MONITOR
--- idf_monitor on COM31 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:5988
load:0x40078000,len:0
load:0x40078000,len:15784
entry 0x400792e8
I (28) boot: ESP-IDF v3.1-dev-322-gf307f41-dirty 2nd stage bootloader
I (28) boot: compile time 13:47:58
I (29) boot: Enabling RNG early entropy source...
I (35) boot: SPI Speed      : 40MHz
I (39) boot: SPI Mode       : DIO
I (43) boot: SPI Flash Size : 4MB
I (47) boot: Partition Table:
I (50) boot: ## Label            Usage          Type ST Offset   Length
I (58) boot:  0 nvs              WiFi data        01 02 00010000 00006000
I (65) boot:  1 otadata          OTA data         01 00 00016000 00002000
I (73) boot:  2 phy_init         RF data          01 01 00018000 00001000
I (80) boot:  3 ota_0            OTA app          00 10 00020000 00100000
I (88) boot:  4 ota_1            OTA app          00 11 00120000 00100000
I (95) boot:  5 storage          Unknown data     01 82 00220000 00010000
I (103) boot: End of partition table
I (107) esp_image: segment 0: paddr=0x00020020 vaddr=0x3f400020 size=0x12b00 ( 76544) map
I (142) esp_image: segment 1: paddr=0x00032b28 vaddr=0x3ffb0000 size=0x023f0 (  9200) load
I (146) esp_image: segment 2: paddr=0x00034f20 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _iram_start at C:/b/amazon-freertos/lib/FreeRTOS/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1
685

I (150) esp_image: segment 3: paddr=0x00035328 vaddr=0x40080400 size=0x0ace8 ( 44264) load
I (176) esp_image: segment 4: paddr=0x00040018 vaddr=0x400d0018 size=0x6f360 (455520) map
0x400d0018: _stext at ??:?

I (335) esp_image: segment 5: paddr=0x000af380 vaddr=0x4008b0e8 size=0x02dc4 ( 11716) load
0x4008b0e8: xEventGroupWaitBits at C:/b/amazon-freertos/lib/FreeRTOS/event_groups.c:644

I (340) esp_image: segment 6: paddr=0x000b214c vaddr=0x400c0000 size=0x00000 (     0) load
I (350) boot: Loaded app from partition at offset 0x20000
I (350) boot: ota rollback check done
I (352) boot: Disabling RNG early entropy source...
I (358) cpu_start: Pro cpu up.
I (361) cpu_start: Single core mode
I (366) heap_init: Initializing. RAM available for dynamic allocation:
I (372) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (379) heap_init: At 3FFC1138 len 0001EEC8 (123 KiB): DRAM
I (385) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (391) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (398) heap_init: At 4008DEAC len 00012154 (72 KiB): IRAM
I (404) cpu_start: Pro cpu start user code
I (86) cpu_start: Starting scheduler on PRO CPU.
I (110) wifi: wifi firmware version: f79168c
I (110) wifi: config NVS flash: enabled
I (110) wifi: config nano formating: disabled
I (110) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (120) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (130) wifi: Init dynamic tx buffer num: 32
I (140) wifi: Init data frame dynamic rx buffer num: 32
I (140) wifi: Init management frame dynamic rx buffer num: 32
I (140) wifi: wifi driver task: 3ffc7dec, prio:23, stack:4096
I (150) wifi: Init static rx buffer num: 10
I (150) wifi: Init dynamic rx buffer num: 32
I (160) wifi: wifi power manager task: 0x3ffcca2c prio: 21 stack: 2560
0 6 [main] WiFi module initialized. Connecting to AP Mobile...
I (230) phy: phy_version: 383.0, 79a622c, Jan 30 2018, 15:38:06, 0, 0
I (230) wifi: mode : sta (30:ae:a4:80:21:08)
I (230) WIFI: SYSTEM_EVENT_STA_START
I (360) wifi: n:1 0, o:1 0, ap:255 255, sta:1 0, prof:1
I (1340) wifi: state: init -> auth (b0)
I (1350) wifi: state: auth -> assoc (0)
I (1350) wifi: state: assoc -> run (10)
I (1360) wifi: connected with Mobile, channel 1
I (1360) WIFI: SYSTEM_EVENT_STA_CONNECTED
1 401 [IP-task] vDHCPProcess: offer c0a83683ip
I (4120) event: sta ip: 192.168.54.131, mask: 255.255.224.0, gw: 192.168.32.1
I (4120) WIFI: SYSTEM_EVENT_STA_GOT_IP
2 402 [IP-task] vDHCPProcess: offer c0a83683ip
3 402 [main] WiFi Connected to AP. Creating tasks which use network...
4 403 [main] Write code signing certificate...
I (4140) PKCS11: Initializing SPIFFS
I (4140) PKCS11: Partition size: total: 52961, used: 2761
5 406 [main] Write device private key...
I (4260) PKCS11: Initializing SPIFFS
6 418 [main] Key provisioning done...
7 418 [IoT_GGD] Attempting automated selection of Greengrass device
I (4350) wifi: pm start, type:0

I (9310) PKCS11: Initializing SPIFFS
I (9310) PKCS11: Initializing SPIFFS
I (9410) PKCS11: Initializing SPIFFS
I (9410) PKCS11: Initializing SPIFFS
I (9420) PKCS11: Initializing SPIFFS
I (12600) PKCS11: Initializing SPIFFS
8 1988 [IoT_GGD] About to close socket.
9 2489 [IoT_GGD] Socket closed.
10 2489 [IoT_GGD] Stack high watermark for discovery helper task: 2740.
I (25110) PKCS11: Initializing SPIFFS
I (25120) PKCS11: Initializing SPIFFS
I (25220) PKCS11: Initializing SPIFFS
I (25220) PKCS11: Initializing SPIFFS
I (25220) PKCS11: Initializing SPIFFS
I (25960) PKCS11: Initializing SPIFFS
11 2760 [IoT_GGD] About to close socket.
12 2762 [IoT_GGD] Socket closed.
13 2762 [IoT_GGD] Stack high watermark for discovery helper task: 116.
14 2762 [IoT_GGD] Greengrass device discovered.
15 2762 [IoT_GGD] Establishing MQTT communication to Greengrass...
I (27750) PKCS11: Initializing SPIFFS
I (27750) PKCS11: Initializing SPIFFS
I (27860) PKCS11: Initializing SPIFFS
I (27860) PKCS11: Initializing SPIFFS
I (27860) PKCS11: Initializing SPIFFS
I (28660) PKCS11: Initializing SPIFFS
16 3484 [IoT_GGD] Disconnecting from broker.
17 3486 [IoT_GGD] Disconnected from the broker.
18 3486 [IoT_GGD] Deleted Client.
19 3486 [IoT_GGD] Heap low watermark: 109640. Stack high watermark: 116.
20 3486 [IoT_GGD] ----Demo finished----