search

espressif / esp-adf

Espressif Audio Development Framework
Other
1.55k stars 685 forks source link

Dueros相关的例程wifi连接失败后自动重启 (AUD-3648) #772

Closed Beanv587 closed 2 years ago

Beanv587 commented 2 years ago

IDF:release/4.4 ADF:master

IDF、ADF都是最新的,子模块也都是拉取的最新的

包含的此BUG的例子:examples\advanced_examples\esp_dispatcher_dueros、examples\dueros

idf.py menuconfig里已经正确配置CONFIG_WIFI_SSID、CONFIG_WIFI_PASSWORD

测试别的例子配置wifi后能正常运行.打印日志如下(PS:日志里的(3494)显示ssid、pwd都是空的...问题应该在这儿):

entry 0x40080694 I (27) boot: ESP-IDF v4.4-dirty 2nd stage bootloader I (27) boot: compile time 15:42:51 I (27) boot: chip revision: 3 I (30) boot_comm: chip revision: 3, min. bootloader chip revision: 0 I (37) boot.esp32: SPI Speed : 80MHz I (42) boot.esp32: SPI Mode : DIO I (47) boot.esp32: SPI Flash Size : 8MB I (51) boot: Enabling RNG early entropy source... I (57) boot: Partition Table: I (60) boot: ## Label Usage Type ST Offset Length I (67) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (75) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (82) boot: 2 factory factory app 00 00 00010000 00300000 I (90) boot: End of partition table I (94) boot_comm: chip revision: 3, min. application chip revision: 0 I (101) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=1a27c0h (1714112) map I (628) esp_image: segment 1: paddr=001b27e8 vaddr=3ffb0000 size=042b4h ( 17076) load I (633) esp_image: segment 2: paddr=001b6aa4 vaddr=40080000 size=09574h ( 38260) load I (647) esp_image: segment 3: paddr=001c0020 vaddr=400d0020 size=130b70h (1248112) map I (1024) esp_image: segment 4: paddr=002f0b98 vaddr=40089574 size=1404ch ( 81996) load I (1053) esp_image: segment 5: paddr=00304bec vaddr=50000000 size=00010h ( 16) load I (1068) boot: Loaded app from partition at offset 0x10000 I (1068) boot: Disabling RNG early entropy source... I (1080) psram: This chip is ESP32-D0WD I (1080) spiram: Found 64MBit SPI RAM device I (1080) spiram: SPI RAM mode: flash 80m sram 80m I (1085) spiram: PSRAM initialized, cache is in low/high (2-core) mode. I (1093) cpu_start: Pro cpu up. I (1097) cpu_start: Starting app cpu, entry point is 0x40081904 0x40081904: call_start_cpu1 at E:/esp32/esp-idf-v4.4/components/esp_system/port/cpu_start.c:156

I (1090) cpu_start: App cpu up. I (1602) spiram: SPI SRAM memory test OK I (1611) cpu_start: Pro cpu start user code I (1611) cpu_start: cpu freq: 240000000 I (1611) cpu_start: Application information: I (1614) cpu_start: Project name: esp_dispatcher_dueros I (1620) cpu_start: App version: 1 I (1625) cpu_start: Compile time: Feb 23 2022 15:42:29 I (1631) cpu_start: ELF file SHA256: 7a417e150da9ad85... I (1637) cpu_start: ESP-IDF: v4.4-dirty I (1642) heap_init: Initializing. RAM available for dynamic allocation: I (1649) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM I (1656) heap_init: At 3FFB7520 len 00028AE0 (162 KiB): DRAM I (1662) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM I (1668) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM I (1675) heap_init: At 4009D5C0 len 00002A40 (10 KiB): IRAM I (1681) spiram: Adding pool of 4084K of external SPI memory to heap allocator I (1690) spi_flash: detected chip: generic I (1694) spi_flash: flash io: dio I (1699) cpu_start: Starting scheduler on PRO CPU. I (0) cpu_start: Starting scheduler on APP CPU. I (1713) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations I (1758) DISPATCHER_DUEROS: ADF version is I (1758) DISPATCHER_DUEROS: Step 1. Create dueros_speaker instance E (1759) DISPATCHER: exe first list: 0x0 I (1763) DISPATCHER: dispatcher_event_task is running... I (1769) DISPATCHER_DUEROS: [Step 2.0] Create esp_periph_set_handle_t instance and initialize Touch, Button, SDcard I (1781) gpio: GPIO[36]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:3 I (1790) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:3 W (1825) PERIPH_TOUCH: _touch_init I (1825) SDCARD: Using 1-line SD mode, 4-line SD mode, base path=/sdcard I (1892) SDCARD: CID name ACLCE!

