pipeline_bt_sink AVRC cannot be enabled. (AUD-2715)

[iloop2020]

Hi,

We are running the demo "esp-adf/examples/player/pipeline_bt_sink" on "ESP32-Lyrat-Mini V1.2" board, We found that, the AVRC cannot be enabled.

here is IDF and ADF information: ADF: commit:542954aa5a532befc8036536adb2ddb18cc03db2(HEAD -> master, origin/master, origin/HEAD) IDF: commit:382fa9072d9f3013a43577d526c9a5141a7019eb(HEAD, origin/release/v4.1)

Here is the console log with some key messages. W (1376) BT_BTC: A2DP Enable without AVRC W (1556) BT_BTC: AVRC Controller is expected to be initialized in advance of A2DP !!!

boot: ESP-IDF v4.1-629-g382fa9072 2nd stage bootloader I (12) boot: compile time 00:15:20 I (12) boot: chip revision: 1 I (15) boot_comm: chip revision: 1, min. bootloader chip revision: 0 I (22) boot.esp32: SPI Speed : 40MHz I (27) boot.esp32: SPI Mode : DIO I (31) boot.esp32: SPI Flash Size : 8MB

How we compile the demo

1. idf.py menuconfig
2. Select Audio HAL to "ESP32-Lyrat-Mini V1.1"
3. idf.py build
4. idf.py flash monitor.

Please help. Thank you.

[HengYongChao]

Hi @iloop2020 I use ADF: (390ef2918271572237f7ff4028d0e542b68fb707), IDF: (9778b163b174b1e4702cf354e9a26d98c511fd6c). Examples/player/pipeline_bt_sink works good for me. Please try it.

I (10) boot: ESP-IDF v4.1-beta1-182-g9778b163b 2nd stage bootloader
I (10) boot: compile time 16:23:34
I (10) boot: chip revision: 1
I (13) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (20) qio_mode: Enabling default flash chip QIO
I (25) boot.esp32: SPI Speed      : 80MHz
I (30) boot.esp32: SPI Mode       : QIO
I (35) boot.esp32: SPI Flash Size : 4MB
I (39) boot: Enabling RNG early entropy source...
I (45) boot: Partition Table:
I (48) boot: ## Label            Usage          Type ST Offset   Length
I (55) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (63) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (70) boot:  2 factory          factory app      00 00 00010000 00124f80
I (78) boot: End of partition table
I (82) boot_comm: chip revision: 1, min. application chip revision: 0
I (89) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x2c530 (181552) map
I (152) esp_image: segment 1: paddr=0x0003c558 vaddr=0x3ffbdb60 size=0x034b0 ( 13488) load
I (156) esp_image: segment 2: paddr=0x0003fa10 vaddr=0x40080000 size=0x00404 (  1028) load
0x40080000: _WindowOverflow4 at /workshop/audio/esp-idfs/esp-idf-release_v4.1/components/freertos/xtensa_vectors.S:1778

I (159) esp_image: segment 3: paddr=0x0003fe1c vaddr=0x40080404 size=0x001fc (   508) load
I (167) esp_image: segment 4: paddr=0x00040020 vaddr=0x400d0020 size=0xaaa40 (698944) map
0x400d0020: _stext at ??:?

I (382) esp_image: segment 5: paddr=0x000eaa68 vaddr=0x40080600 size=0x14a04 ( 84484) load
I (423) boot: Loaded app from partition at offset 0x10000
I (423) boot: Disabling RNG early entropy source...
I (423) cpu_start: Pro cpu up.
I (427) cpu_start: Application information:
I (432) cpu_start: Project name:     play_bt_music
I (437) cpu_start: App version:      v2.2-50-g390ef291-dirty
I (444) cpu_start: Compile time:     Jan 19 2021 16:23:27
I (450) cpu_start: ELF file SHA256:  7dc41a1914e5784b...
I (456) cpu_start: ESP-IDF:          v4.1-beta1-182-g9778b163b
I (462) cpu_start: Starting app cpu, entry point is 0x400813dc
0x400813dc: call_start_cpu1 at /workshop/audio/esp-idfs/esp-idf-release_v4.1/components/esp32/cpu_start.c:275

