Resample examples not working

[aristarchos]

Hi,
Trying to use the resample examples in esp-adf but they do not behave as expected.
Environment esp-adf is v2.4.1 (same results seen with esp-adf master)
There are three audio devkits here, the
ESP32-LyraT
ESP32-LyraT-Mini
ESP32-S2-Kaluga-1
Tested with all of them and problems exist in all.

Can someone verify that the esp-adf resample examples do work ok or not?
eg the:
audio_processing/pipeline_resample
audio_processing/pipeline_spiffs_amr_resample

Am I missing something obvious here?

Here is the output from ESP32-LyraT-Mini

Code: [Select all] [Expand/Collapse]

1. ets Jun  8 2016 00:22:57
2.  
3. rst:0x1 (POWERON_RESET),boot:0x1b (SPI_FAST_FLASH_BOOT)
4. flash read err, 1000
5. ets_main.c 371
6. ets Jun  8 2016 00:22:57
7.  
8. rst:0x10 (RTCWDT_RTC_RESET),boot:0x1b (SPI_FAST_FLASH_BOOT)
9. configsip: 0, SPIWP:0xee
10. clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
11. mode:DIO, clock div:2
12. load:0x3fff0030,len:6676
13. load:0x40078000,len:14848
14. ho 0 tail 12 room 4
15. load:0x40080400,len:3792
16. 0x40080400: _init at ??:?
17.  
18. entry 0x40080694
19. I (29) boot: ESP-IDF v4.4.2-155-g23d5a582cb 2nd stage bootloader
20. I (29) boot: compile time 12:54:11
21. I (29) boot: chip revision: 1
22. I (33) boot_comm: chip revision: 1, min. bootloader chip revision: 0
23. I (40) boot.esp32: SPI Speed      : 40MHz
24. I (45) boot.esp32: SPI Mode       : DIO
25. I (50) boot.esp32: SPI Flash Size : 2MB
26. I (54) boot: Enabling RNG early entropy source...
27. I (60) boot: Partition Table:
28. I (63) boot: ## Label            Usage          Type ST Offset   Length
29. I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
30. I (78) boot:  1 phy_init         RF data          01 01 0000f000 00001000
31. I (85) boot:  2 factory          factory app      00 00 00010000 00100000
32. I (93) boot:  3 storage          Unknown data     01 82 00110000 000f0000
33. I (100) boot: End of partition table
34. I (105) boot_comm: chip revision: 1, min. application chip revision: 0
35. I (112) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=1e89ch (125084) map
36. I (166) esp_image: segment 1: paddr=0002e8c4 vaddr=3ffb0000 size=01754h (  5972) load
37. I (168) esp_image: segment 2: paddr=00030020 vaddr=400d0020 size=47aach (293548) map
38. I (278) esp_image: segment 3: paddr=00077ad4 vaddr=3ffb1754 size=00cc0h (  3264) load
39. I (279) esp_image: segment 4: paddr=0007879c vaddr=40080000 size=0e23ch ( 57916) load
40. I (307) esp_image: segment 5: paddr=000869e0 vaddr=50000000 size=00010h (    16) load
41. I (314) boot: Loaded app from partition at offset 0x10000
42. I (314) boot: Disabling RNG early entropy source...
43. I (327) cpu_start: Pro cpu up.
44. I (328) cpu_start: Starting app cpu, entry point is 0x400812b8
45. 0x400812b8: call_start_cpu1 at /home/aristarchos/Espressif/framework/esp-adf-v2.4.1/esp-idf/components/esp_system/port/cpu_start.c:148
46.  
47. I (0) cpu_start: App cpu up.
48. I (342) cpu_start: Pro cpu start user code
49. I (342) cpu_start: cpu freq: 160000000
50. I (342) cpu_start: Application information:
51. I (346) cpu_start: Project name:     spiffs_amr_resample_app
52. I (352) cpu_start: App version:      1
53. I (357) cpu_start: Compile time:     Oct  8 2022 13:04:13
54. I (363) cpu_start: ELF file SHA256:  247f5235cf37ecba...
55. I (369) cpu_start: ESP-IDF:          v4.4.2-155-g23d5a582cb
56. I (376) heap_init: Initializing. RAM available for dynamic allocation:
57. I (383) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
58. I (389) heap_init: At 3FFB2E90 len 0002D170 (180 KiB): DRAM
59. I (395) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
60. I (401) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
61. I (408) heap_init: At 4008E23C len 00011DC4 (71 KiB): IRAM
62. I (415) spi_flash: detected chip: gd
63. I (418) spi_flash: flash io: dio
64. W (422) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
65. I (436) cpu_start: Starting scheduler on PRO CPU.
66. I (0) cpu_start: Starting scheduler on APP CPU.
67. I (685) PERIPH_SPIFFS: Partition size: total: 896321, used: 4518
68. W (715) I2C_BUS: i2c_bus_create:58: I2C bus has been already created, [port:0]
69. I (725) SPIFFS_AMR_RESAMPLE_EXAMPLE: [1.1] Initialize recorder pipeline
70. I (725) SPIFFS_AMR_RESAMPLE_EXAMPLE: [1.2] Create audio elements for recorder pipeline
71. I (735) SPIFFS_AMR_RESAMPLE_EXAMPLE: [1.3] Register audio elements to recorder pipeline
72. I (745) SPIFFS_AMR_RESAMPLE_EXAMPLE: [2.2] Create audio elements for playback pipeline
73. I (755) SPIFFS_AMR_RESAMPLE_EXAMPLE: [2.3] Register audio elements to playback pipeline
74. I (755) SPIFFS_AMR_RESAMPLE_EXAMPLE: [ 3 ] Set up  event listener
75. E (10735) SPIFFS_AMR_RESAMPLE_EXAMPLE: STOP playback and START recording
76. W (10735) AUDIO_PIPELINE: Without stop, st:1
77. W (10735) AUDIO_PIPELINE: Without wait stop, st:1
78. I (10735) SPIFFS_AMR_RESAMPLE_EXAMPLE: Link audio elements to make recorder pipeline ready
79. I (10745) SPIFFS_AMR_RESAMPLE_EXAMPLE: Setup file path to save recorded audio
80. I (15645) SPIFFS_AMR_RESAMPLE_EXAMPLE: STOP recording and START playback
81. W (15645) AUDIO_ELEMENT: IN-[filter_downsample] AEL_IO_ABORT
82. E (15645) AUDIO_ELEMENT: [filter_downsample] Element already stopped
83. W (15655) AUDIO_ELEMENT: IN-[file_writer] AEL_IO_ABORT
84. W (15665) AUDIO_ELEMENT: IN-[amrnb_encoder] AEL_IO_ABORT
85. I (15675) SPIFFS_AMR_RESAMPLE_EXAMPLE: Link audio elements to make playback pipeline ready
86. I (15675) SPIFFS_AMR_RESAMPLE_EXAMPLE: Setup file path to read the amr audio to play
87. W (15695) SPIFFS_STREAM: No more data, ret:0
88. E (15715) FIR_RESAMPLE: failed to allocate p_out buffer.size 196608 line 2010
89. E (15715) RSP_FILTER: Failed to create the resample handler
90. E (15715) AUDIO_ELEMENT: [filter_upsample] AEL_STATUS_ERROR_OPEN,-1
91. W (15725) AUDIO_ELEMENT: [filter_upsample] audio_element_on_cmd_error,7
92. W (15735) AUDIO_ELEMENT: OUT-[amr_decoder] AEL_IO_ABORT
93. W (15735) AMR_DECODER: output aborted -3
94. W (15745) AUDIO_ELEMENT: IN-[i2s_writer] AEL_IO_ABORT