I (2299) DISPATCHER_DUEROS: [Step 2.1] Initialize input key service I (2299) DISPATCHER_DUEROS: [Step 3.0] Create display service instance I (2302) DISPATCHER_DUEROS: [Step 3.1] Register display service execution type I (2310) DISPATCHER_DUEROS: [Step 4.0] Initialize recorder engine I (2331) I2S: APLL expected frequency is 22579200 Hz, real frequency is 22579193 Hz I (2332) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3 I (2337) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3 I (2344) I2S: I2S0, MCLK output by GPIO0 I (2349) LYRAT_V4_3: I2S0, MCLK output by GPIO0 I (2355) AUDIO_PIPELINE: link el->rb, el:0x3f80a6cc, tag:i2s, rb:0x3f80aadc I (2377) AUDIO_PIPELINE: link el->rb, el:0x3f80a83c, tag:filter, rb:0x3f80cb1c I (2377) AUDIO_ELEMENT: [i2s-0x3f80a6cc] Element task created I (2381) AUDIO_ELEMENT: [raw-0x3f80a96c] Element task created I (2388) AUDIO_THREAD: The filter task allocate stack on external memory I (2395) AUDIO_ELEMENT: [filter-0x3f80a83c] Element task created I (2401) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:359, MEM Total:4344879 Bytes, Inter:242459 Bytes, Dram:233795 Bytes

I (2423) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_RESUME,state:1 I (2425) AUDIO_ELEMENT: [filter] AEL_MSG_CMD_RESUME,state:1 I (2432) RSP_FILTER: sample rate of source data : 48000, channel of source data : 2, sample rate of destination data : 16000, channel of destination data : 2 I (2448) AUDIO_PIPELINE: Pipeline started I (2450) AUDIO_SETUP: Recorder has been created Deprecated Quantized wakeNet5: wakeNet5_v1_hilexin_5_0.95_0.90, mode:0 (Dec 10 2021 20:15:15) 3 Initial ONE-MIC auido front-end for speech recognition, mode:1, (Dec 10 2021 20:29:24) SINGLE_RECOGNITION: v2; (Dec 10 2021 20:45:08) I (2486) MN: ---------------------SPEECH COMMANDS--------------------- I (2492) MN: Command ID0, phrase 0: da kai kong tiao I (2515) MN: Command ID1, phrase 1: guan bi kong tiao I (2515) MN: Command ID2, phrase 2: zeng da feng su I (2516) MN: Command ID3, phrase 3: jian xiao feng su I (2521) MN: Command ID4, phrase 4: sheng gao yi du I (2527) MN: Command ID5, phrase 5: jiang di yi du I (2532) MN: Command ID6, phrase 6: zhi re mo shi I (2538) MN: Command ID7, phrase 7: zhi leng mo shi I (2543) MN: Command ID8, phrase 8: song feng mo shi I (2561) MN: Command ID9, phrase 9: jie neng mo shi I (2562) MN: Command ID10, phrase 10: chu shi mo shi I (2565) MN: Command ID11, phrase 11: jian kang mo shi I (2571) MN: Command ID12, phrase 12: shui mian mo shi I (2577) MN: Command ID13, phrase 13: da kai lan ya I (2582) MN: Command ID14, phrase 14: guan bi lan ya I (2588) MN: Command ID15, phrase 15: kai shi bo fang I (2607) MN: Command ID16, phrase 16: zan ting bo fang I (2607) MN: Command ID17, phrase 17: ding shi yi xiao shi I (2611) MN: Command ID18, phrase 18: da kai dian deng I (2616) MN: Command ID19, phrase 19: guan bi dian deng I (2622) MN: ---------------------------------------------------------

W (2629) MN: MultiNet may cause WatchDog on ESP32 sometimes! I (2636) AUDIO_THREAD: The feed_task task allocate stack on external memory I (2653) AUDIO_THREAD: The fetch_task task allocate stack on external memory I (2656) AUDIO_THREAD: The recorder_task task allocate stack on external memory I (2777) DISPATCHER_DUEROS: [Step 4.1] Register wanted recorder execution type I (2812) DISPATCHER_DUEROS: [Step 5.0] Initialize esp player I (2813) gpio: GPIO[19]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:3 E (2818) gpio: gpio_install_isr_service(449): GPIO isr service already installed I (2866) gpio: GPIO[21]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (2866) ES8388_DRIVER: init,out:02, in:00 I (2903) AUDIO_HAL: Codec mode is 3, Ctrl:1 I (2961) AUDIO_THREAD: The media_task task allocate stack on external memory I (2961) ESP_AUDIO_TASK: media_ctrl_task running...,0x3f81dff8

----------------------------- ESP Audio Platform ----------------------------- | | | ESP_AUDIO-v1.7.0-31-g5b8f999-3072767-09be8fe | | Compile date: Oct 14 2021-11:00:34 |

I (3021) ESP_AUDIO_CTRL: Func:media_ctrl_create, Line:350, MEM Total:4186599 Bytes, Inter:196547 Bytes, Dram:187883 Bytes

I (3058) MP3_DECODER: MP3 init E (3059) I2S: register I2S object to platform failed I (3059) I2S: I2S0, MCLK output by GPIO0 I (3061) LYRAT_V4_3: I2S0, MCLK output by GPIO0 I (3102) AUDIO_SETUP: Func:setup_player, Line:131, MEM Total:4176135 Bytes, Inter:191691 Bytes, Dram:183027 Bytes