I (0) cpu_start: App cpu up.
I (472) heap_init: Initializing. RAM available for dynamic allocation:
I (479) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (485) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (492) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (498) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM
I (504) heap_init: At 3FFCF4E0 len 00010B20 (66 KiB): DRAM
I (510) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (516) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (523) heap_init: At 40095004 len 0000AFFC (43 KiB): IRAM
I (529) cpu_start: Pro cpu start user code
I (546) spi_flash: detected chip: gd
I (546) spi_flash: flash io: qio
W (546) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
I (557) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (591) BLUETOOTH_EXAMPLE: [ 1 ] Create Bluetooth service
I (591) BTDM_INIT: BT controller compile version [1ee1530]
I (601) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (721) phy: phy_version: 4180, cb3948e, Sep 12 2019, 16:39:13, 0, 0
I (1281) BLUETOOTH_EXAMPLE: [ 2 ] Start codec chip
I (1301) DRV8311: ES8311 in Slave mode
I (1321) gpio: GPIO[21]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
W (1321) I2C_BUS: i2c_bus_create:57: I2C bus has been already created, [port:0]
I (1331) AUDIO_HAL: Codec mode is 2, Ctrl:1
I (1331) BLUETOOTH_EXAMPLE: [ 3 ] Create audio pipeline for playback
I (1341) BLUETOOTH_EXAMPLE: [3.1] Create i2s stream to write data to codec chip
I (1341) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3
I (1351) I2S: DMA Malloc info, datalen=blocksize=1200, dma_buf_count=3
I (1381) I2S: APLL: Req RATE: 44100, real rate: 44099.988, BITS: 16, CLKM: 1, BCK_M: 8, MCLK: 11289597.000, SCLK: 1411199.625000, diva: 1, divb: 0
I (1381) LYRAT_MINI_V1_1: I2S0, MCLK output by GPIO0
I (1391) BLUETOOTH_EXAMPLE: [3.2] Get Bluetooth stream
I (1391) BLUETOOTH_EXAMPLE: [3.2] Register all elements to audio pipeline
I (1401) BLUETOOTH_EXAMPLE: [3.3] Link it together [Bluetooth]-->bt_stream_reader-->i2s_stream_writer-->[codec_chip]
I (1411) AUDIO_PIPELINE: link el->rb, el:0x3ffd8340, tag:bt, rb:0x3ffd8654
I (1421) BLUETOOTH_EXAMPLE: [ 4 ] Initialize peripherals
I (1431) BLUETOOTH_EXAMPLE: [4.1] Initialize Touch peripheral
I (1431) BLUETOOTH_EXAMPLE: [4.2] Create Bluetooth peripheral
I (1441) BLUETOOTH_EXAMPLE: [4.2] Start all peripherals
I (1451) BLUETOOTH_EXAMPLE: [ 5 ] Set up  event listener
I (1451) BLUETOOTH_EXAMPLE: [5.1] Listening event from all elements of pipeline
I (1461) BLUETOOTH_EXAMPLE: [5.2] Listening event from peripherals
I (1471) BLUETOOTH_EXAMPLE: [ 6 ] Start audio_pipeline
I (1471) AUDIO_ELEMENT: [bt-0x3ffd8340] Element task created
I (1481) AUDIO_ELEMENT: [i2s-0x3ffd6754] Element task created
I (1481) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:359, MEM Total:136092 Bytes

I (1491) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_RESUME,state:1
I (1501) I2S_STREAM: AUDIO_STREAM_WRITER
I (1501) AUDIO_PIPELINE: Pipeline started
I (1511) BLUETOOTH_EXAMPLE: [ 7 ] Listen for all pipeline events
E (44261) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
I (44371) BLUETOOTH_EXAMPLE: [ * ] Receive music info from Bluetooth, sample_rates=44100, bits=16, ch=2
I (44391) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_PAUSE
I (44421) I2S: APLL: Req RATE: 44100, real rate: 44099.988, BITS: 16, CLKM: 1, BCK_M: 8, MCLK: 11289597.000, SCLK: 1411199.625000, diva: 1, divb: 0
I (44421) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_RESUME,state:4
I (44431) I2S_STREAM: AUDIO_STREAM_WRITER
W (44841) BT_APPL: new conn_srvc id:19, app_id:0
E (44851) BLUETOOTH_EXAMPLE: [ * ] Action command error: src_type:1048585, source:0x3ffdc95c cmd:1, data:0x0, data_len:0
I (66751) BT_LOG: bta_av_link_role_ok hndl:x41 role:1 conn_audio:x1 bits:1 features:x824b

