esp-adf
esp-adf copied to clipboard
Dueros demo error: AUDIO_EVT: There is no space in external queue (AUD-3818)
I ran Dueros' Demo, and there was no response to the voice interaction step. When I manually clicked the Rec button, it would report warn: W (661493) AUDIO_EVT: There is no space in external queue
.
Development board: ESP32-Lyrat-Mini V1.2
ADF version: release/v2.4
IDF version: release/v4.4
Build on: MacOS 12
Full log:
--- idf_monitor on /dev/cu.SLAB_USBtoUART 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
I (10) boot: ESP-IDF v4.4.1-91-g36823b45cc-dirty 2nd stage bootloader
I (10) boot: compile time 01:00:42
I (11) boot: chip revision: 3
I (14) boot_comm: chip revision: 3, min. bootloader chip revision: 0
I (21) qio_mode: Enabling default flash chip QIO
I (26) boot.esp32: SPI Speed : 80MHz
I (31) boot.esp32: SPI Mode : QIO
I (35) boot.esp32: SPI Flash Size : 4MB
I (40) boot: Enabling RNG early entropy source...
I (45) boot: Partition Table:
I (49) boot: ## Label Usage Type ST Offset Length
I (56) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (64) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (71) boot: 2 factory factory app 00 00 00010000 00310000
I (79) boot: End of partition table
I (83) boot_comm: chip revision: 3, min. application chip revision: 0
I (90) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=6b7f8h (440312) map
I (220) esp_image: segment 1: paddr=0007b820 vaddr=3ffb0000 size=041f0h ( 16880) load
I (225) esp_image: segment 2: paddr=0007fa18 vaddr=40080000 size=00600h ( 1536) load
I (226) esp_image: segment 3: paddr=00080020 vaddr=400d0020 size=14c9f8h (1362424) map
I (610) esp_image: segment 4: paddr=001cca20 vaddr=40080600 size=16cb4h ( 93364) load
I (640) esp_image: segment 5: paddr=001e36dc vaddr=50000000 size=00010h ( 16) load
I (652) boot: Loaded app from partition at offset 0x10000
I (652) boot: Disabling RNG early entropy source...
I (663) psram: This chip is ESP32-D0WD
I (664) spiram: Found 64MBit SPI RAM device
I (664) spiram: SPI RAM mode: flash 80m sram 80m
I (669) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (676) cpu_start: Pro cpu up.
I (680) cpu_start: Starting app cpu, entry point is 0x4008163c
0x4008163c: call_start_cpu1 at /Users/Shared/SDK/esp/esp-idf/components/esp_system/port/cpu_start.c:160
I (0) cpu_start: App cpu up.
I (1161) spiram: SPI SRAM memory test OK
I (1170) cpu_start: Pro cpu start user code
I (1170) cpu_start: cpu freq: 240000000
I (1170) cpu_start: Application information:
I (1173) cpu_start: Project name: esp_dueros
I (1178) cpu_start: App version: v2.3-277-g4f84517-dirty
I (1184) cpu_start: Compile time: May 13 2022 01:01:29
I (1191) cpu_start: ELF file SHA256: 470c97f7785df1c6...
I (1197) cpu_start: ESP-IDF: v4.4.1-91-g36823b45cc-dirty
I (1204) heap_init: Initializing. RAM available for dynamic allocation:
I (1211) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1217) heap_init: At 3FFB7458 len 00028BA8 (162 KiB): DRAM
I (1223) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1230) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1236) heap_init: At 400972B4 len 00008D4C (35 KiB): IRAM
I (1243) spiram: Adding pool of 4084K of external SPI memory to heap allocator
I (1251) spi_flash: detected chip: gd
I (1255) spi_flash: flash io: qio
W (1259) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
I (1273) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1288) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (1327) DUEROS: ADF version is v2.3-277-g4f84517-dirty
I (1333) DRV8311: ES8311 in Slave mode
I (1344) gpio: GPIO[21]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
W (1389) I2C_BUS: i2c_bus_create:57: I2C bus has been already created, [port:0]
I (1392) gpio: GPIO[13]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1402) SDCARD: Using 1-line SD mode, 4-line SD mode, base path=/sdcard
I (1474) SDCARD: CID name ASTC!
E (1895) DISPATCHER: exe first list: 0x0
I (1896) DISPATCHER: dispatcher_event_task is running...
I (1899) AUDIO_THREAD: The wifi_serv task allocate stack on external memory
I (1905) wifi:wifi driver task: 3ffce72c, prio:23, stack:6656, core=0
I (1909) system_api: Base MAC address is not set
I (1914) system_api: read default base MAC address from EFUSE
I (1934) wifi:wifi firmware version: 63017e0
I (1934) wifi:wifi certification version: v7.0
I (1934) wifi:config NVS flash: enabled
I (1935) wifi:config nano formating: disabled
I (1939) wifi:Init data frame dynamic rx buffer num: 32
I (1944) wifi:Init management frame dynamic rx buffer num: 32
I (1949) wifi:Init management short buffer num: 32
I (1954) wifi:Init static tx buffer num: 16
I (1958) wifi:Init tx cache buffer num: 32
I (1962) wifi:Init static rx buffer size: 1600
I (1966) wifi:Init static rx buffer num: 16
I (1970) wifi:Init dynamic rx buffer num: 32
I (1975) wifi_init: rx ba win: 16
I (1978) wifi_init: tcpip mbox: 32
I (1982) wifi_init: udp mbox: 6
I (1985) wifi_init: tcp mbox: 6
I (1989) wifi_init: tcp tx win: 5744
I (1993) wifi_init: tcp rx win: 5744
I (1998) wifi_init: tcp mss: 1440
I (2002) wifi_init: WiFi/LWIP prefer SPIRAM
I (2007) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (2099) wifi:mode : sta (34:94:54:4c:1c:5c)
I (2099) wifi:enable tsf
I (1613,tid:3ffdebb8) lightduer_session.c( 44):random = 75933
W (2907) AUDIO_BOARD: The board has already been initialized!
I (2907) AUDIO_THREAD: The media_task task allocate stack on external memory
I (2911) WIFI_SERV: Connect to wifi ssid: Lanistor, pwd: 6688##**
I (2918) ESP_AUDIO_TASK: media_ctrl_task running...,0x3f81a6ec
----------------------------- ESP Audio Platform -----------------------------
| |
| ESP_AUDIO-v1.7.0-63-g2b9ee8e-bec4a56-4d51bc8 |
| Compile date: Feb 23 2022-02:43:28 |
------------------------------------------------------------------------------
I (2958) ESP_AUDIO_CTRL: Func:media_ctrl_create, Line:350, MEM Total:4209135 Bytes, Inter:185739 Bytes, Dram:151719 Bytes
I (2970) AUDIO_HAL: Codec mode is 3, Ctrl:1
I (2982) MP3_DECODER: MP3 init
I (2984) I2S: APLL expected frequency is 24576000 Hz, real frequency is 24575996 Hz
I (2987) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3
I (2994) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3
I (3002) I2S: I2S0, MCLK output by GPIO0
I (3006) LYRAT_MINI_V1_1: I2S0, MCLK output by GPIO0
I (3012) AUDIO_WRAPPER: Func:duer_audio_setup_player, Line:184, MEM Total:4199851 Bytes, Inter:170239 Bytes, Dram:136219 Bytes
I (3024) AUDIO_WRAPPER: esp_audio instance is:0x3f81a6ec
I (3031) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3
I (3037) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3
I (3045) I2S: I2S1, MCLK output by GPIO0
I (3049) LYRAT_MINI_V1_1: I2S1, MCLK output by GPIO0
I (3055) AUDIO_PIPELINE: link el->rb, el:0x3f81ca98, tag:i2s, rb:0x3f81cd24
I (3063) AUDIO_ELEMENT: [i2s-0x3f81ca98] Element task created
I (3069) AUDIO_ELEMENT: [raw-0x3f81cbc8] Element task created
I (3075) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:359, MEM Total:4186927 Bytes, Inter:157079 Bytes, Dram:123059 Bytes
I (3087) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_RESUME,state:1
I (3093) AUDIO_PIPELINE: Pipeline started
I (3098) 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 (3124) RECORDER_SR: Multinet is not enabled in SDKCONFIG
I (3128) AUDIO_THREAD: The feed_task task allocate stack on external memory
I (3136) AUDIO_THREAD: The fetch_task task allocate stack on external memory
I (3144) AUDIO_THREAD: The recorder_task task allocate stack on external memory
I (3152) AUDIO_THREAD: The voice_read_task task allocate stack on external memory
I (4013) wifi:new:<10,0>, old:<1,0>, ap:<255,255>, sta:<10,0>, prof:1
I (4772) wifi:state: init -> auth (b0)
I (4815) wifi:state: auth -> assoc (0)
I (4855) wifi:state: assoc -> run (10)
I (5008) wifi:connected with Lanistor, aid = 7, channel 10, BW20, bssid = 50:64:2b:0a:fc:e1
I (5009) wifi:security: WPA2-PSK, phy: bgn, rssi: -65
I (5011) wifi:pm start, type: 1
W (5017) WIFI_SERV: WiFi Event cb, Unhandle event_base:WIFI_EVENT, event_id:4
W (5072) wifi:<ba-add>idx:0 (ifx:0, 50:64:2b:0a:fc:e1), tid:0, ssn:2, winSize:64
I (5096) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (6329) esp_netif_handlers: sta ip: 192.168.31.141, mask: 255.255.255.0, gw: 192.168.31.1
I (6330) WIFI_SERV: Got ip:192.168.31.141
W (6333) WIFI_SERV: STATE type:2, pdata:0x0, len:0
I (6352) DUEROS: PERIPH_WIFI_CONNECTED [145]
E (6352) DUEROS: Recv Que DUER_CMD_LOGIN
I (6353) DUEROS: duer_start, len:1469
{"configures":"{}","bindToken":"xxx","coapPort":443,"token":"xxx","serverAddr":"device.iot.baidu.com","lwm2mPort":443,"uuid":"2208000000000a","rsaCaCrt":"-----BEGIN CERTIFICATE-----\nxxxxxx\n-----END CERTIFICATE-----\n","macId":"","version":15584}��?T
W (6483) DUEROS: duer_callback: type:0, source:0x3f80a434 data:2, data_len:0
I (5201,tid:3ffdebb8) lightduer_engine.c( 242):duer_engine_start, g_handler:3F81A5D4, length:1469, profile:3F83AC24
I (5219,tid:3ffdebb8) lightduer_ca_conf.c( 38): duer_conf_get_string: uuid = 2208000000000a
I (5226,tid:3ffdebb8) lightduer_ca_conf.c( 38): duer_conf_get_string: serverAddr = device.iot.baidu.com
I (5272,tid:3ffdebb8) baidu_ca_socket_adp.c( 139):DNS lookup succeeded. IP=110.242.69.142
I (5293,tid:3ffdebb8) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK)
W (5294,tid:3ffdebb8) lightduer_events.c( 81):[lightduer_ca] <== event end = 40128B58, timespent = 94
I (6080,tid:3ffdebb8) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK)
W (6080,tid:3ffdebb8) lightduer_events.c( 81):[lightduer_ca] <== event end = 40128D18, timespent = 740
I (6088,tid:3ffdebb8) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WULD_BLOCK)
I (6096,tid:3ffdebb8) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK)
I (6106,tid:3ffdebb8) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK)
I (6124,tid:3ffdebb8) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK)
I (6124,tid:3ffdebb8) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK)
I (6132,tid:3ffdebb8) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK)
I (6139,tid:3ffdebb8) lightduer_engine.c( 242):duer_engine_start, g_handler:3F81A5D4, length:0, profile:00000000
I (6151,tid:3ffdebb8) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK)
I (6162,tid:3ffdebb8) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK)
I (6167,tid:3ffdebb8) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK)
I (6176,tid:3ffdebb8) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK)
I (6184,tid:3ffdebb8) lightduer_connagent.c( 208):will start latter(DUER_ERR_TRANS_WOULD_BLOCK)
I (6894,tid:3ffdebb8) lightduer_voice.c( 915):Mutex initializing
I (6894,tid:3ffdebb8) lightduer_connagent.c( 189):connect started!
I (6895,tid:3ffdebb8) lightduer_ds_log_cache.c( 85):no cache report
E (8183) DUEROS: event: 0
I (8187) DUEROS: duer_dcs_init
I (6911,tid:3ffdebb8) lightduer_dcs_router.c( 306):namespace: ai.dueros.private.protocol
I (6916,tid:ffdebb8) lightduer_dcs_router.c( 306):namespace: ai.dueros.device_interface.screen_extended_card
I (6925,tid:3ffdebb8) lightduer_dcs_router.c( 306):namespace: ai.dueros.device_interface.screen
I (6934,tid:3ffdebb8) lightduer_dcs_router.c( 306):namespace: ai.dueros.device_interface.system
I (6942,tid:3ffdebb8) lightduer_dcs_router.c( 306):namespace: ai.dueros.device_interface.voice_input
I (6951,tid:3ffdebb8) lightduer_dcs_router.c( 306):namespace: ai.dueros.device_interface.voice_output
I (6961,tid:3ffdebb8) lightduer_dcs_router.c( 306):namespace: ai.dueros.device_interface.speaker_controller
I (6970,tid:3ffdebb8) lightduer_dcs_router.c( 306):namespace: ai.dueros.device_interface.audio_player
I (8261) AUDIO_WRAPPER: duer_dcs_get_speaker_state
E (8269) DUEROS: event: DUER_EVENT_STARTED
W (6988,tid:3ffdebb8) lightduer_events.c( 81):[lightduer_ca] <== event end = 40128D18, timespent = 99
I (6997,tid:3ffdebb8) lightduer_connagent.c( 222):add resource successfully!!
I (7005,tid:3ffdebb8) lightduer_connagent.c( 222):add resource successfully!!
I (8269) DUEROS: Dueros DUER_CMD_CONNECTED, duer_state:20m
W (7011,tid:3ffdebb8) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len:2, qcache_len:3
W (8300) DUEROS: duer_callback: type:0, source:0x3f80a434 data:3, data_len:0
W (7030,tid:3ffdebb8) lightduer_system_info.c( 306):Undefined memory type, 0
E (7042,tid:3ffdebb8) lightduer_system_info.c( 389):Sys Info: Get disk info failed
W (7059,tid:3ffdebb8) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len:2, qcache_len:4
W (7070,tid:3ffdebb8) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len:2, qcache_len:3
W (7080,tid:3ffdebb8) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len:2, qcache_len:2
W (7089,tid:3ffdebb8) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len:2, qcache_len:1
I (7894,tid:3ffdebb8) lightduer_dcs_router.c( 460):Directive name: ThrowException
E (7894,tid:3ffdebb8) lightduer_dcs_system.c( 314):error code: INVALID_REQUEST_EXCEPTION
E (7898,tid:3ffdebb8) lightduer_dcs_system.c( 315):error: didp product not exsists
I (7910,tid:3ffdebb8) lightduer_dcs_router.c( 460):Directive name: ThrowException
E (7914,tid:3ffdebb8) lightduer_dcs_system.c( 314):error code: INVALID_REQUEST_EXCEPTION
E (7921,tid:3ffdebb8) lightduer_dcs_system.c( 315):error: didp product not exsists
I (7935,tid:3ffdebb8) lightduer_dcs_router.c( 460):Directive name: DialogueFinished
W (7938,tid:3ffdebb8) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len:1, qcache_len:2
I (7955,tid:3ffdebb8) lightduer_dcs_router.c( 460):Directive name: DialogueFinished
W (7961,tid:3ffdebb8) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len:2, qcache_len:2
W (7975,tid:3ffdebb8) lightduer_engine.c( 697):data cache has not sent, pending..., dcache_len:2, qcache_len:1
W (33676) AUDIO_EVT: There is no space in external queue
W (36667) AUDIO_EVT: There is no space in external queue
W (38071) AUDIO_EVT: There is no space in external queue
W (43347) AUDIO_EVT: There is no space in external queue
I (43468) DUEROS: AUDIO_USER_KEY_VOL_UP [69]
W (43468) AUDIO_EVT: There is no space in external queue
W (47016) AUDIO_EVT: There is no space in external queue
W (48699) AUDIO_EVT: There is no space in external queue
Hi @lanistor
W (48699) AUDIO_EVT: There is no space in external queue
esp_err_t audio_event_iface_sendout(audio_event_iface_handle_t evt, audio_event_iface_msg_t *msg)
{
if (evt->external_queue) {
if (xQueueSend(evt->external_queue, (void *)msg, 0) != pdPASS) {
ESP_LOGW(TAG, "There is no space in external queue");
return ESP_FAIL;
}
}
return ESP_OK;
}
https://github.com/espressif/esp-adf/blob/master/components/audio_pipeline/audio_event_iface.c#L273
This means that your event receiving queue is full, you can see here AUDIO_EVENT_IFACE_DEFAULT_CFG. Even if you set it bigger, it will be stuffed again. The most important thing is to clear the event receiving queue.
Happened to me when setup of the listener was missing. I had to add
audio_event_iface_set_listener(esp_periph_set_get_event_iface(set), evt);
This topic has become inactive so I'm going to close the issue. Please reopen this if you have any questions or need any further assistance.