I (3102) AUDIO_SETUP: esp_audio instance is:0x3f81dff8 I (3118) DISPATCHER_DUEROS: [Step 5.1] Register wanted player execution type I (3135) DISPATCHER_DUEROS: [Step 6.0] Initialize dueros service I (3139) DISPATCHER_DUEROS: [Step 6.1] Register dueros service execution type W (3146) DISPATCHER: The 1002 index of function already exists I (3160) DISPATCHER_DUEROS: [Step 7.0] Create Wi-Fi service instance I (3196) AUDIO_THREAD: The wifi_serv task allocate stack on external memory I (3199) wifi:wifi driver task: 3ffdd0d0, prio:23, stack:6656, core=0 I (3199) system_api: Base MAC address is not set I (3204) system_api: read default base MAC address from EFUSE I (3227) wifi:wifi firmware version: 7679c42 I (3227) wifi:wifi certification version: v7.0 I (3227) wifi:config NVS flash: enabled I (3228) wifi:config nano formating: disabled I (3232) wifi:Init data frame dynamic rx buffer num: 32 I (3237) wifi:Init management frame dynamic rx buffer num: 32 I (3242) wifi:Init management short buffer num: 32 I (3247) wifi:Init static tx buffer num: 16 I (3251) wifi:Init tx cache buffer num: 32 I (3255) wifi:Init static rx buffer size: 1600 I (3259) wifi:Init static rx buffer num: 16 I (3263) wifi:Init dynamic rx buffer num: 32 I (3267) wifi_init: rx ba win: 16 I (3271) wifi_init: tcpip mbox: 32 I (3275) wifi_init: udp mbox: 6 I (3278) wifi_init: tcp mbox: 6 I (3282) wifi_init: tcp tx win: 5744 I (3287) wifi_init: tcp rx win: 5744 I (3291) wifi_init: tcp mss: 1440 I (3295) wifi_init: WiFi/LWIP prefer SPIRAM I (3300) wifi_init: WiFi IRAM OP enabled I (3304) wifi_init: WiFi RX IRAM OP enabled I (3310) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07 I (3401) wifi:mode : sta (8c:4b:14:16:16:b0) I (3402) wifi:enable tsf I (3479) DISPATCHER_DUEROS: [Step 7.1] Register wanted display service execution type I (3479) DISPATCHER_DUEROS: [Step 7.2] Initialize Wi-Fi provisioning type(AIRKISS or SMARTCONFIG) I (3494) WIFI_SERV: Connect to wifi ssid: , pwd: ESP_ERROR_CHECK failed: esp_err_t 0x300a (ESP_ERR_WIFI_SSID) at 0x40090c44 0x40090c44: _esp_error_check_failed at E:/esp32/esp-idf-v4.4/components/esp_system/esp_err.c:42

file: "E:/esp32/esp-adf/components/wifi_service/src/wifi_service.c" line 425 func: wifi_task expression: esp_wifi_connect()

abort() was called at PC 0x40090c47 on core 0 0x40090c47: _esp_error_check_failed at E:/esp32/esp-idf-v4.4/components/esp_system/esp_err.c:43

Backtrace:0x40082455:0x3f82cbb00x40090c51:0x3f82cbd0 0x40098175:0x3f82cbf0 0x40090c47:0x3f82cc60 0x400dff33:0x3f82cc80 0x40082455: panic_abort at E:/esp32/esp-idf-v4.4/components/esp_system/panic.c:402

0x40090c51: esp_system_abort at E:/esp32/esp-idf-v4.4/components/esp_system/esp_system.c:121

0x40098175: abort at E:/esp32/esp-idf-v4.4/components/newlib/abort.c:46

0x40090c47: _esp_error_check_failed at E:/esp32/esp-idf-v4.4/components/esp_system/esp_err.c:43

0x400dff33: wifi_task at E:/esp32/esp-adf/components/wifi_service/src/wifi_service.c:425 (discriminator 1)

ELF file SHA256: 7a417e150da9ad85

Rebooting...

HengYongChao commented 2 years ago

Hi @Beanv587

关于你的 WiFi 配置是空这个问题的确有些奇怪，请问你的 WiFi 的 SSID 和 PWD 是特殊字符吗？ 可使用普通的英文字母做测试有没有一样的问题呢？ 另外可以擦除 整个 flash 再烧录尝试。

你说可以使用别的例程链接成功。可否上传 sdkconfig 配置看一看呢， 我的本地测试链接正常，无法复现你的问题，我的sdkconfig 配置如下供你参考，sdkconfig.zip。

Beanv587 commented 2 years ago

Hi @Beanv587

关于你的 WiFi 配置是空这个问题的确有些奇怪，请问你的 WiFi 的 SSID 和 PWD 是特殊字符吗？ 可使用普通的英文字母做测试有没有一样的问题呢？ 另外可以擦除 整个 flash 再烧录尝试。

你说可以使用别的例程链接成功。可否上传 sdkconfig 配置看一看呢， 我的本地测试链接正常，无法复现你的问题，我的sdkconfig 配置如下供你参考，sdkconfig.zip。

@HengYongChao 按你的建议,我把flash全部擦除后重新烧录,问题解决.但是很奇怪程序有异常.我稍后把详细日志发上来.

我的开发板是Lyrat V4.3。

Beanv587 commented 2 years ago

