m5stack / Core2-for-AWS-IoT-Kit

Accompanying code for use with AWS IoT Kit content. Works with PlatformIO and ESP-IDF v4.2.
https://m5stack.com/collections/m5-core/products/m5stack-core2-esp32-iot-development-kit-for-aws-iot-edukit
MIT License
127 stars 66 forks source link

Intro to Alexa fot IoT #39

Closed shurillu closed 3 years ago

shurillu commented 3 years ago

Hello,

I'm trying to run the example for Alexa, but I'm stuck in the Amazon authentication phase. Here the detail:

  1. Flash the certificates stage: all seems to go fine (I got the certificates by email, I modified the CSV file, I generated the mfg.bin file and I loaded the certificate into my Core2)
  2. Flash the firmware stage: all seems to go fine. The Core2 boots, side leds blinks red, the display shows "ALEXA APP" and the slider to set the screen brightness.
  3. Smartphone Espressif "ESP Alexa" App stage: I downloaded the Alexa App for iPhone (iOS ver 14.3). Running the app, I tap on "Add New Device" button and the pone found my Core2 as "ESP-Alexa-A7FC". Tapping on it, the app show the "Proof of Possession" code (abcd1234), tapping on "Done" button the app show an "amazon alexa" message and ask for signing in with Amazon.
  4. When I tap on that button (sign in with Amazon) in the serial log I see these messages:
    
    I (732594) [avs_config]: Received request for device details
    I (732594) [avs_config]: code_verifier - abcd1234, code_challenge - 6c7nGrky_ehjM40Ivk3p3-OeoEm9r7NCzmWexUULaa4
    I (732594) [avs_config]: version: 1, DSN: b8f009c4a7fc, ProductID: Core2ForAWS