GeSHi © Codebox Plus Extension

[tempo.tian]

Seems there is not enough memory.

E (15715) FIR_RESAMPLE: failed to allocate p_out buffer.size 196608 line 2010

Please try to enable PSRAM, after enabled adf module will try to use PSRAM firstly.
Menuconfig -> Component Config -> esp32 specific --> support for external, SPI-connected RAM

[aristarchos]

Hi,

Changed the sdkconfig setting as instructed, now the memory issue is ok though a new issue came up regarding channels.
to remind you, this is the =untouched= pipeline_resample example, it is verbatim without any change from me, just as it comes from esp-adf github repository.
Specifically this is the new error
E (10254) FIR_RESAMPLE: in encode mode, src_ch and dest_ch should be same, here src_ch = 2 : dest_ch = 1.
E (10264) RSP_FILTER: Failed to create the resample handler

Following is the complete log

ets Jun 8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
flash read err, 1000
ets_main.c 371
I (13) boot: ESP-IDF v4.4.2-155-g23d5a582cb 2nd stage bootloader
I (13) boot: compile time 12:02:57
I (13) boot: chip revision: 1
I (16) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (23) boot.esp32: SPI Speed : 40MHz
I (27) boot.esp32: SPI Mode : DIO
I (32) boot.esp32: SPI Flash Size : 2MB
I (37) boot: Enabling RNG early entropy source...
I (42) boot: Partition Table:
I (45) boot: ## Label Usage Type ST Offset Length
I (53) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (60) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (68) boot: 2 factory factory app 00 00 00010000 00100000
I (75) boot: End of partition table
I (79) boot_comm: chip revision: 1, min. application chip revision: 0
I (86) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=17dd0h ( 97744) map
I (130) esp_image: segment 1: paddr=00027df8 vaddr=3ffb0000 size=02728h ( 10024) load
I (135) esp_image: segment 2: paddr=0002a528 vaddr=40080000 size=05af0h ( 23280) load
I (146) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=3e920h (256288) map
I (239) esp_image: segment 4: paddr=0006e948 vaddr=40085af0 size=0f698h ( 63128) load
I (265) esp_image: segment 5: paddr=0007dfe8 vaddr=50000000 size=00010h ( 16) load
I (275) boot: Loaded app from partition at offset 0x10000
I (275) boot: Disabling RNG early entropy source...
I (287) psram: This chip is ESP32-D0WD
I (289) spiram: Found 64MBit SPI RAM device
I (290) spiram: SPI RAM mode: flash 40m sram 40m
I (293) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (300) cpu_start: Pro cpu up.
I (304) cpu_start: Starting app cpu, entry point is 0x400816bc
0x400816bc: call_start_cpu1 at /home/aristarchos/Espressif/framework/esp-adf-v2.4.1/esp-idf/components/esp_system/port/cpu_start.c:148

