esp-idf: BT A2DP sink doesn't handle AVRC commands during playback (IDFGH-4920)

• I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
• I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
• I have searched the issue tracker for a similar issue and not found a similar issue.

Environment

• Development Kit: ESP32-Wrover-Kit
• Kit version: v1 (?)
• Module or chip used: ESP32-WROOM-32D
• IDF version: v4.4-dev-473-gc49d03b8e
• Build System: idf.py
• Compiler version: xtensa-esp32-elf-gcc (crosstool-NG esp-2020r3) 8.4.0
• Operating System: macOS (Apple M1)
• Using an IDE?: VSCode, compiling and flashing over commandline (zsh)
• Power Supply: USB or External

Problem Description

I’m using the ESP as a Bluetooth A2DP Sink, like in the official example. Playback works fine. However, once a device is connected and playing audio back through the ESP no AVRC Commands, like absolute volume, from the Host/Source are neither executed nor logged (to the monitor). Only after the Audio Stream has been paused or suspended will all cued AVRC Commands be handled.

Expected Behavior

AVRC Commands should be handled during playback and printed to the monitor as soon as the arrive.

Actual Behavior

AVRC Commands are not executed during playback. But after the Audio Stream has been suspended.

Steps to reproduce

1. build, flash and monitor the official A2DP Sink example
2. Connect a BT Host Device
3. Start playing an Audio Stream
4. Change the Volume on the Host
5. Stop the Audio Stream

Code to reproduce this issue

Just the aforementioned Example.

Debug Logs

>>> Startup above, Host Device is connected
I (11074) BT_AV: ESP_BT_GAP_MODE_CHG_EVT mode:2
I (16224) BT_AV: ESP_BT_GAP_MODE_CHG_EVT mode:0
I (16244) BT_LOG: bta_av_link_role_ok hndl:x41 role:1 conn_audio:x1 bits:1 features:x824b

W (16244) BT_APPL: new conn_srvc id:19, app_id:1
I (16244) BT_AV: A2DP audio state: Started
I (16344) RCCT: AVRC event notification: 1
I (16344) BT_AV: Playback status changed: 0x1
>>> At this point the Audio Stream has started and I'm changing Volume
I (18894) BT_AV: Audio packet count 100
I (17824) RCTG: Volume is set locally to: 48%
I (21224) BT_AV: Audio packet count 200
I (23544) BT_AV: Audio packet count 300
I (25864) BT_AV: Audio packet count 400
I (27824) RCTG: Volume is set locally to: 52%
I (28184) BT_AV: Audio packet count 500
>>> I've now stopped the Audio Stream, the following output appears instantly
I (28264) RCTG: AVRC set absolute volume: 38%
I (28264) RCTG: Volume is set by remote controller 38%

I (28264) RCTG: AVRC set absolute volume: 32%
I (28264) RCTG: Volume is set by remote controller 32%

...

I (28304) RCTG: AVRC set absolute volume: 7%
I (28314) RCTG: Volume is set by remote controller 7%

I (28314) RCCT: AVRC event notification: 1
I (28324) BT_AV: Playback status changed: 0x2
I (28334) BT_AV: A2DP audio state: Suspended
I (28334) RCTG: AVRC register event notification: 13, param: 0x0

>>> These Volume changes reflect my input accurately, however way too late

Thing I’ve tried

I’ve used two different Source Devices (an Iphone and a Macbook). Both of which have delivered the same results.

When commenting out line ./main/bt_app_core.c:128

i2s_write(0, data, item_size, &bytes_written, portMAX_DELAY);

The AVRC events work as expected.

By measuring this line’s execution time by saving calls to esp_timer_get_time() before and after the line and printing the difference I’ve received a nominal time of around 23ms. With a packet size of 4096 Stereo Samples, we get 4096 / 2 = 2048 Samples per channel per function call. At fs = 44100Hz this is equal to 2048 * (1/44100Hz) = 46.44ms per Channel. Thus the function call takes only half the amount of time as our audio samples represent. I don’t think i2s_write is too slow to handle the ammount of data nor should it block any AVRC events from being handled.

When changing the portMAX_DELAY of the i2s_write to something like pdMS_TO_TICKS(10) the AVRC events work again in real time, however the audio is now choppy, since not all samples are pushed out.