My phone shows this:
![IMG_E5804](https://user-images.githubusercontent.com/34068748/104809474-c4780e00-57ed-11eb-9d81-fa6e22d79831.JPG)

The italian message says something like that: _We apologies. An error has occurred while we are trying to manage your request._

At this point I can't do anything else.

If I skip the Amazon sign in phase, I can set the WiFi credentials but without an account, the Core2 can't login with Amazon: the Core 2 side leds are blue pulsing cyan.  This is the serial log output

W (1702644) wifi:Error! Should use default active scan time parameter for WiFi scan when Bluetooth is enabled!!!!!!

I (1725394) [app_prov]: Received Wi-Fi credentials: SSID: mySSID Password: myPASSWORD I (1727844) wifi:new:<6,0>, old:<1,0>, ap:<255,255>, sta:<6,0>, prof:1 I (1728544) wifi:state: init -> auth (b0) I (1728554) wifi:state: auth -> assoc (0) I (1728554) wifi:state: assoc -> run (10) I (1728594) wifi:connected with mySSID, aid = 19, channel 6, BW20, bssid = 00:1c:82:05:2c:58 I (1728604) wifi:security: WPA2-PSK, phy: bgn, rssi: -34 I (1728604) wifi:pm start, type: 1

I (1728714) wifi:AP's beacon interval = 102400 us, DTIM period = 1 [app_wifi]: Connected with IP Address: 192.168.1.65 I (1729454) esp_netif_handlers: sta ip: 192.168.1.65, mask: 255.255.255.0, gw: 192.168.1.1 I (1729454) wifi_prov_mgr: STA Got IP I (1729454) [app_prov]: Provisioning successful I (1732724) wifi_prov_mgr: Provisioning stopped I (1732724) [app_prov]: Provisioning stopped I (1732724) wifi_prov_scheme_ble: BTDM memory released I (1732734) [va_nvs_utils]: No value set for: friendlyname I (1732734) [va_nvs_utils]: No value set for: udn I (1732744) SSDP: Network Interface List (1): [alexa]: Waiting for time to be updated I (1732744) SSDP: 1. wifi : 192.168.1.65 I (1732764) LSSDP: create SSDP socket 58 [alexa]: Done getting current time: 1610793030 I (1734064) [tls_certification]: Done setting global CA store I (1734064) [va_nvs_utils]: No value set for: clientId I (1734064) [va_nvs_utils]: No value set for: refreshToken I (1734074) [alexa]: Checking for companion app based authentication...

[alexa]: Waiting for authentication tokens. [alexa]: Waiting for authentication tokens. [alexa]: Waiting for authentication tokens. [alexa]: Waiting for authentication tokens. [alexa]: Waiting for authentication tokens. [alexa]: Waiting for authentication tokens. [alexa]: Waiting for authentication tokens. [alexa]: Waiting for authentication tokens. [alexa]: Waiting for authentication tokens.


The last message is repeated.

Any clues?

Thanks, 

Stefano
nishit-jain-esp commented 3 years ago

@shurillu : Have you by any chance modified the Product ID to Core2ForAWS, since thats what is showing in the log. Can you please confirm if in the file Core2-for-AWS-IoT-EduKit/Alexa_for_IoT-Intro/main/Kconfig.projbuild the value for ALEXA_PRODUCT_ID is set to esp_alexa_open

shurillu commented 3 years ago

Hello nishit-jain-esp thank you for your response. I can confirm that I used the source code downloaded yesterday from github, master branch. I checked the Kconfig.projbuild and the ALEXA_PRODUCT_ID is set to esp_alexa_open. Here the snipped extracted from the Kconfig.projbuild file:

config ALEXA_PRODUCT_ID
    string "Device Product ID"
    default "esp_alexa_open"
    help
        Product ID that will be used by the device to connect with AVS.

Hoping that could be useful to find the issue, Here the full log from the boot to the moment when the Amazon logging stage abort.

ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x17 (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:1
load:0x3fff0030,len:4
load:0x3fff0034,len:7488
ho 0 tail 12 room 4
load:0x40078000,len:14368
load:0x40080400,len:5360
entry 0x40080710
I (31) boot: ESP-IDF v4.2-218-g8911c2912 2nd stage bootloader
I (31) boot: compile time 18:10:02
I (31) boot: chip revision: 3
I (35) boot_comm: chip revision: 3, min. bootloader chip revision: 0
I (42) qio_mode: Enabling default flash chip QIO
I (47) boot.esp32: SPI Speed      : 80MHz
I (52) boot.esp32: SPI Mode       : QIO
I (57) boot.esp32: SPI Flash Size : 16MB
I (61) boot: Enabling RNG early entropy source...
I (67) boot: Partition Table:
I (70) boot: ## Label            Usage          Type ST Offset   Length
I (77) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (85) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (92) boot:  2 fctry_aia        WiFi data        01 02 00010000 00006000
I (100) boot:  3 fctry            WiFi data        01 02 00016000 00006000
I (107) boot:  4 otadata          OTA data         01 00 0001c000 00002000
I (115) boot:  5 ota_0            OTA app          00 10 00020000 003f0000
I (123) boot:  6 ota_1            OTA app          00 11 00410000 003f0000
I (130) boot: End of partition table
I (134) boot_comm: chip revision: 3, min. application chip revision: 0
I (142) esp_image: segment 0: paddr=0x00020020 vaddr=0x3f400020 size=0x1afe1c (1768988) map
I (736) esp_image: segment 1: paddr=0x001cfe44 vaddr=0x3ffbdb60 size=0x001d4 (   468) load
I (736) esp_image: segment 2: paddr=0x001d0020 vaddr=0x400d0020 size=0x13e994 (1304980) map
I (1174) esp_image: segment 3: paddr=0x0030e9bc vaddr=0x3ffbdd34 size=0x0493c ( 18748) load
I (1182) esp_image: segment 4: paddr=0x00313300 vaddr=0x40080000 size=0x00404 (  1028) load
I (1182) esp_image: segment 5: paddr=0x0031370c vaddr=0x40080404 size=0x1da9c (121500) load
I (1255) boot: Loaded app from partition at offset 0x20000
I (1255) boot: Disabling RNG early entropy source...
I (1256) psram: This chip is ESP32-D0WD
I (1260) spiram: Found 64MBit SPI RAM device
I (1265) spiram: SPI RAM mode: flash 80m sram 80m
I (1270) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (1278) cpu_start: Pro cpu up.
I (1281) cpu_start: Application information:
I (1286) cpu_start: Project name:     AWS_IoT_EduKit-Intro_to_Alexa
I (1293) cpu_start: App version:      1
I (1298) cpu_start: Compile time:     Jan 15 2021 18:09:38
I (1304) cpu_start: ELF file SHA256:  8f09fec98a3c2837...
I (1310) cpu_start: ESP-IDF:          v4.2-218-g8911c2912
I (1316) cpu_start: Starting app cpu, entry point is 0x40082104
I (0) cpu_start: App cpu up.
I (1825) spiram: SPI SRAM memory test OK
I (1829) heap_init: Initializing. RAM available for dynamic allocation:
I (1829) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (1832) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (1838) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (1844) heap_init: At 3FFCF300 len 00010D00 (67 KiB): DRAM
I (1850) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1857) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1863) heap_init: At 4009DEA0 len 00002160 (8 KiB): IRAM
I (1870) cpu_start: Pro cpu start user code
I (1874) spiram: Adding pool of 4037K of external SPI memory to heap allocator
I (1895) spi_flash: detected chip: generic
I (1895) spi_flash: flash io: qio
I (1896) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1904) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (1914) [app_main]: ==== Voice Assistant SDK version: v1.2.2 ====
I (1964) wifi:wifi driver task: 3ffdd778, prio:23, stack:6656, core=0
I (1964) system_api: Base MAC address is not set
I (1964) system_api: read default base MAC address from EFUSE
I (1984) wifi:wifi firmware version: 25f230e
I (1984) wifi:wifi certification version: v7.0
I (1984) wifi:config NVS flash: enabled
I (1984) wifi:config nano formating: disabled
I (1984) wifi:Init data frame dynamic rx buffer num: 32
I (1994) wifi:Init management frame dynamic rx buffer num: 32
I (1994) wifi:Init management short buffer num: 32
I (2004) wifi:Init static tx buffer num: 32
I (2004) wifi:Init tx cache buffer num: 32
I (2004) wifi:Init static rx buffer size: 1600
I (2014) wifi:Init static rx buffer num: 10
I (2014) wifi:Init dynamic rx buffer num: 32
I (2024) wifi_init: rx ba win: 16
I (2024) wifi_init: tcpip mbox: 32
I (2024) wifi_init: udp mbox: 6
I (2034) wifi_init: tcp mbox: 12
I (2034) wifi_init: tcp tx win: 14360
I (2044) wifi_init: tcp rx win: 14360
I (2044) wifi_init: tcp mss: 1440
I (2044) wifi_init: WiFi/LWIP prefer SPIRAM
I (2054) [app_smart_home]: Registering command: smart-home
[app_smart_home]: *************** Light's Power turned ON ***************
[app_smart_home]: *************** Light's Brightness changed to 100 ***************
I (2074) wifi_prov_scheme_ble: BT memory released
I (2104) AUDIO_BOARD: Installing M5Stack Core2 for AWS IoT EduKit board i2s driver for Speaker
I (2104) I2S: DMA Malloc info, datalen=blocksize=600, dma_buf_count=3
I (2104) I2S: PLL_D2: Req RATE: 48000, real rate: 48076.000, BITS: 16, CLKM: 13, BCK: 8, MCLK: 12292917.167, SCLK: 1538432.000000, diva: 64, divb: 1
I (2134) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 1| Intr:3
I (2334) ILI9341: Initialization.
I (2534) ILI9341: Display orientation: LANDSCAPE
I (2534) ILI9341: 0x36 command value: 0x08
I (2534) AUDIO_BOARD: M5Stack Core2 for AWS IoT EduKit LED driver Initialized.
I (3934) [tone]: Disabling Start-of-Request tone
I (3934) [tone]: Disabling End-of-Request tone
I (3934) [scli]: Initialising UART on port 0
I (3934) uart: queue free spaces: 8