I (0) cpu_start: App cpu up.
I (1195) spiram: SPI SRAM memory test OK
I (1203) cpu_start: Pro cpu start user code
I (1203) cpu_start: cpu freq: 160000000
I (1203) cpu_start: Application information:
I (1206) cpu_start: Project name: resample_app
I (1211) cpu_start: App version: 1
I (1216) cpu_start: Compile time: Oct 11 2022 12:02:51
I (1222) cpu_start: ELF file SHA256: b52355d41769c2b5...
I (1228) cpu_start: ESP-IDF: v4.4.2-155-g23d5a582cb
I (1235) heap_init: Initializing. RAM available for dynamic allocation:
I (1242) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1248) heap_init: At 3FFB32B8 len 0002CD48 (179 KiB): DRAM
I (1254) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1260) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1267) heap_init: At 40095188 len 0000AE78 (43 KiB): IRAM
I (1274) spiram: Adding pool of 4095K of external SPI memory to heap allocator
I (1283) spi_flash: detected chip: gd
I (1286) spi_flash: flash io: dio
W (1290) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (1304) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1314) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations
W (1844) I2C_BUS: i2c_bus_create:58: I2C bus has been already created, [port:0]
I (1864) RESAMPLE_EXAMPLE: [1.1] Initialize recorder pipeline
I (1864) RESAMPLE_EXAMPLE: [1.2] Create audio elements for recorder pipeline
I (1864) RESAMPLE_EXAMPLE: [1.3] Register audio elements to recorder pipeline
I (1874) RESAMPLE_EXAMPLE: [2.2] Create audio elements for playback pipeline
I (1884) RESAMPLE_EXAMPLE: [2.3] Register audio elements to playback pipeline
I (1884) RESAMPLE_EXAMPLE: [ 3 ] Set up event listener
<Here user press "Rec" for 3 seconds>
E (10234) RESAMPLE_EXAMPLE: STOP Playback and START [Record]
W (10234) AUDIO_PIPELINE: Without stop, st:1
W (10234) AUDIO_PIPELINE: Without wait stop, st:1
I (10234) RESAMPLE_EXAMPLE: Link audio elements to make recorder pipeline ready
I (10244) RESAMPLE_EXAMPLE: Setup file path to save recorded audio
E (10254) FIR_RESAMPLE: in encode mode, src_ch and dest_ch should be same, here src_ch = 2 : dest_ch = 1.
E (10264) RSP_FILTER: Failed to create the resample handler
E (10264) AUDIO_ELEMENT: [filter_downsample] AEL_STATUS_ERROR_OPEN,-1
W (10274) AUDIO_ELEMENT: [filter_downsample] audio_element_on_cmd_error,7
W (10284) AUDIO_ELEMENT: IN-[wav_encoder] AEL_IO_ABORT
W (10294) AUDIO_ELEMENT: OUT-[i2s_reader] AEL_IO_ABORT
W (10294) AUDIO_ELEMENT: OUT-[i2s_reader] AEL_IO_ABORT
W (10294) AUDIO_ELEMENT: OUT-[i2s_reader] AEL_IO_ABORT
W (10304) AUDIO_ELEMENT: OUT-[i2s_reader] AEL_IO_ABORT
<Here user release "Rec">
I (16774) RESAMPLE_EXAMPLE: STOP [Record] and START Playback
E (16774) AUDIO_ELEMENT: [i2s_reader] Element already stopped
E (16774) AUDIO_ELEMENT: [filter_downsample] Element already stopped
E (16774) AUDIO_ELEMENT: [wav_encoder] Element already stopped
W (16784) AUDIO_ELEMENT: IN-[file_writer] AEL_IO_ABORT
I (16794) RESAMPLE_EXAMPLE: Link audio elements to make playback pipeline ready
I (16804) RESAMPLE_EXAMPLE: Setup file path to read the wav audio to play
W (16874) FATFS_STREAM: No more data, ret:0