entry 0x400806b4 I (27) boot: ESP-IDF v4.4-dirty 2nd stage bootloader I (27) boot: compile time 20:56:13 I (27) boot: chip revision: 3 I (30) boot_comm: chip revision: 3, min. bootloader chip revision: 0 I (38) qio_mode: Enabling default flash chip QIO I (43) boot.esp32: SPI Speed : 80MHz I (47) boot.esp32: SPI Mode : QIO I (52) boot.esp32: SPI Flash Size : 8MB I (57) boot: Enabling RNG early entropy source... I (62) boot: Partition Table: I (66) boot: ## Label Usage Type ST Offset Length I (73) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (80) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (88) boot: 2 factory factory app 00 00 00010000 00300000 I (95) boot: End of partition table I (99) boot_comm: chip revision: 3, min. application chip revision: 0 I (107) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=68738h (427832) map I (233) esp_image: segment 1: paddr=00078760 vaddr=3ffb0000 size=041c4h ( 16836) load I (238) esp_image: segment 2: paddr=0007c92c vaddr=40080000 size=036ech ( 14060) load I (243) esp_image: segment 3: paddr=00080020 vaddr=400d0020 size=14272ch (1320748) map I (611) esp_image: segment 4: paddr=001c2754 vaddr=400836ec size=134f0h ( 79088) load I (637) esp_image: segment 5: paddr=001d5c4c vaddr=50000000 size=00010h ( 16) load I (649) boot: Loaded app from partition at offset 0x10000 I (649) boot: Disabling RNG early entropy source... I (660) psram: This chip is ESP32-D0WD I (660) spiram: Found 64MBit SPI RAM device I (661) spiram: SPI RAM mode: flash 80m sram 80m I (666) spiram: PSRAM initialized, cache is in low/high (2-core) mode. I (673) cpu_start: Pro cpu up. I (677) cpu_start: Starting app cpu, entry point is 0x400816b4 0x400816b4: call_start_cpu1 at E:/esp32/esp-idf-v4.4/components/esp_system/port/cpu_start.c:156

I (0) cpu_start: App cpu up. I (1158) spiram: SPI SRAM memory test OK I (1166) cpu_start: Pro cpu start user code I (1166) cpu_start: cpu freq: 240000000 I (1167) cpu_start: Application information: I (1170) cpu_start: Project name: esp_dueros I (1175) cpu_start: App version: 1 I (1179) cpu_start: Compile time: Feb 23 2022 20:59:27 I (1185) cpu_start: ELF file SHA256: 6c60573d06ff1838... I (1192) cpu_start: ESP-IDF: v4.4-dirty I (1197) heap_init: Initializing. RAM available for dynamic allocation: I (1204) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM I (1210) heap_init: At 3FFB7458 len 00028BA8 (162 KiB): DRAM I (1217) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM I (1223) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM I (1230) heap_init: At 40096BDC len 00009424 (37 KiB): IRAM I (1236) spiram: Adding pool of 4084K of external SPI memory to heap allocator I (1244) spi_flash: detected chip: generic I (1249) spi_flash: flash io: qio I (1254) cpu_start: Starting scheduler on PRO CPU. I (0) cpu_start: Starting scheduler on APP CPU. I (1268) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations I (1294) DUEROS: ADF version is I (1295) gpio: GPIO[19]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:3 E (1296) gpio: gpio_install_isr_service(449): GPIO isr service already installed I (1315) gpio: GPIO[21]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (1315) ES8388_DRIVER: init,out:02, in:00 I (1324) gpio: GPIO[36]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:3 I (1328) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:3 W (1363) PERIPH_TOUCH: _touch_init I (1363) SDCARD: Using 1-line SD mode, 4-line SD mode, base path=/sdcard I (1429) SDCARD: CID name ACLCE!

E (1837) DISPATCHER: exe first list: 0x0 I (1838) DISPATCHER: dispatcher_event_task is running... I (1841) AUDIO_THREAD: The wifi_serv task allocate stack on external memory I (1847) wifi:wifi driver task: 3ffcdc14, prio:23, stack:6656, core=0 I (1851) system_api: Base MAC address is not set I (1856) system_api: read default base MAC address from EFUSE I (1864) wifi:wifi firmware version: 7679c42 I (1866) wifi:wifi certification version: v7.0 I (1871) wifi:config NVS flash: enabled I (1874) wifi:config nano formating: disabled I (1878) wifi:Init data frame dynamic rx buffer num: 32 I (1883) wifi:Init management frame dynamic rx buffer num: 32 I (1889) wifi:Init management short buffer num: 32 I (1894) wifi:Init static tx buffer num: 16 I (1898) wifi:Init tx cache buffer num: 32 I (1901) wifi:Init static rx buffer size: 1600 I (1905) wifi:Init static rx buffer num: 16 I (1909) wifi:Init dynamic rx buffer num: 32 I (1913) wifi_init: rx ba win: 16 I (1917) wifi_init: tcpip mbox: 32 I (1921) wifi_init: udp mbox: 6 I (1925) wifi_init: tcp mbox: 6 I (1929) wifi_init: tcp tx win: 5744 I (1933) wifi_init: tcp rx win: 5744 I (1937) wifi_init: tcp mss: 1440 I (1941) wifi_init: WiFi/LWIP prefer SPIRAM I (1947) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07 I (2035) wifi:mode : sta (8c:4b:14:16:16:b0) I (2036) wifi:enable tsf I (1575,tid:3ffde0a0) lightduer_session.c( 44):random = 75933 I (2852) WIFI_SERV: Connect to wifi ssid: **, pwd: ** W (2853) AUDIO_BOARD: The board has already been initialized! I (2855) AUDIO_THREAD: The media_task task allocate stack on external memory I (2862) ESP_AUDIO_TASK: media_ctrl_task running...,0x3f81a7c0