>> I (3944) [diag_cli]: Registering command: up-time
I (3944) [diag_cli]: Registering command: mem-dump
I (3954) [diag_cli]: Registering command: task-dump
I (3964) [diag_cli]: Registering command: cpu-dump
I (3964) [diag_cli]: Registering command: sock-dump
I (3974) [diag_cli]: Registering command: heap-trace
I (3974) [va_diag_cli]: Registering command: nvs-get
I (3984) [va_diag_cli]: Registering command: nvs-set
I (3984) [va_diag_cli]: Registering command: nvs-erase
I (3994) [va_diag_cli]: Registering command: reboot
I (3994) [va_diag_cli]: Registering command: crash
I (4004) [wifi_cli]: Registering command: wifi-set
I (4014) [app-auth]: Registering command: sign-in
I (4014) [app-auth]: Registering command: sign-out
I (4024) [speaker]: Registering command: vol-up
I (4024) [speaker]: Registering command: vol-down
I (4034) [speaker]: Registering command: vol-set
I (4034) [va_nvs_utils]: No value set for: speaker_vol
I (4044) [speaker]: Using default volume
[speaker]: Volume changed to 80
I (4054) [audio_codec]: Starting mp3_decoder codec
I (4054) [va_nvs_utils]: No value set for: wifi_reset_bit
[app_prov]: Starting provisioning
I (4144) phy: phy_version: 4500, 0cd6843, Sep 17 2020, 15:37:07, 0, 0
I (4144) wifi:mode : sta (b8:f0:09:c4:a7:fc)
I (4144) BTDM_INIT: BT controller compile version [d886f91]
I (4414) wifi_prov_mgr: Provisioning started with service name : ESP-Alexa-A7FC
I (4414) [app_prov]: Provisioning started
[app_prov]: Provisioning started with:
        service name: ESP-Alexa-A7FC
        service key:
        proof of possession (pop): abcd1234