As seen the error, I tried to chnage the example source file resample_example.c in only one line (40) from
#define SAVE_FILE_CHANNEL 1
to
#define SAVE_FILE_CHANNEL 2

After making this change in github example's code, rebuild and run again, now there is no such error, but again there in nothing heard in the output when I release "Rec" or press "Play". (I assume that the on-board microphone of LyraT-Mini is used)
Upon inspection of the produced "REC.WAV" file on the microSD card, it is a few Kb and some seconds of silence, no audio recorded from on-board mic.

Here is the output from the changed (from 1 to 2) channels in "#define SAVE_FILE_CHANNEL"

ets Jun 8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
flash read err, 1000
ets_main.c 371
I (13) boot: ESP-IDF v4.4.2-155-g23d5a582cb 2nd stage bootloader
I (13) boot: compile time 12:02:57
I (13) boot: chip revision: 1
I (16) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (23) boot.esp32: SPI Speed : 40MHz
I (27) boot.esp32: SPI Mode : DIO
I (32) boot.esp32: SPI Flash Size : 2MB
I (37) boot: Enabling RNG early entropy source...
I (42) boot: Partition Table:
I (45) boot: ## Label Usage Type ST Offset Length
I (53) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (60) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (68) boot: 2 factory factory app 00 00 00010000 00100000
I (75) boot: End of partition table
I (79) boot_comm: chip revision: 1, min. application chip revision: 0
I (86) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=17dd0h ( 97744) map
I (130) esp_image: segment 1: paddr=00027df8 vaddr=3ffb0000 size=02728h ( 10024) load
I (135) esp_image: segment 2: paddr=0002a528 vaddr=40080000 size=05af0h ( 23280) load
I (146) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=3e920h (256288) map
I (239) esp_image: segment 4: paddr=0006e948 vaddr=40085af0 size=0f698h ( 63128) load
I (265) esp_image: segment 5: paddr=0007dfe8 vaddr=50000000 size=00010h ( 16) load
I (275) boot: Loaded app from partition at offset 0x10000
I (275) boot: Disabling RNG early entropy source...
I (287) psram: This chip is ESP32-D0WD
I (289) spiram: Found 64MBit SPI RAM device
I (290) spiram: SPI RAM mode: flash 40m sram 40m
I (293) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (300) cpu_start: Pro cpu up.
I (304) cpu_start: Starting app cpu, entry point is 0x400816bc
0x400816bc: call_start_cpu1 at /home/aristarchos/Espressif/framework/esp-adf-v2.4.1/esp-idf/components/esp_system/port/cpu_start.c:148