----------------------------- ESP Audio Platform ----------------------------- | | | ESP_AUDIO-v1.7.0-31-g5b8f999-3072767-09be8fe | | Compile date: Oct 14 2021-11:00:34 |

I (2909) ESP_AUDIO_CTRL: Func:media_ctrl_create, Line:350, MEM Total:4205967 Bytes, Inter:190331 Bytes, Dram:154559 Bytes

I (2931) AUDIO_HAL: Codec mode is 3, Ctrl:1 I (2935) MP3_DECODER: MP3 init I (2937) I2S: APLL expected frequency is 24576000 Hz, real frequency is 24575996 Hz I (2943) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3 I (2950) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3 I (2957) I2S: I2S0, MCLK output by GPIO0 I (2977) LYRAT_V4_3: I2S0, MCLK output by GPIO0 I (2979) AUDIO_WRAPPER: Func:duer_audio_setup_player, Line:171, MEM Total:4197079 Bytes, Inter:174851 Bytes, Dram:139079 Bytes

I (2984) AUDIO_WRAPPER: esp_audio instance is:0x3f81a7c0 E (2990) I2S: register I2S object to platform failed I (2996) I2S: I2S0, MCLK output by GPIO0 I (3000) LYRAT_V4_3: I2S0, MCLK output by GPIO0 I (3006) AUDIO_PIPELINE: link el->rb, el:0x3f81cb5c, tag:i2s, rb:0x3f81cf6c I (3023) AUDIO_PIPELINE: link el->rb, el:0x3f81cccc, tag:filter, rb:0x3f81efac I (3027) AUDIO_ELEMENT: [i2s-0x3f81cb5c] Element task created I (3033) AUDIO_ELEMENT: [raw-0x3f81cdfc] Element task created I (3039) AUDIO_THREAD: The filter task allocate stack on external memory I (3047) AUDIO_ELEMENT: [filter-0x3f81cccc] Element task created I (3069) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:359, MEM Total:4177315 Bytes, Inter:168407 Bytes, Dram:132635 Bytes

I (3070) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_RESUME,state:1 I (3077) AUDIO_ELEMENT: [filter] AEL_MSG_CMD_RESUME,state:1 I (3084) RSP_FILTER: sample rate of source data : 48000, channel of source data : 2, sample rate of destination data : 16000, channel of destination data : 2 I (3115) AUDIO_PIPELINE: Pipeline started I (3115) AUDIO_WRAPPER: Recorder has been created Deprecated Quantized wakeNet5: wakeNet5_v1_hilexin_5_0.95_0.90, mode:0 (Dec 10 2021 20:15:15) 3 Initial ONE-MIC auido front-end for speech recognition, mode:1, (Dec 10 2021 20:29:24) W (3134) RECORDER_SR: Multinet is not enabled in SDKCONFIG I (3139) AUDIO_THREAD: The feed_task task allocate stack on external memory I (3161) AUDIO_THREAD: The fetch_task task allocate stack on external memory I (3162) AUDIO_THREAD: The recorder_task task allocate stack on external memory I (3269) AUDIO_THREAD: The voice_read_task task allocate stack on external memory I (3826) wifi:new:<9,0>, old:<1,0>, ap:<255,255>, sta:<9,0>, prof:1 I (4386) wifi:state: init -> auth (b0) I (4390) wifi:state: auth -> assoc (0) I (4394) wifi:state: assoc -> run (10) W (4407) wifi:idx:0 (ifx:0, c2:56:27:bc:4b:24), tid:0, ssn:0, winSize:64 I (4419) wifi:connected with Bean_ESP32, aid = 1, channel 9, BW20, bssid = c2:56:27:bc:4b:24 I (4419) wifi:security: WPA2-PSK, phy: bgn, rssi: -36 I (4421) wifi:pm start, type: 1

