Closed ypiotrp closed 3 years ago
Thanks for the very detailed report and sorry for the inconvenience, we will look into.
Hi @ypiotrp ,
Thanks for your analysis. And we also find that some device has the buffer size as 60 and some other define it as 120. My colleague has made some changes to the HFP AG module. I will inform him to give you a patch ASAP.
Hope it wroks. Thanks
Hi @ypiotrp
Please try this fix_ag_buf.zip on v4.2. Thanks
Hi @Alvin1Zhang and @Wth-Esp
Thank you for your fast response. Today I tested the example with the newest IDF v.4.2 with your patch. First of all the HFP AG example does not build because of the warnings -Warray-bounds in btc_hf_ag.c
. in several functions the local variable idx
can be set to -1 if the btc_hf_idx_by_bdaddr()
failes. Next it is used as an index in eg. hf_local_param
array which causes Core dump and reboot. To get it working I first turned off the -Werror=all compilation flag but as I said it ended up with Core Dump which is not surprising. Then I made an security check after setting the idx variable. In case it is set to -1 the function is exited with error return value. It helped for the Core Dump but the issue still exists. The effect now is that I can't connect audio with the connected HFP device.
To reproduce it you just have to turn audio on and off several times. Will there be a time when the HFP AG example will simply work?
Hi @ypiotrp
I didn't face the building warning as yours. As for the original issue, we will test 60 bytes CVSD. And update fix ASAP.
Thanks
Hi @ypiotrp
Please try this hfp_patch.zip on v4.2-rc. Thanks
Hi @munho-espressif,
I applied your patch. After the configuration I mentioned in "Steps to reproduce" and building the example and trying to connect audio to the device ESP32 dumped core. I present the log below. Have you made any progress on the issue so far? Log:
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:4
load:0x3fff0034,len:7324
load:0x40078000,len:13212
ho 0 tail 12 room 4
load:0x40080400,len:4568
0x40080400: _init at ??:?
entry 0x400806f4
I (30) boot: ESP-IDF v4.2-rc-1-g4ea2679ad8-dirty 2nd stage bootloader
I (30) boot: compile time 13:03:56
I (31) boot: chip revision: 1
I (35) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (42) boot.esp32: SPI Speed : 40MHz
I (46) boot.esp32: SPI Mode : DIO
I (51) boot.esp32: SPI Flash Size : 2MB
I (55) boot: Enabling RNG early entropy source...
I (61) boot: Partition Table:
I (64) boot: ## Label Usage Type ST Offset Length
I (72) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (79) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (87) boot: 2 factory factory app 00 00 00010000 00100000
I (94) boot: End of partition table
I (98) boot_comm: chip revision: 1, min. application chip revision: 0
I (105) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1b23c (111164) map
I (157) esp_image: segment 1: paddr=0x0002b264 vaddr=0x3ffbdb60 size=0x03518 ( 13592) load
I (163) esp_image: segment 2: paddr=0x0002e784 vaddr=0x40080000 size=0x00404 ( 1028) load
0x40080000: _WindowOverflow4 at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/freertos/xtensa/xtensa_vectors.S:1730
I (164) esp_image: segment 3: paddr=0x0002eb90 vaddr=0x40080404 size=0x01488 ( 5256) load
I (175) esp_image: segment 4: paddr=0x00030020 vaddr=0x400d0020 size=0x6fc60 (457824) map
0x400d0020: _stext at ??:?
I (356) esp_image: segment 5: paddr=0x0009fc88 vaddr=0x4008188c size=0x146bc ( 83644) load
0x4008188c: start_cpu0_default at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/esp32/cpu_start.c:486
I (404) boot: Loaded app from partition at offset 0x10000
I (405) boot: Disabling RNG early entropy source...
I (405) cpu_start: Pro cpu up.
I (409) cpu_start: Application information:
I (413) cpu_start: Project name: hfp_ag
I (418) cpu_start: App version: 1
I (423) cpu_start: Compile time: Jan 4 2021 13:17:06
I (429) cpu_start: ELF file SHA256: cbbe88d3e6984bf9...
I (435) cpu_start: ESP-IDF: v4.2-rc-1-g4ea2679ad8-dirty
I (441) cpu_start: Starting app cpu, entry point is 0x40081904
0x40081904: call_start_cpu1 at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/esp32/cpu_start.c:287
I (0) cpu_start: App cpu up.
I (452) heap_init: Initializing. RAM available for dynamic allocation:
I (459) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (465) heap_init: At 3FFB6BF8 len 00001408 (5 KiB): DRAM
I (471) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (477) heap_init: At 3FFCA208 len 00015DF8 (87 KiB): DRAM
I (483) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (490) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (496) heap_init: At 40095F48 len 0000A0B8 (40 KiB): IRAM
I (502) cpu_start: Pro cpu start user code
I (521) spi_flash: detected chip: generic
I (521) spi_flash: flash io: dio
W (521) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (532) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (565) BTDM_INIT: BT controller compile version [3723d5b]
I (565) system_api: Base MAC address is not set
I (565) system_api: read default base MAC address from EFUSE
I (665) phy: phy_version: 4500, 0cd6843, Sep 17 2020, 15:37:07, 0, 0
E (1265) BT_BTC: btc_I (1275) uart: queue free spaces: 8
########################################################################
HFP AG command usage manual
HFP AG commands begins with "hf" and end with ";"
I (1275) gpio: GPIO[5]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
Supported commands are as follows, arguments are embraced with < and >
hf con; -- set up connection with peer device
hf dis; -- disconnection with peer device
hf cona; -- set up audio connection with peer device
hf disa; -- release audio connection with peer device
hf vron; -- start voice recognition
hf vroff; -- stop voice recognition
hf vu <tgt> <vol>; -- volume update
tgt: 0-speaker, 1-microphone
vol: volume gain ranges from 0 to 15
hf ind <call> <ntk> <callsetup> <sig>; -- unsolicited indication device status to HF Client
call: call status [0,1]
callsetup: call setup status [0,3]
ntk: network status [0,1]
sig: signal strength value from 0~5
hf ate <rep> <err>; -- send extended at error code
rep: response code from 0 to 7
err: error code from 0 to 32
hf iron; -- in-band ring tone provided
hf iroff; -- in-band ring tone not provided
hf ac; -- Answer Incoming Call from AG
hf rc; -- Reject Incoming Call from AG
hf d <num>; -- Dial Number by AG, e.g. hf d 11223344
hf end; -- End up a call by AG
hf h; -- to see the command for HFP AG
########################################################################
I (1415) gpio: GPIO[25]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1425) gpio: GPIO[26]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1435) gpio: GPIO[35]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1435) gpio: GPIO[19]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1445) gpio: GPIO[21]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1455) gpio: GPIO[22]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
E (3585) CNSL: Command [hf con;]
Connect.
W (6215) BT_APPL: new conn_srvc id:5, app_id:0
I (6215) BT_APP_HF: APP HFP event: CONNECTION_STATE_EVT
I (6215) BT_APP_HF: --connection state CONNECTED, peer feats 0x0, chld_feats 0x0
I (6385) BT_APP_HF: APP HFP event: CIND_RESPONSE_EVT
I (6385) BT_APP_HF: --CIND Start.
I (6425) BT_APP_HF: APP HFP event: CONNECTION_STATE_EVT
I (6435) BT_APP_HF: --connection state SLC_CONNECTED, peer feats 0xbf, chld_feats 0x4010
I (6465) BT_APP_HF: APP HFP event: NREC_RESPONSE_EVT
I (6465) BT_APP_HF: --NREC status is: NREC DISABLE.
I (6505) BT_APP_HF: APP HFP event: VOLUME_CONTROL_EVT
I (6505) BT_APP_HF: --Volume Target: SPEAKER, Volume 10
I (6615) BT_APP_HF: APP HFP event: CLCC_RESPONSE_EVT
I (6615) BT_APP_HF: --Calling Line Identification.
I (6695) BT_APP_HF: APP HFP event: UNKNOW_AT_CMD
I (6695) BT_APP_HF: --UNKOW AT CMD: +CSRSF=0,0,0,1,0,0,2
E (37575) CNSL: Command [hf cona;]
Connect Audio
W (37575) BT_BTM: BTM Remote does not support 2-EDR eSCO
W (37575) BT_BTM: BTM Remote does not support 3-EDR eSCO
I (37585) BT_APP_HF: APP HFP event: AUDIO_STATE_EVT
I (37585) BT_APP_HF: --Audio State connecting
E (38175) BT_BTM: btm_sco_connected, handle 181
I (38175) BT_APP_HF: APP HFP event: AUDIO_STATE_EVT
I (38175) BT_APP_HF: --Audio State connected
W (38185) BT_APPL: bta_ag_sco_read_cback: status(2)
vhci.c 172
Guru Meditation Error: Core 0 panic'ed (Interrupt wdt timeout on CPU0).
Core 0 register dump:
PC : 0x400895f9 PS : 0x00060634 A0 : 0x80106c94 A1 : 0x3ffbe290
0x400895f9: vhci_recv at ??:?
A2 : 0x00000002 A3 : 0x00000000 A4 : 0x40017620 A5 : 0x3ffb8140
A6 : 0x3ffcc0c0 A7 : 0x3ffbea20 A8 : 0x800895f9 A9 : 0x3ffbe200
A10 : 0x0000000b A11 : 0x0000000b A12 : 0x0000000c A13 : 0xffffffff
A14 : 0x00000000 A15 : 0xfffffffc SAR : 0x00000004 EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000 LBEG : 0x4000c349 LEND : 0x4000c36b LCOUNT : 0xffffffff
Core 0 was running in ISR context:
EPC1 : 0x4013fb2b EPC2 : 0x00000000 EPC3 : 0x00000000 EPC4 : 0x400895f9
0x4013fb2b: uart_hal_write_txfifo at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/soc/src/hal/uart_hal_iram.c:35
0x400895f9: vhci_recv at ??:?
Backtrace:0x400895f6:0x3ffbe290 0x40106c91:0x3ffbe2b0 0x400174f1:0x3ffbe2d0 0x40017707:0x3ffbe2f0 0x4008959a:0x3ffbe320 0x40089779:0x3ffbe340 0x40106c63:0x3ffbe360 0x40089790:0x3ffbe380 0x40082909:0x3ffbe3a0 0x40082dce:0x3ffce360 0x40089541:0x3ffce380 0x4011533d:0x3ffce3a0 0x400d5738:0x3ffce3c0 0x400f3ed5:0x3ffce3e0 0x400d9c11:0x3ffce410 0x400da975:0x3ffce430 0x400d9e55:0x3ffce460 0x400ed3ab:0x3ffce480 0x400d9f56:0x3ffce4a0 0x400edc44:0x3ffce4c0 0x4008fae5:0x3ffce4e0
0x400895f6: vhci_recv at ??:?
0x40106c91: r_eif_recv at ??:?
0x4008959a: vhci_recv_end at vhci.c:?
0x40089779: r_vhci_isr at ??:?
0x40106c63: r_eif_isr at ??:?
0x40089790: r_eif_isr_wrapper at intc.c:?
0x40082909: _xt_lowint1 at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/freertos/xtensa/xtensa_vectors.S:1105
0x40082dce: cause_sw_intr_to_core_wrapper at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/bt/controller/bt.c:769
0x40089541: vhci_set_interrupt at vhci.c:?
0x4011533d: API_vhci_host_send_packet at ??:?
0x400d5738: esp_vhci_host_send_packet at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/bt/controller/bt.c:1008
0x400f3ed5: transmit_data at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/bt/host/bluedroid/hci/hci_hal_h4.c:159
0x400d9c11: transmit_fragment at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/bt/host/bluedroid/hci/hci_layer.c:338
0x400da975: fragment_and_dispatch at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/bt/host/bluedroid/hci/packet_fragmenter.c:81
0x400d9e55: event_packet_ready at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/bt/host/bluedroid/hci/hci_layer.c:329
0x400ed3ab: fixed_queue_process at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/bt/common/osi/fixed_queue.c:254
0x400d9f56: hci_host_thread_handler at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/bt/host/bluedroid/hci/hci_layer.c:223
0x400edc44: osi_thread_run at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/bt/common/osi/thread.c:68
0x4008fae5: vPortTaskWrapper at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/freertos/xtensa/port.c:143
Core 1 register dump:
PC : 0x4013e75a PS : 0x00060634 A0 : 0x800d3f86 A1 : 0x3ffbccb0
0x4013e75a: esp_pm_impl_waiti at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/esp32/pm_esp32.c:486
A2 : 0x00000000 A3 : 0x00000000 A4 : 0x00000001 A5 : 0x80000001
A6 : 0x00000003 A7 : 0x00060023 A8 : 0x800d3eda A9 : 0x3ffbcc80
A10 : 0x00000000 A11 : 0x00060623 A12 : 0x00060620 A13 : 0x00060623
A14 : 0x00000001 A15 : 0x00000000 SAR : 0x00000000 EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000 LBEG : 0x00000000 LEND : 0x00000000 LCOUNT : 0x00000000
Backtrace:0x4013e757:0x3ffbccb0 0x400d3f83:0x3ffbccd0 0x40090471:0x3ffbccf0 0x4008fae5:0x3ffbcd10
0x4013e757: esp_pm_impl_waiti at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/esp32/pm_esp32.c:484
0x400d3f83: esp_vApplicationIdleHook at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/esp_common/src/freertos_hooks.c:63
0x40090471: prvIdleTask at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/freertos/tasks.c:3386 (discriminator 1)
0x4008fae5: vPortTaskWrapper at C:/Users/partyka/Documents/projects/device/esp32/esp-idf/components/freertos/xtensa/port.c:143
Hi @ypiotrp Please try this hfp_ag.zip
on v4.2-rc. Thanks
Thanks @munho-espressif
I think we can close this issue because the main problem here (size of outgoing buffer) has been solved. I still have problem with HFP-AG example not running stable. I will create a new issue. By the way I saw in this comment you are planning to improve the audio applications. Can you tell me more about it? Is there any deadline for that. It it is important for me because I want to create my product using ESP32 and HFP AG.
Regards, Piotr
@ypiotrp Thanks for reporting and updates, good to know the main problem has been resolved, please create another ticket for the new issue, will close this ticket now.
Environment
Problem Description
After applying the patch from #4967 on ESP-IDF v4.1 the link between ESP32 and the HFP headset started to work. My project is based on HFP-AG example from the ESP-IDF. I use HCI as a SCO data path, turned off WBS and I changed the
BR/EDR Sync(SCO/eSCO) Max Connections to 1
. Unfortunately after changing the headset for a different model it seems like memory allocated for thep_buf
buffer submitted tobt_app_hf_outgoing_cb(uint8_t *p_buf, uint32_t sz)
function is less thansz
.The ESP-IDF rev 4.2-rc doesn't need the patch.
Expected Behavior
Audio data being seemlessly transferred to the HFP Client device.
Actual Behavior
Using other device after the first call to
bt_app_hf_outgoing_cb
I got core dump. After analysys I made some changes in the ESP_IDF functions. The changes are presesnt in the patch I added as a attachment to this issue. If the value ofsz
inbt_app_hf_outgoing_cb
is equeal to 120 the the example should work. When I connected to a different device withsz
equeal to 60 the system crashed.Steps to reproduce
idf.py menuconfig
and:menuconfig
.app_hf_msg_set.c
uncomment line 16 and provide the Bluetooth address of the device you want to connect with.hf con;
andhf cona;
commands in UART interface.Code to reproduce this issue
Just original HFP-AG example. I attached my temporary fix as a git patch file.
Debug Logs