espressif / esp-tflite-micro

TensorFlow Lite Micro for Espressif Chipsets
Apache License 2.0
392 stars 83 forks source link

Micro Speech continues restart after compiling with target esp32-s3 #38

Open techlearnerr opened 1 year ago

techlearnerr commented 1 year ago

Hey folks,

I am trying to compile the micro speech example. After successfully compilation the controller continues to restart every few seconds and log as follows:

I (25) boot: ESP-IDF v5.0.1-dirty 2nd stage bootloader
I (25) boot: compile time 09:34:25
I (25) boot: chip revision: v0.1
I (27) qio_mode: Enabling default flash chip QIO
I (32) boot.esp32s3: Boot SPI Speed : 80MHz
I (37) boot.esp32s3: SPI Mode       : QIO
I (42) boot.esp32s3: SPI Flash Size : 2MB
I (47) boot: Enabling RNG early entropy source...
I (52) boot: Partition Table:
I (56) boot: ## Label            Usage          Type ST Offset   Length
I (63) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (70) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (78) boot:  2 factory          factory app      00 00 00010000 00100000
I (85) boot: End of partition table
I (90) esp_image: segment 0: paddr=00010020 vaddr=3c030020 size=126e8h ( 75496) map
I (109) esp_image: segment 1: paddr=00022710 vaddr=3fc90e00 size=02378h (  9080) load
I (111) esp_image: segment 2: paddr=00024a90 vaddr=40374000 size=0b588h ( 46472) load
I (124) esp_image: segment 3: paddr=00030020 vaddr=42000020 size=2ee8ch (192140) map
I (154) esp_image: segment 4: paddr=0005eeb4 vaddr=4037f588 size=01774h (  6004) load
I (160) boot: Loaded app from partition at offset 0x10000
I (161) boot: Disabling RNG early entropy source...
I (174) cpu_start: Pro cpu up.
I (174) cpu_start: Starting app cpu, entry point is 0x403751cc
0x403751cc: call_start_cpu1 at D:/.espressif/frameworks/esp-idf-v5.0.1/components/esp_system/port/cpu_start.c:142