W (4426) WIFI_SERV: WiFi Event cb, Unhandle event_base:WIFI_EVENT, event_id:4 I (4515) wifi:AP's beacon interval = 102400 us, DTIM period = 3 I (5296) esp_netif_handlers: sta ip: 192.168.0.215, mask: 255.255.255.0, gw: 192.168.0.1 I (5297) WIFI_SERV: Got ip:192.168.0.215 W (5299) WIFI_SERV: STATE type:2, pdata:0x0, len:0 I (5323) DUEROS: PERIPH_WIFI_CONNECTED [145] E (5323) DUEROS: Recv Que DUER_CMD_LOGIN I (5324) DUEROS: duer_start, le14 {"nfures":}"biTon":"8ff3d7**1470","coapPort"43ton"kYivzULrP**1Md8Va",ervedd:"vi.iot.baidu.com","lwm2mPt":443,"uuid":1b0000c"rsaCrt":"-----BEN RTICE-----\nMIIDUDC**ZXXGyVJBun---D RTICTE---",ac":"","versio:100�? UEROS: dr_llckty:0sorce:0x3f80a51c data:2, data_len:0 I (4166,tid:3ffde0a0) lightduer_engine.c( 242):duer_engine_start, g_handler:3F81A6BC, length:1469, profile:3F83AEF4 I (4183,tid:3ffde0a0) lightduer_ca_conf.c( 38): duer_conf_get_string: uuid = 21b4000000000c I (4191,tid:3ffde0a0) lightduer_ca_conf.c( 38): duer_conf_get_string: serverAddr = device.t.idco I (4212,tid:3ffde0a0) baidu_ca_socket_adp.c( 139):DNS lookup succeeded. IP=14.215.177.163 I (4233,tid:3ffde0a0) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK) W (4233,tid:3ffde0a0) lightduer_events.c( 81):[lightduer_ca] <== event end = 4011F8BC, timespent = 67 I (5133,tid:3ffde0a0) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK) W (5133,tid:3ffde0a0) lightduer_events.c( 81):[lightduer_ca] <== event end = 4011FA7C, timespent = 852 I (5143,tid:3ffde0a0) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK) I (5149,tid:3ffde0a0) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK) I (5168,tid:3ffde0a0) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK) I (5169,tid:3ffde0a0) lightduer_connagent.c(08wi srtatter(DUER_ERRRA_WLDLO) I (5175,tid:3ffde0) lightduer_connage.c20:wl art latter(DUER_ERR_TRANS_WOULD_BLOCK) I (5183,tid:3ffde0a0) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK) I (5189,tid:3ffde0a0) lightduer_engine.c( 242):duer_engine_start, g_handler:3F81A6BC, length:0, profile:00000000 I (5200,tid:3ffde0a0) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK) I (5215,tid:3ffde0a0) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BCK) I (5218,tid:3ffde0a0) ghuer_nnent.c( 208)ill start latter(DUER_ERTRS_ULBLK) I (5223,tid:3de0)igduer_connagent.c( 8):wl artatter(DUER_ERTRS_ULBLK) I (5230,tid:3ffde0a lhtduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK) I (5442,tid:3ffde0a0) lightduer_voice.c( 915):Mutex initializing I (5442,tid:3ffde0a0) lightduer_connagent.c( 189):connect started! I (5444,tid:3ffde0a0) lightduer_ds_log_cache.c( 85):no cache report E (13DUOSeve: 0 UES:uer_dcs_init I (5457,tid:3ffde0a0) lightduer_dcroer( 6):namespace: aduosriatprotocol I (61,tid:3ffde0)igdu_d_rter.c( 306):namespace: ai.dueros.dece_interfacecrn_teedar I (5468,tid:3ffde0a litduer_dcs_router.c( 306):namespace: ai.dueros.device_interface.screen I (5476,tid:3ffde0a0) lightduer_dcs_router.c( 306):namespace: ai.dueros.device_interface.system I (5485,tid:3ffde0a0) lightduer_dcs_router.c( 306):namespace: ai.dueros.device_interface.voice_input I (5496,tid:3ffde0a0) lightduer_dcs_router.c( 306):namespace: ai.duerodecentface.voice_oupu I (550tid:3ffde0a0litdr_d_rte.c( 306):namespace: ai.dueros.vi_ierce.spke_ctrler I (5508,d:fda0litdr_dcs_router.c( 306):nampa: .drodecentfacauo_ay I 77 AIORAPPER: duer_dcs_get_speaker_state E (6785) DUEROS: event: DUER_EVENT_STARTED I (6785) DUEROS: Dueros DUER_CMD_CONNECTED, duer_state:2 W (6792) DUEROS: duer_callback: type:0, source:0x3f80a51c data:3, data_len:0 W (5525,tid:3ffde0a0) lightduer_events.c( 81):[lightduer_ca] <== event end = 4011FA7C, timespent 88 I (554ti3fe0) ghuecoagt. 2):d sourcsuesul!! I (5550,tid:3ffde0a0) ghuecoagt. 2):add resource successfly!! W (5555idff0a ligduer_engine.c69:da chhanot sent, penng.,cae_n:, qcache_len: W (5563,tid:3ffde0a0) lightduer_system_info.c( 306):Undefined memory type, 0 E (5573,tid:3ffde0a0) lightduer_system_info.c( 389):Sys Info: Get disk info failed W (5583,tid:3ffde0a0) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len:2, qcache_len:4 W (5589,tid:3ffde0a0) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len: qche_len:3 W (5605,tid:3ffde0a0) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len:2, qcache_len:2 W (5610,tid:3ffde0a0) lightduer_engine.c( 697):data cache has not sent,enng.,cache_len:2, ac_len:1 I (5736,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: ThrowException E (5737,tid:3ffde0a0) lightduer_dcs_system.c( 314):error code:NVALIREESEXCEPTION E 74tid:fda0lightercs_st.c(15err:idproduct not eis I (5750,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: ThrowException E 75tid:3ffde0a0) lightduer_dcs_system.c( 4)rror code: INVALID_REQUEST_EXCEPTION E (5758,tid:3ffde0a0) lightduer_dcs_system.c( 315):error: didp product not exsists I (5773,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: DialogueFinished I (5779,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: DialogueFinished W (5805,tid:3ffde0a0) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len:2, qcache_len:2 W (5811,tid:3ffde0a0) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len:2, qcache_len:1 I (17830) DUEROS: rec_engine_cb - AUDIO_REC_WAKEUP_START I (17831) DUEROS: rec_engine_cb - Play tone I (17831) ESP_AUDIO_CTRL: Enter play procuresr0m (136ESAUO_RLPl pcere,RLs , c:0 (839) ESP_AUDICT: qut_D_Que CM0,vaab:5,uex3e10m (144)SPUD_CL:un_cl_ayLi:7, METol:1849Bys,nt:135Bys,ra917 te I (17844) ESP_AUDIO_TASK: It's a decoder I (17855) ESP_AUDIO_TASK: 1.CUR IN:[IN_file],CODEC:[DEC_wav],RESAMPLE:[48000],OUT:[OUT_iis],rate:0,ch:0,pos:0 I (17866) ESP_AUDIO_TASK: 2.Handles,IN:0x3f81b9e8,CODEC:0x3f81c2ec,FILTER:0x3f8407a0,OUT:0x3f81c990 I (17875) ESP_AUDIO_TASK: 2.2 Update all pipeline I (17880) ESP_AUDIO_TASK: 2.3 Linked new pipeline I (17886) AUDIO_PIPELINE: link el->rb, el:0x3f81b9e8, tag:IN_file, rb:0x3f840a3c I (17894) AUDIO_PIPELINE: link el->rb, el:0x3f81c2ec, tag:DEC_wav, rb:0x3f840a78 I (17902) AUDIO_PIPELINE: link el->rb, el:0x3f8407a0, tag:Audio_forge, rb:0x3f840ab4 I (17911) ESP_AUDIO_TASK: 3. Previous starting... I (18019) AUDIO_ELEMENT: [IN_file-0x3f81b9e8] Element task created I (18022) AUDIO_ELEMENT: [IN_file] AEL_MSG_CMD_RESUME,state:1 I (18038) AUDIO_THREAD: The DEC_wav task allocate stack on external memory I (18040) AUDIO_ELEMENT: [DEC_wav-0x3f81c2ec] Element task created I (18047) AUDIO_ELEMENT: [DEC_wav] AEL_MSG_CMD_RESUME,state:1 I (18054) ESP_AUDIO_TASK: Blocking play until received AEL_MSG_CMD_REPORT_MUSIC_INFO I (18096) FATFS_STREAM: File size: 12024 byte, file position: 0 I (18097) ESP_AUDIO_TASK: Recv Element[IN_file-0x3f81b9e8] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING I (18138) CODEC_ELEMENT_HELPER: The element is 0x3f81c2ec. The reserve data 2 is 0x0. I (18138) WAV_DECODER: a new song playing I (18141) ESP_AUDIO_TASK: Received muisc info then on play I (18147) ESP_AUDIO_TASK: On event play, status:UNKNOWN, 0 I (18153) AUDIO_THREAD: The Audio_forge task allocate stack on external memory I (18161) AUDIO_ELEMENT: [Audio_forge-0x3f8407a0] Element task created I (18168) AUDIO_ELEMENT: [Audio_forge] AEL_MSCMRESUME,state:[0 I (18174) AUD_FGE: audio_forge opened0m I (18174) AUDIO_ELEMENT: [OUT_iis-0x3f81c990] Element task created I (18180) AUDIOOR: dio_rge reopen I (18185) AUDIO_ELEMENT: [OUT_iis] AEL_MSG_CMD_RESUME,state:1 I (18195) I2S_STREAM: AUDIO_STREAM_WRITER I (200) ESP_AUDIO_CTRL: itlay ocur ret:0 I (18200) ESP_AUDIO_TASK: Recv Element[DEC_wav-0x3f81c2ec] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING I (18205) ESP_AUDIO_CTRL: Sync play waiting ... I (18216) ESP_AUDIO_TASK: Recv Element[Audio_forge-0x3f8407a0] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING I (18233) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f81c990] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING I (18244) ESP_AUDIO_TASK: ESP_AUDIO status is AEL_STATUS_STATE_RUNNING, 1, src:0, is_stopping:0 I (18253) ESP_AUDIO_TASK: Func:media_ctrl_task, Line:984, MEM Total:3947279 Bytes, Inter:117879 Bytes, Dram:82107 Bytes