I (0) cpu_start: App cpu up.
I (1195) spiram: SPI SRAM memory test OK
I (1203) cpu_start: Pro cpu start user code
I (1203) cpu_start: cpu freq: 160000000
I (1203) cpu_start: Application information:
I (1206) cpu_start: Project name: resample_app
I (1211) cpu_start: App version: 1
I (1216) cpu_start: Compile time: Oct 11 2022 12:02:51
I (1222) cpu_start: ELF file SHA256: b944c02526127262...
I (1228) cpu_start: ESP-IDF: v4.4.2-155-g23d5a582cb
I (1235) heap_init: Initializing. RAM available for dynamic allocation:
I (1242) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1248) heap_init: At 3FFB32B8 len 0002CD48 (179 KiB): DRAM
I (1254) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1260) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1267) heap_init: At 40095188 len 0000AE78 (43 KiB): IRAM
I (1274) spiram: Adding pool of 4095K of external SPI memory to heap allocator
I (1283) spi_flash: detected chip: gd
I (1286) spi_flash: flash io: dio
W (1290) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (1304) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1314) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations
W (1844) I2C_BUS: i2c_bus_create:58: I2C bus has been already created, [port:0]
I (1864) RESAMPLE_EXAMPLE: [1.1] Initialize recorder pipeline
I (1864) RESAMPLE_EXAMPLE: [1.2] Create audio elements for recorder pipeline
I (1864) RESAMPLE_EXAMPLE: [1.3] Register audio elements to recorder pipeline
I (1874) RESAMPLE_EXAMPLE: [2.2] Create audio elements for playback pipeline
I (1884) RESAMPLE_EXAMPLE: [2.3] Register audio elements to playback pipeline
I (1884) RESAMPLE_EXAMPLE: [ 3 ] Set up event listener
<Here user press "Rec" for 3 seconds>
E (12774) RESAMPLE_EXAMPLE: STOP Playback and START [Record]
W (12774) AUDIO_PIPELINE: Without stop, st:1
W (12774) AUDIO_PIPELINE: Without wait stop, st:1
I (12774) RESAMPLE_EXAMPLE: Link audio elements to make recorder pipeline ready
I (12784) RESAMPLE_EXAMPLE: Setup file path to save recorded audio
<Here user release "Rec">
I (16134) RESAMPLE_EXAMPLE: STOP [Record] and START Playback
W (16164) AUDIO_ELEMENT: IN-[filter_downsample] AEL_IO_ABORT
E (16164) AUDIO_ELEMENT: [filter_downsample] Element already stopped
W (16174) AUDIO_ELEMENT: IN-[file_writer] AEL_IO_ABORT
W (16174) AUDIO_ELEMENT: IN-[wav_encoder] AEL_IO_ABORT
I (16194) RESAMPLE_EXAMPLE: Link audio elements to make playback pipeline ready
I (16194) RESAMPLE_EXAMPLE: Setup file path to read the wav audio to play
W (19284) FATFS_STREAM: No more data, ret:0