I (0) cpu_start: App cpu up.
I (188) cpu_start: Pro cpu start user code
I (188) cpu_start: cpu freq: 160000000 Hz
I (188) cpu_start: Application information:
I (191) cpu_start: Project name:     micro_speech
I (197) cpu_start: App version:      83bc5cc-dirty
I (202) cpu_start: Compile time:     Apr 17 2023 09:34:16
I (208) cpu_start: ELF file SHA256:  bc89fd6c70466fa1...
I (214) cpu_start: ESP-IDF:          v5.0.1-dirty
I (220) cpu_start: Min chip rev:     v0.0
I (224) cpu_start: Max chip rev:     v0.99
I (229) cpu_start: Chip rev:         v0.1
I (234) heap_init: Initializing. RAM available for dynamic allocation:
I (241) heap_init: At 3FC9C4D0 len 0004D240 (308 KiB): D/IRAM
I (247) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
I (254) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (260) heap_init: At 600FE010 len 00001FF0 (7 KiB): RTCRAM
I (267) spi_flash: detected chip: generic
I (271) spi_flash: flash io: qio
W (275) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
W (288) i2s(legacy): legacy i2s driver is deprecated, please migrate to use driver/i2s_std.h, driver/i2s_pdm.h or driver/i2s_tdm.h
I (301) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x7 (TG0WDT_SYS_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x403743c0
0x403743c0: _DoubleExceptionVector at D:/.espressif/frameworks/esp-idf-v5.0.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:469

SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3810,len:0x17ac
load:0x403c9700,len:0xd7c
load:0x403cc700,len:0x3164
entry 0x403c992c
I (29) boot: ESP-IDF v5.0.1-dirty 2nd stage bootloader
I (29) boot: compile time 09:34:25
I (29) boot: chip revision: v0.1
I (32) qio_mode: Enabling default flash chip QIO
I (37) boot.esp32s3: Boot SPI Speed : 80MHz
I (42) boot.esp32s3: SPI Mode       : QIO
I (46) boot.esp32s3: SPI Flash Size : 2MB
W (51) boot.esp32s3: PRO CPU has been reset by WDT.
W (57) boot.esp32s3: APP CPU has been reset by WDT.
I (62) boot: Enabling RNG early entropy source...
I (68) boot: Partition Table:
I (71) boot: ## Label            Usage          Type ST Offset   Length
I (78) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (86) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (93) boot:  2 factory          factory app      00 00 00010000 00100000
I (101) boot: End of partition table
I (105) esp_image: segment 0: paddr=00010020 vaddr=3c030020 size=126e8h ( 75496) map
I (125) esp_image: segment 1: paddr=00022710 vaddr=3fc90e00 size=02378h (  9080) load
I (127) esp_image: segment 2: paddr=00024a90 vaddr=40374000 size=0b588h ( 46472) load
I (140) esp_image: segment 3: paddr=00030020 vaddr=42000020 size=2ee8ch (192140) map
I (169) esp_image: segment 4: paddr=0005eeb4 vaddr=4037f588 size=01774h (  6004) load
I (176) boot: Loaded app from partition at offset 0x10000
I (176) boot: Disabling RNG early entropy source...
I (190) cpu_start: Pro cpu up.
I (190) cpu_start: Starting app cpu, entry point is 0x403751cc
0x403751cc: call_start_cpu1 at D:/.espressif/frameworks/esp-idf-v5.0.1/components/esp_system/port/cpu_start.c:142

I (0) cpu_start: App cpu up.
I (204) cpu_start: Pro cpu start user code
I (204) cpu_start: cpu freq: 160000000 Hz
I (204) cpu_start: Application information:
I (207) cpu_start: Project name:     micro_speech
I (212) cpu_start: App version:      83bc5cc-dirty
I (218) cpu_start: Compile time:     Apr 17 2023 09:34:16
I (224) cpu_start: ELF file SHA256:  bc89fd6c70466fa1...
I (230) cpu_start: ESP-IDF:          v5.0.1-dirty
I (235) cpu_start: Min chip rev:     v0.0
I (240) cpu_start: Max chip rev:     v0.99
I (245) cpu_start: Chip rev:         v0.1
I (250) heap_init: Initializing. RAM available for dynamic allocation:
I (257) heap_init: At 3FC9C4D0 len 0004D240 (308 KiB): D/IRAM
I (263) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
I (270) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (276) heap_init: At 600FE010 len 00001FF0 (7 KiB): RTCRAM
I (283) spi_flash: detected chip: generic
I (287) spi_flash: flash io: qio
W (291) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
W (304) i2s(legacy): legacy i2s driver is deprecated, please migrate to use driver/i2s_std.h, driver/i2s_pdm.h or driver/i2s_tdm.h
I (317) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x7 (TG0WDT_SYS_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40379fe1
0x40379fe1: _xt_context_save at D:/.espressif/frameworks/esp-idf-v5.0.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_context.S:214

SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3810,len:0x17ac
load:0x403c9700,len:0xd7c
load:0x403cc700,len:0x3164
entry 0x403c992c

Target platform: ESP32-S3 IDF version release/v5.0

vikramdattu commented 1 year ago

Please make sure the I2S pin configuration is as per mic on ESP32S3 you have. You can make the changes in i2s_init function of audio_provider.cc

techlearnerr commented 1 year ago

I have changed the I2S pin configuration in

audio_provider.cc

  i2s_pin_config_t pin_config = {
      .bck_io_num = 13,    // IIS_SCLK
      .ws_io_num = 18,     // IIS_LCLK
      .data_out_num = -1,  // IIS_DSIN
      .data_in_num = 14,   // IIS_DOUT
  };

after these changes, I got the following response (Task watchdog got triggered)


entry 0x403c992c
I (25) boot: ESP-IDF v5.0.1-dirty 2nd stage bootloader
I (25) boot: compile time 09:34:25
I (25) boot: chip revision: v0.1
I (27) qio_mode: Enabling default flash chip QIO
I (32) boot.esp32s3: Boot SPI Speed : 80MHz
I (37) boot.esp32s3: SPI Mode       : QIO
I (42) boot.esp32s3: SPI Flash Size : 2MB
I (47) boot: Enabling RNG early entropy source...
I (52) boot: Partition Table:
I (56) boot: ## Label            Usage          Type ST Offset   Length
I (63) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (70) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (78) boot:  2 factory          factory app      00 00 00010000 00100000
I (85) boot: End of partition table
I (90) esp_image: segment 0: paddr=00010020 vaddr=3c030020 size=126e8h ( 75496) map
I (109) esp_image: segment 1: paddr=00022710 vaddr=3fc90e00 size=02378h (  9080) load
I (111) esp_image: segment 2: paddr=00024a90 vaddr=40374000 size=0b588h ( 46472) load
I (124) esp_image: segment 3: paddr=00030020 vaddr=42000020 size=2ee8ch (192140) map
I (154) esp_image: segment 4: paddr=0005eeb4 vaddr=4037f588 size=01774h (  6004) load
I (160) boot: Loaded app from partition at offset 0x10000
I (161) boot: Disabling RNG early entropy source...
I (174) cpu_start: Pro cpu up.
I (174) cpu_start: Starting app cpu, entry point is 0x403751cc
0x403751cc: call_start_cpu1 at D:/.espressif/frameworks/esp-idf-v5.0.1/components/esp_system/port/cpu_start.c:142

I (0) cpu_start: App cpu up.
I (188) cpu_start: Pro cpu start user code
I (188) cpu_start: cpu freq: 160000000 Hz
I (188) cpu_start: Application information:
I (191) cpu_start: Project name:     micro_speech
I (197) cpu_start: App version:      83bc5cc-dirty
I (202) cpu_start: Compile time:     Apr 17 2023 09:34:16
I (208) cpu_start: ELF file SHA256:  4abe29b796b6f4b5...
I (214) cpu_start: ESP-IDF:          v5.0.1-dirty
I (220) cpu_start: Min chip rev:     v0.0
I (224) cpu_start: Max chip rev:     v0.99
I (229) cpu_start: Chip rev:         v0.1
I (234) heap_init: Initializing. RAM available for dynamic allocation:
I (241) heap_init: At 3FC9C4D0 len 0004D240 (308 KiB): D/IRAM
I (247) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
I (254) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (260) heap_init: At 600FE010 len 00001FF0 (7 KiB): RTCRAM
I (267) spi_flash: detected chip: generic
I (271) spi_flash: flash io: qio
W (275) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
W (288) i2s(legacy): legacy i2s driver is deprecated, please migrate to use driver/i2s_std.h, driver/i2s_pdm.h or driver/i2s_tdm.h
I (301) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (160) TF_LITE_AUDIO_PROVIDER: Audio Recording started
E (39346) task_wdt: Task watchdog got triggered. The following tasks/users did not reset the watchdog in time:
E (39346) task_wdt:  - IDLE (CPU 1)
E (39346) task_wdt: Tasks currently running:
E (39346) task_wdt: CPU 0: IDLE
E (39346) task_wdt: CPU 1: tensorflow
E (39346) task_wdt: Print CPU 1 backtrace

Backtrace: 0x4037883E:0x3FC921C0 0x40377005:0x3FC921E0 0x42008863:0x3FCEB870 0x42008499:0x3FCEB8B0 0x42008006:0x3FCEB8E00x4037883e: esp_crosscore_isr at D:/.espressif/frameworks/esp-idf-v5.0.1/components/esp_system/crosscore_int.c:96

0x40377005: _xt_lowint1 at D:/.espressif/frameworks/esp-idf-v5.0.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1118

0x42008863: FeatureProvider::PopulateFeatureData(long, long, int*) at D:/tflite-micro-esp-examples/examples/micro_speech/main/feature_provider.cc:80

0x42008499: loop at D:/tflite-micro-esp-examples/examples/micro_speech/main/main_functions.cc:122

0x42008006: tf_main() at D:/tflite-micro-esp-examples/examples/micro_speech/main/main.cc:29 (discriminator 1)

E (44346) task_wdt: Task watchdog got triggered. The following tasks/users did not reset the watchdog in time:
E (44346) task_wdt:  - IDLE (CPU 1)
E (44346) task_wdt: Tasks currently running:
E (44346) task_wdt: CPU 0: IDLE
E (44346) task_wdt: CPU 1: tensorflow
E (44346) task_wdt: Print CPU 1 backtrace

Backtrace: 0x4037883E:0x3FC921C0 0x40377005:0x3FC921E0 0x42008865:0x3FCEB870 0x42008499:0x3FCEB8B0 0x42008006:0x3FCEB8E00x4037883e: esp_crosscore_isr at D:/.espressif/frameworks/esp-idf-v5.0.1/components/esp_system/crosscore_int.c:96

0x40377005: _xt_lowint1 at D:/.espressif/frameworks/esp-idf-v5.0.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1118

0x42008865: FeatureProvider::PopulateFeatureData(long, long, int*) at D:/tflite-micro-esp-examples/examples/micro_speech/main/feature_provider.cc:84

0x42008499: loop at D:/tflite-micro-esp-examples/examples/micro_speech/main/main_functions.cc:122

0x42008006: tf_main() at D:/tflite-micro-esp-examples/examples/micro_speech/main/main.cc:29 (discriminator 1)

E (49346) task_wdt: Task watchdog got triggered. The following tasks/users did not reset the watchdog in time:
E (49346) task_wdt:  - IDLE (CPU 1)
E (49346) task_wdt: Tasks currently running:
E (49346) task_wdt: CPU 0: IDLE
E (49346) task_wdt: CPU 1: tensorflow
E (49346) task_wdt: Print CPU 1 backtrace

Backtrace: 0x4037883E:0x3FC921C0 0x40377005:0x3FC921E0 0x42008865:0x3FCEB870 0x42008499:0x3FCEB8B0 0x42008006:0x3FCEB8E00x4037883e: esp_crosscore_isr at D:/.espressif/frameworks/esp-idf-v5.0.1/components/esp_system/crosscore_int.c:96

0x40377005: _xt_lowint1 at D:/.espressif/frameworks/esp-idf-v5.0.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1118

0x42008865: FeatureProvider::PopulateFeatureData(long, long, int*) at D:/tflite-micro-esp-examples/examples/micro_speech/main/feature_provider.cc:84

0x42008499: loop at D:/tflite-micro-esp-examples/examples/micro_speech/main/main_functions.cc:122

0x42008006: tf_main() at D:/tflite-micro-esp-examples/examples/micro_speech/main/main.cc:29 (discriminator 1)
vikramdattu commented 1 year ago

@techlearnerr Watchdog triggers in this case mean, there are continuous inferences. This should not happen even with ESP32, ESP32-S3 is even more powerful. Did you do any other changes such as in ring_buffer etc?

I hope I2S configuration is now correct. Please check for the code which might be causing this. If there are not much changes, is there a way for me to reproduce your issue?

techlearnerr commented 1 year ago

@vikramdattu I didn't do any changes except the pin configuration

  i2s_pin_config_t pin_config = {
      .bck_io_num = 13,    // IIS_SCLK
      .ws_io_num = 18,     // IIS_LCLK
      .data_out_num = -1,  // IIS_DSIN
      .data_in_num = 14,   // IIS_DOUT
  };

The microphone I am using is MEMS Microphone Breakout - SPH0645LM4H

I (25) boot: ESP-IDF v5.0.1-dirty 2nd stage bootloader
I (25) boot: compile time 09:32:41
I (25) boot: chip revision: v0.1
I (27) qio_mode: Enabling default flash chip QIO
I (32) boot.esp32s3: Boot SPI Speed : 80MHz
I (37) boot.esp32s3: SPI Mode       : QIO
I (42) boot.esp32s3: SPI Flash Size : 2MB
I (47) boot: Enabling RNG early entropy source...
I (52) boot: Partition Table:
I (56) boot: ## Label            Usage          Type ST Offset   Length
I (63) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (70) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (78) boot:  2 factory          factory app      00 00 00010000 00100000
I (85) boot: End of partition table
I (90) esp_image: segment 0: paddr=00010020 vaddr=3c030020 size=127f0h ( 75760) map
I (110) esp_image: segment 1: paddr=00022818 vaddr=3fc90e00 size=02378h (  9080) load
I (111) esp_image: segment 2: paddr=00024b98 vaddr=40374000 size=0b480h ( 46208) load
I (124) esp_image: segment 3: paddr=00030020 vaddr=42000020 size=2ee8ch (192140) map
I (154) esp_image: segment 4: paddr=0005eeb4 vaddr=4037f480 size=0187ch (  6268) load
I (160) boot: Loaded app from partition at offset 0x10000
I (161) boot: Disabling RNG early entropy source...
I (174) cpu_start: Pro cpu up.
I (174) cpu_start: Starting app cpu, entry point is 0x403751cc
0x403751cc: call_start_cpu1 at D:/.espressif/frameworks/esp-idf-v5.0.1/components/esp_system/port/cpu_start.c:142

I (0) cpu_start: App cpu up.
I (188) cpu_start: Pro cpu start user code
I (188) cpu_start: cpu freq: 160000000 Hz
I (188) cpu_start: Application information:
I (191) cpu_start: Project name:     micro_speech
I (197) cpu_start: App version:      83bc5cc-dirty
I (202) cpu_start: Compile time:     Apr 24 2023 09:32:17
I (208) cpu_start: ELF file SHA256:  d68b52e237bf89fa...
I (214) cpu_start: ESP-IDF:          v5.0.1-dirty
I (220) cpu_start: Min chip rev:     v0.0
I (224) cpu_start: Max chip rev:     v0.99
I (229) cpu_start: Chip rev:         v0.1
I (234) heap_init: Initializing. RAM available for dynamic allocation:
I (241) heap_init: At 3FC9C4D0 len 0004D240 (308 KiB): D/IRAM
I (247) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
I (254) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (260) heap_init: At 600FE010 len 00001FF0 (7 KiB): RTCRAM
I (267) spi_flash: detected chip: generic
I (271) spi_flash: flash io: qio
W (275) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
W (288) i2s(legacy): legacy i2s driver is deprecated, please migrate to use driver/i2s_std.h, driver/i2s_pdm.h or driver/i2s_tdm.h
I (301) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (160) TF_LITE_AUDIO_PROVIDER: Audio Recording started
Heard unknown (230) @8600ms
Heard unknown (206) @11300ms
Heard unknown (209) @14100ms
Heard unknown (236) @15700ms
Heard unknown (231) @17300ms
Heard unknown (205) @18900ms
E (39346) task_wdt: Task watchdog got triggered. The following tasks/users did not reset the watchdog in time:
E (39346) task_wdt:  - IDLE (CPU 1)
E (39346) task_wdt: Tasks currently running:
E (39346) task_wdt: CPU 0: IDLE
E (39346) task_wdt: CPU 1: tensorflow
E (39346) task_wdt: Print CPU 1 backtrace

Backtrace: 0x4037883E:0x3FC921C0 0x40377005:0x3FC921E0 0x4200886D:0x3FCEB870 0x42008499:0x3FCEB8B0 0x42008006:0x3FCEB8E0
0x4037883e: esp_crosscore_isr at D:/.espressif/frameworks/esp-idf-v5.0.1/components/esp_system/crosscore_int.c:96

0x40377005: _xt_lowint1 at D:/.espressif/frameworks/esp-idf-v5.0.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1118

0x4200886d: FeatureProvider::PopulateFeatureData(long, long, int*) at D:/.espressif/frameworks/tflite-micro-esp-examples/examples/micro_speech/main/feature_provider.cc:85 (discriminator 3)

0x42008499: loop at D:/.espressif/frameworks/tflite-micro-esp-examples/examples/micro_speech/main/main_functions.cc:122

0x42008006: tf_main() at D:/.espressif/frameworks/tflite-micro-esp-examples/examples/micro_speech/main/main.cc:29 (discriminator 1)

Heard unknown (215) @20500ms
Heard unknown (215) @22100ms
Heard unknown (213) @23700ms
E (44346) task_wdt: Task watchdog got triggered. The following tasks/users did not reset the watchdog in time:
E (44346) task_wdt:  - IDLE (CPU 1)
E (44346) task_wdt: Tasks currently running:
E (44346) task_wdt: CPU 0: IDLE
E (44346) task_wdt: CPU 1: tensorflow
E (44346) task_wdt: Print CPU 1 backtrace

Backtrace: 0x4037883E:0x3FC921C0 0x40377005:0x3FC921E0 0x42008872:0x3FCEB870 0x42008499:0x3FCEB8B0 0x42008006:0x3FCEB8E0
0x4037883e: esp_crosscore_isr at D:/.espressif/frameworks/esp-idf-v5.0.1/components/esp_system/crosscore_int.c:96

0x40377005: _xt_lowint1 at D:/.espressif/frameworks/esp-idf-v5.0.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1118

0x42008872: FeatureProvider::PopulateFeatureData(long, long, int*) at D:/.espressif/frameworks/tflite-micro-esp-examples/examples/micro_speech/main/feature_provider.cc:85 (discriminator 3)

0x42008499: loop at D:/.espressif/frameworks/tflite-micro-esp-examples/examples/micro_speech/main/main_functions.cc:122

0x42008006: tf_main() at D:/.espressif/frameworks/tflite-micro-esp-examples/examples/micro_speech/main/main.cc:29 (discriminator 1)

Heard unknown (205) @25500ms
Heard unknown (224) @27100ms