W (18517) FATFS_STREAM: No more data, ret:0 I (18517) AUDIO_ELEMENT: IN-[IN_file] AEL_IO_DONE,0 I (18517) AUDIO_ELEMENT: IN-[DEC_wav] AEL_IO_DONE,-2 I (18522) DEC_WAV: Closed I (18526) ESP_AUDIO_TASK: Received last pos: 11918 bytes I (18532) ESP_AUDIO_TASK: Recv Element[DEC_wav-0x3f81c2ec] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED I (18616) ESP_AUDIO_TASK: Recv Element[IN_file-0x3f81b9e8] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED I (18702) AUDIO_ELEMENT: IN-[Audio_forge] AEL_IO_DONE,-2 I (18702) AUDIO_FORGE: audio forge closed I (18703) ESP_AUDIO_TASK: Recv Element[Audio_forge-0x3f8407a0] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED I (18756) AUDIO_ELEMENT: IN-[OUT_iis] AEL_IO_DONE,-2 I (18794) ESP_AUDIO_TASK: Received last time: 362 ms I (18794) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f81c990] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_FINISHED I (18800) ESP_AUDIO_TASK: ESP_AUDIO status is AEL_STATUS_STATE_FINISHED, 1, src:0, is_stopping:0 I (18810) ESP_AUDIO_TASK: Func:media_ctrl_task, Line:984, MEM Total:3973479 Bytes, Inter:117963 Bytes, Dram:82191 Bytes