I (4424) [prompt]: Processing request ===> Play
I (4434) [focus_manager]: Acquire channel: Prompt Prompt

[prompt]: On Focus: Foreground
I (4444) [sys_playback]: Acquire
I (4434) [prompt]: Processing request ===> Foreground
I (4444) [focus_manager]: Now active channel: Prompt Prompt

[audio_codec]: Starting audio codec mp3_decoder
I (4464) [prompt]: Processing request ===> Play
I (4464) [audio_codec]: Codec mp3_decoder Event Started
[basic_player]: Codec event: Codec Started
I (4474) MP3Decoder: Found ID3 tag, skipping 45 bytes
I (4484) MP3Decoder: MP3 sync operation...
I (4484) MP3Decoder: MP3 sync success
I (4494) [audio_codec]: Codec mp3_decoder Event Set Freq
[basic_player]: Codec event: Codec Set Frequency
I (4504) [basic_player]: Set Freq event: 24000, 1, 16
I (4504) [prompt]: Processing request ===> Pipeline Started
I (4514) [m5stackcore2_init]: Pausing I2S Reader Stream
I (4524) MP3Decoder: Codec reader finished
I (4544) MP3Decoder: Done with last chunk
I (4544) MP3Decoder: Closed
I (4544) [audio_codec]: Codec mp3_decoder Event Stopped
[basic_player]: Codec event: Codec Stopped
W (4614) AUDIO_BOARD: Installing I2S driver mode 1
I (4614) I2S: DMA Malloc info, datalen=blocksize=600, dma_buf_count=3
I (4614) I2S: PLL_D2: Req RATE: 48000, real rate: 48076.000, BITS: 16, CLKM: 13, BCK: 8, MCLK: 12292917.167, SCLK: 1538432.000000, diva: 64, divb: 1
I (4624) I2S: PLL_D2: Req RATE: 48000, real rate: 48076.000, BITS: 16, CLKM: 13, BCK: 8, MCLK: 12292917.167, SCLK: 1538432.000000, diva: 64, divb: 1
I (5124) [prompt]: Processing request ===> Pipeline Stopped
[audio_codec]: Starting audio codec mp3_decoder
I (5124) [audio_codec]: Codec mp3_decoder Event Started
[basic_player]: Codec event: Codec Started
I (5124) MP3Decoder: Found ID3 tag, skipping 45 bytes
I (5134) MP3Decoder: MP3 sync operation...
I (5134) MP3Decoder: MP3 sync success
I (5144) [audio_codec]: Codec mp3_decoder Event Set Freq
[basic_player]: Codec event: Codec Set Frequency
I (5154) [basic_player]: Set Freq event: 24000, 1, 16
I (5164) [prompt]: Processing request ===> Pipeline Started
I (8394) MP3Decoder: Codec reader finished
I (8704) MP3Decoder: Done with last chunk
I (8704) MP3Decoder: Closed
I (8704) [audio_codec]: Codec mp3_decoder Event Stopped
[basic_player]: Codec event: Codec Stopped
I (9564) [prompt]: Processing request ===> Pipeline Stopped
I (9564) [focus_manager]: Release channel: Prompt Prompt
I (9564) [focus_manager]: Releasing Prompt
I (9574) [sys_playback]: Release
I (44184) [avs_config]: Received request for device details
I (44184) [avs_config]: code_verifier - abcd1234, code_challenge - 6c7nGrky_ehjM40Ivk3p3-OeoEm9r7NCzmWexUULaa4
I (44194) [avs_config]: version: 1, DSN: b8f009c4a7fc, ProductID: Core2ForAWS

Thanks, Stefano

rashedtalukder commented 3 years ago

Hi Stefano, could you please do a git pull and grab the latest commit? The sdkconfig.defaults was changed and the product name was changed in there. I’ve reverted it.

Alternatively, you can run idf.py menuconfig, go to voice assistant configurations and change the product ID to esp_alexa_open

shurillu commented 3 years ago

Hello rashedtalukder I downloaded the latest commit and it works perfectly! Thank you so much!

Stefano