W (66751) BT_APPL: new conn_srvc id:19, app_id:1

Done

[iloop2020]

Hi @HengYongChao

Thank you for your support, we tested your suggest ADF and IDF version, it works fine on "ESP32-Lyrat-Mini V1.2" board".

I think the ADF is new but the suggested IDF is a not up to day(5/2020), is there any reason why we need to use old version ?

Can you help to verify the new IDF, for example Tag v4.1 or v4.2, release/v4.1, release/v4.2 ?

Thank you. Best Regards, Leo

[HengYongChao]

Hi @HengYongChao

Thank you for your support, we tested your suggest ADF and IDF version, it works fine on "ESP32-Lyrat-Mini V1.2" board".

I think the ADF is new but the suggested IDF is a not up to day(5/2020), is there any reason why we need to use old version ?

Can you help to verify the new IDF, for example Tag v4.1 or v4.2, release/v4.1, release/v4.2 ?

Thank you. Best Regards, Leo

Hi @iloop2020 ,

I have tried the following IDF versions compile with adf pipeline bt sink example, they are work fine, please update your error logs.

Board: lyrat mini v1.2 adf :ebf07df81c idf release/v4.2 :8f20b9dc8a

Board: lyrat mini v1.2 adf :ebf07df81c idf release/v4.1 :9778b163b1

[expresspotato]

Same issue here, compile the pipeline_a2dp_sink_and_hfp example from esp-adf and the buttons do not work with a LyraT 4.3 version board. They are read but no AVRCP command's are sent.

Early on you'll see:

W (1472) BT_BTC: A2DP Enable without AVRC then... W (1722) BT_BTC: AVRC Controller is expected to be initialized in advance of A2DP !!!

[HengYongChao]

Same issue here, compile the pipeline_a2dp_sink_and_hfp example from esp-adf and the buttons do not work with a LyraT 4.3 version board. They are read but no AVRCP command's are sent.

Early on you'll see:

W (1472) BT_BTC: A2DP Enable without AVRC then... W (1722) BT_BTC: AVRC Controller is expected to be initialized in advance of A2DP !!!

Hi @expresspotato

What is the version information of your idf and adf? Have you tested the version I mentioned above?

[gijsn]

Im having the same issue, but using a different example (pipeline_a2dp_sink_stream) Using the builtin esp-idf of the esp-adf, the AVRCP works (but I cannot get volume up/down, which is vital in my application). When updating the builtin esp-idf submodule to origin/release/v4.1, including its submodules, the AVRC no longer works, though the buttons still get recognized

[expresspotato]

Same issue here, compile the pipeline_a2dp_sink_and_hfp example from esp-adf and the buttons do not work with a LyraT 4.3 version board. They are read but no AVRCP command's are sent. Early on you'll see: W (1472) BT_BTC: A2DP Enable without AVRC then... W (1722) BT_BTC: AVRC Controller is expected to be initialized in advance of A2DP !!!

Hi @expresspotato

What is the version information of your idf and adf? Have you tested the version I mentioned above?

esp-adf: At commit you suggested, all the way back from: Mon Jan 18 09:58:34 2021 +0800 HEAD detached at 390ef29

esp-idf: The one included in esp-adf at this revision, all the way back from: Wed May 6 16:18:51 2020 +0800 HEAD detached at 722043f73

Still does not work. Pressing a touch button on the LyraT 4.3 reveals:

E (26294) BLUETOOTH_EXAMPLE: [ * ] Action command error: src_type:1048578, source:0x3ffdf254 cmd:1, data:0x9, data_len:0

A little concerning the fix is to go way back out of date... I was hoping these examples would work with relatively recent releases of esp-adf (2.2) and esp-idf (4.2), doesn't compile on 4.3.

There shouldn't be releases without the examples being updated to work.