W (18821) ESP_AUDIO_TASK: Destroy the old pipeline, FINISHED W (18873) ESP_AUDIO_TASK: The old pipeline destroyed, FINISHED I (18873) ESP_AUDIO_CTRL: Sync play done I (19450) DUEROS: rec_engine_cb - AUDIO_REC_VAD_START I (19450) DUEROS: Recv Que DUER_CMD_START I (19452) AUDIO_WRAPPER: duer_dcs_get_speaker_state I (18193,tid:3ffc8f) ghuedcs_lal.c( 197):Cuendiogd:1b000000c40bcc007110003 W (19463) DUEROS: duer_callbac: type:0, source:0x3f80a51c data:4, data_len:0 I (18260,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: ThrowException E (18260,tid:3ffde0a0) lightduer_dcs_system.c( 314):error code: INTERNAL_SERVICE_EXCEPTION E (18264,tid:3ffde0a0) lightduer_dcs_system.c( 315):error: didp product not exsists I (18603,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: ThrowException E (18603,tid:3ffde0a0) lightduer_dcs_system.c( 314):error code: INTERNAL_SERVICE_EXCEPTION E (18609,tid:3ffde0a0) lightduer_dcs_system.c( 315):error: didp product not exsists I (18888,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: ThrowException E (18888,tid:3ffde0a0) lightduer_dcs_system.c( 314):error code: INTERNAL_SERVICE_EXCEPTION E (18892,tid:3ffde0a0) lightduer_dcs_system.c( 315):error: didp product not exsists I (19178,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: ThrowException E (19178,tid:3ffde0a0) lightduer_dcs_system.c( 314):error code: INTERNAL_SERVICE_EXCEPTION E (19184,tid:3ffde0a0) lightduer_dcs_system.c( 315):error: didp product not exsists I (19470,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: ThrowException E (19470,tid:3ffde0a0) lightduer_dcs_system.c( 34)rr code: INTERNAL_SERVICE_EXCEPTION E (19474,tid:3ffde0a0) lightduer_dcs_system.c( 315):error: didp product not exsists I (19768,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: ThrowException E (19768,tid:3ffde0a0) lightduer_dcs_system.c( 314):error code: INTERNAL_SERVICE_EXCEPTION E (19772,tid:3ffde0a0) lightduer_dcs_system.c( 315):error: didp product not exsists I (20106,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: ThrowException E (20106,tid:3ffde0a0) lightduer_dcs_system.c( 314):error code: INTERNAL_SERVICE_EXCEPTION E (20112,tid:3ffde0a0) lightduer_dcs_system.c( 315):error: didp product not exsists I (20346,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: ThrowException E (20346,tid:3ffde0a0) lightduer_dcs_system.c( 314):error code: INTERNAL_SERVICE_EXCEPTION E (20352,tid:3ffde0a0) lightduer_dcs_system.c( 315):error: didp product not exsists I (21761) DUEROS: rec_engine_cb - AUDIO_REC_VAD_STOP, state:4 I (21762) DUEROS: Dueros DUER_CMD_STOP W (21787) DUEROS: duer_callback: type:0, source:0x3f80a51c data:5, data_len:0 I (20615,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: ThrowException E (20615,tid:3ffde0a0) lightduer_dcs_system.c( 34)err deINLIREESEXPTN E 06,t:3fda0litdercs_syem( 5)rr: dproct t sis I (20625,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directe me DloeFisd I (20633,tid:3ffde0a0) lightduer_dcs_router.c( 460):Directive name: ThrowException E (20635,tid:3ffde0a0) lightduer_dcs_system.c( 314):error code: INTERNAL_SERVICE_EXCEPTION E (20643,tid:3ffde0a0) lightduer_dcs_system.c( 315):error: didp product not exsists W (20658,tid:3ffde0a0) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len:, qchele1 I (22662) DUEROS: rec_engine_cb - AUDIO_REC_WAKEUP_END

Beanv587 commented 2 years ago

唤醒前从5573开始出现了错误,唤醒时(17830)无任何错误,唤醒后(19450)比如说今天天气怎么样,过程中就不断出现异常

我把相关敏感信息已经用*处理

HengYongChao commented 2 years ago

Hi @Beanv587

17830 后面的异常是指？ 无法播放下发的音频吗？ 还指后面提示的错误吗？

E (19768,tid:3ffde0a0) lightduer_dcs_system.c( 314):error code: INTERNAL_SERVICE_EXCEPTION E (19772,tid:3ffde0a0) lightduer_dcs_system.c( 315):error: didp product not exsists`

这个是 dueros 库抛出的 内部服务异常，产品不存在？ 可能和你的 profile 有关，重新更换或者申请新的 profile ，再试试有无异常。

Beanv587 commented 2 years ago

didp product not exsists

@HengYongChao 看来确实是,百度当初给的20个Profile.当一个profile绑定了一个设备后就无法用新的Profile了.我换成当初老的Profile问题就解决.谢谢