espradio commented 1 year ago

Answers checklist.

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

General issue report

I am trying the standard AD2P SOURCE program on ESP32. However, When trying to connect to a specific BT speaker it is NOT working.(It is not able staying A2DP connected state for more than 3 seconds) But it works on other BT speakers. Here is the full log. Branch: master


rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
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:7104
load:0x40078000,len:15660
load:0x40080400,len:4
load:0x40080404,len:3872
entry 0x40080648
I (29) boot: ESP-IDF v5.2-dev-544-g54576b7528-dirty 2nd stage bootloader
I (29) boot: compile time May 16 2023 18:40:08
I (32) boot: Multicore bootloader
I (36) boot: chip revision: v3.0
I (39) boot.esp32: SPI Speed      : 40MHz
I (44) boot.esp32: SPI Mode       : DIO
I (49) boot.esp32: SPI Flash Size : 2MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (69) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (84) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=2a9c4h (174532)                                                                                                                                                              map
I (168) esp_image: segment 1: paddr=0003a9ec vaddr=3ffbdb60 size=04570h ( 17776)                                                                                                                                                              load
I (175) esp_image: segment 2: paddr=0003ef64 vaddr=40080000 size=010b4h (  4276)                                                                                                                                                              load
I (177) esp_image: segment 3: paddr=00040020 vaddr=400d0020 size=a7450h (685136)                                                                                                                                                              map
I (429) esp_image: segment 4: paddr=000e7478 vaddr=400810b4 size=17454h ( 95316)                                                                                                                                                              load
I (481) boot: Loaded app from partition at offset 0x10000
I (481) boot: Disabling RNG early entropy source...
I (493) cpu_start: Multicore app
I (493) cpu_start: Pro cpu up.
I (493) cpu_start: Starting app cpu, entry point is 0x400812e0
I (0) cpu_start: App cpu up.
I (513) cpu_start: Pro cpu start user code
I (513) cpu_start: cpu freq: 160000000 Hz
I (513) cpu_start: Application information:
I (518) cpu_start: Project name:     a2dp_source
I (523) cpu_start: App version:      v5.2-dev-544-g54576b7528-dirty
I (530) cpu_start: Compile time:     May 16 2023 18:47:01
I (536) cpu_start: ELF file SHA256:  e39c137f72a7e95b...
I (542) cpu_start: ESP-IDF:          v5.2-dev-544-g54576b7528-dirty
I (549) cpu_start: Min chip rev:     v0.0
I (554) cpu_start: Max chip rev:     v3.99
I (559) cpu_start: Chip rev:         v3.0
I (564) heap_init: Initializing. RAM available for dynamic allocation:
I (571) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (577) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (583) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (589) heap_init: At 3FFCBC20 len 000143E0 (80 KiB): DRAM
I (595) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (602) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (608) heap_init: At 40098508 len 00007AF8 (30 KiB): IRAM
I (616) spi_flash: detected chip: gd
I (619) spi_flash: flash io: dio
W (622) spi_flash: Detected size(16384k) larger than the size in the binary imag                                                                                                                                                             e header(2048k). Using the size in the binary image header.
I (637) coexist: coex firmware version: ebddf30
I (642) app_start: Starting scheduler on CPU0
I (646) app_start: Starting scheduler on CPU1
I (646) main_task: Started on CPU0
I (656) main_task: Calling app_main()
I (676) BTDM_INIT: BT controller compile version [ad2b7cd]
I (676) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1386) BT_AV: Starting device discovery...
W (1386) BT_BTC: btc_avrc_tg_set_rn_supported_evt failed: AVRC TG not yet initia                                                                                                                                                             lized

W (1396) BT_BTC: A2DP Enable with AVRC
I (1406) BT_AV: bt_app_av_sm_hdlr state: 1, event: 0x4
I (1406) BT_AV: event: 10
I (1416) BT_AV: event: 10
I (1416) BT_AV: event: 10
I (1416) BT_AV: event: 10
I (1416) main_task: Returned from app_main()
I (1426) BT_AV: Discovery started.
I (11386) BT_AV: bt_app_av_sm_hdlr state: 1, event: 0xff00
I (12476) BT_AV: Scanned device: f8:23:45:44:23:43
I (12486) BT_AV: --Class of Device: 0x340408
I (12486) BT_AV: --RSSI: -45
I (12486) BT_AV: Found a target device, address f8:23:45:44:23:43, name BT_Car
I (12496) BT_AV: Cancel device discovery ...
I (12496) BT_AV: Device discovery stopped.
I (12506) BT_AV: a2dp connecting to peer: BT_Car
W (12506) BT_APPL: reset flags
I (12516) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
W (13056) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (13056) BT_AV: event: 16
I (21386) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (31386) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (41386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (41386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (43456) BT_L2CAP: L2CAP got sec_comp for unknown BD_ADDR

W (43456) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (43456) BT_APPL: bta_dm_act no entry for connected service cbs
W (43466) BT_BTC: BTA_AV_OPEN_EVT::FAILED status: 3

I (43466) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (51386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (51386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (51386) BT_APPL: reset flags
I (51396) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
W (51506) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (51506) BT_AV: event: 16
I (61386) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (71386) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (81386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (81386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (81916) BT_L2CAP: L2CAP got sec_comp for unknown BD_ADDR

W (81916) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (81916) BT_APPL: bta_dm_act no entry for connected service cbs
W (81926) BT_BTC: BTA_AV_OPEN_EVT::FAILED status: 3

I (81926) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (91386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (91386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (91386) BT_APPL: reset flags
I (91396) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
W (92626) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
W (92626) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 32000
I (92636) BT_AV: event: 16
W (92726) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
E (93456) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
W (93716) BT_APPL: new conn_srvc id:18, app_id:0
W (93716) BT_APPL: bta_dm_pm_ssr conn_srvc id:18, app_id:0
W (93716) BT_APPL: bta_dm_pm_ssr:2, lat:1200
I (93726) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (93726) BT_AV: a2dp connected
W (100396) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (100396) BT_APPL: bta_dm_act no entry for connected service cbs
W (100396) BT_AVCT: ccb 0 not allocated
E (100396) BT_APPL: bta_av_rc_create found duplicated handle:0
I (100406) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x0
E (100406) BT_BTC: handle_rc_connect Connect failed with error code: 2
I (100416) BT_AV: a2dp disconnected
I (101386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (101386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (101386) BT_APPL: reset flags
I (101396) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
W (102356) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (102356) BT_AV: event: 16
E (102406) BT_BTC: btc_initiate_av_open_tmr_hdlr No connected RC peers
I (111386) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (121386) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (131386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (131386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (132716) BT_L2CAP: L2CAP got sec_comp for unknown BD_ADDR

W (132716) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (132716) BT_APPL: bta_dm_act no entry for connected service cbs
W (132726) BT_BTC: BTA_AV_OPEN_EVT::FAILED status: 3

I (132726) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (141386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (141386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (141386) BT_APPL: reset flags
I (141396) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
W (142066) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (142066) BT_AV: event: 16
W (142396) BT_APPL: bta_dm_act no entry for connected service cbs
W (142396) BT_BTC: BTA_AV_OPEN_EVT::FAILED status: 3

I (142396) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
W (146396) BT_HCI: hci cmd send: disconnect: hdl 0x80, rsn:0x13
W (146466) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x16
I (151386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (151386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (151386) BT_APPL: reset flags
I (151396) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
W (152536) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
W (152536) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 32000
I (152536) BT_AV: event: 16
W (152606) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
E (153536) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
W (153786) BT_APPL: new conn_srvc id:18, app_id:0
W (153786) BT_APPL: bta_dm_pm_ssr conn_srvc id:18, app_id:0
W (153786) BT_APPL: bta_dm_pm_ssr:2, lat:1200
I (153796) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (153796) BT_AV: a2dp connected
W (160366) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (160366) BT_APPL: bta_dm_act no entry for connected service cbs
W (160366) BT_AVCT: ccb 0 not allocated
E (160376) BT_APPL: bta_av_rc_create found duplicated handle:0
I (160376) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x0
E (160376) BT_BTC: handle_rc_connect Connect failed with error code: 2
I (160386) BT_AV: a2dp disconnected
I (161386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (161386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (161386) BT_APPL: reset flags
I (161396) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
W (162246) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (162246) BT_AV: event: 16
E (162376) BT_BTC: btc_initiate_av_open_tmr_hdlr No connected RC peers
E (162566) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
W (162676) BT_APPL: new conn_srvc id:18, app_id:0
W (162676) BT_APPL: bta_dm_pm_ssr conn_srvc id:18, app_id:0
W (162676) BT_APPL: bta_dm_pm_ssr:2, lat:1200
I (162686) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (162686) BT_AV: a2dp connected
E (162896) BT_BTM: tBTM_SEC_DEV:0x3ffd35ac rs_disc_pending=0

W (162916) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
W (162936) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
W (168946) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (168946) BT_APPL: bta_dm_act no entry for connected service cbs
W (168946) BT_AVCT: ccb 0 not allocated
E (168946) BT_APPL: bta_av_rc_create found duplicated handle:0
I (168956) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x0
E (168956) BT_BTC: handle_rc_connect Connect failed with error code: 2
I (168966) BT_AV: a2dp disconnected
E (170956) BT_BTC: btc_initiate_av_open_tmr_hdlr No connected RC peers
I (171386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (171386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (171386) BT_APPL: reset flags
I (171396) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
W (172266) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (172266) BT_AV: event: 16
E (172606) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
W (172726) BT_APPL: new conn_srvc id:18, app_id:0
W (172726) BT_APPL: bta_dm_pm_ssr conn_srvc id:18, app_id:0
W (172726) BT_APPL: bta_dm_pm_ssr:2, lat:1200
I (172726) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (172736) BT_AV: a2dp connected
E (172946) BT_BTM: tBTM_SEC_DEV:0x3ffd35ac rs_disc_pending=0

W (172976) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
W (172986) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
W (179406) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (179406) BT_APPL: bta_dm_act no entry for connected service cbs
W (179406) BT_AVCT: ccb 0 not allocated
E (179406) BT_APPL: bta_av_rc_create found duplicated handle:0
I (179416) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x0
I (179426) BT_AV: a2dp disconnected
I (181386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (181386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (181386) BT_APPL: reset flags
I (181396) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
W (182566) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (182566) BT_AV: event: 16
E (182876) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
W (182986) BT_APPL: new conn_srvc id:18, app_id:0
W (182986) BT_APPL: bta_dm_pm_ssr conn_srvc id:18, app_id:0
W (182986) BT_APPL: bta_dm_pm_ssr:2, lat:1200
I (182996) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (182996) BT_AV: a2dp connected
E (183216) BT_BTM: tBTM_SEC_DEV:0x3ffd35ac rs_disc_pending=0

W (183246) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
W (183256) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
W (189746) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (189756) BT_APPL: bta_dm_act no entry for connected service cbs
W (189756) BT_AVCT: ccb 0 not allocated
E (189756) BT_APPL: bta_av_rc_create found duplicated handle:0
I (189766) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x0
E (189766) BT_BTC: handle_rc_connect Connect failed with error code: 2
I (189766) BT_AV: a2dp disconnected
I (191386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (191386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (191386) BT_APPL: reset flags
I (191396) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
W (191616) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (191626) BT_AV: event: 16
E (191766) BT_BTC: btc_initiate_av_open_tmr_hdlr No connected RC peers
E (191946) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
W (192056) BT_APPL: new conn_srvc id:18, app_id:0
W (192056) BT_APPL: bta_dm_pm_ssr conn_srvc id:18, app_id:0
W (192056) BT_APPL: bta_dm_pm_ssr:2, lat:1200
I (192066) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (192066) BT_AV: a2dp connected
E (192276) BT_BTM: tBTM_SEC_DEV:0x3ffd35ac rs_disc_pending=0

W (192306) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
W (192326) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
W (198246) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (198246) BT_APPL: bta_dm_act no entry for connected service cbs
W (198246) BT_AVCT: ccb 0 not allocated
E (198256) BT_APPL: bta_av_rc_create found duplicated handle:0
I (198256) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x0
I (198266) BT_AV: a2dp disconnected
I (201386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (201386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (201386) BT_APPL: reset flags
I (201396) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
W (201466) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (201476) BT_AV: event: 16
E (201776) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
W (201886) BT_APPL: new conn_srvc id:18, app_id:0
W (201886) BT_APPL: bta_dm_pm_ssr conn_srvc id:18, app_id:0
W (201886) BT_APPL: bta_dm_pm_ssr:2, lat:1200
I (201896) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (201896) BT_AV: a2dp connected
E (202096) BT_BTM: tBTM_SEC_DEV:0x3ffd35ac rs_disc_pending=0

W (202126) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
W (202146) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
W (208066) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (208066) BT_APPL: bta_dm_act no entry for connected service cbs
W (208066) BT_AVCT: ccb 0 not allocated
E (208066) BT_APPL: bta_av_rc_create found duplicated handle:0
I (208076) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x0
I (208086) BT_AV: a2dp disconnected
I (211386) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (211386) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (211386) BT_APPL: reset flags
I (211396) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0

espradio commented 1 year ago

@wmy-espressif Any thoughts?

shangke1112 commented 1 year ago

According to the log ,It seems that the connection was successful, but there was no data transmission within 5 seconds, causing a connection timeout. I think there may be some issues with the link layer, if you can tell us the model of the BT speaker so that we can try to reproduce it and check the package.

espradio commented 1 year ago

It is an BT android device found in car

shangke1112 commented 1 year ago

libbtdm.tar.gz I am sorry ,I can not find the device . Please use this lib for testing ,and send me the log.

espradio commented 1 year ago

Hi @shangke1112 Please find the log with debug image

ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
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:7132
ho 0 tail 12 room 4
load:0x40078000,len:15672
ho 0 tail 12 room 4
load:0x40080400,len:4
load:0x40080404,len:3884
entry 0x40080650
I (33) boot: ESP-IDF v5.2-dev-823-g903af13e84-dirty 2nd stage bootloader
I (33) boot: compile time May 28 2023 18:38:20
I (35) boot: Multicore bootloader
I (39) boot: chip revision: v3.0
I (43) boot.esp32: SPI Speed      : 40MHz
I (48) boot.esp32: SPI Mode       : DIO
I (52) boot.esp32: SPI Flash Size : 2MB
I (57) boot: Enabling RNG early entropy source...
I (62) boot: Partition Table:
I (66) boot: ## Label            Usage          Type ST Offset   Length
I (73) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (81) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (88) boot:  2 factory          factory app      00 00 00010000 00100000
I (96) boot: End of partition table
I (100) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=2a9d4h (174548)                                                                                                                                                              map
I (171) esp_image: segment 1: paddr=0003a9fc vaddr=3ffbdb60 size=04574h ( 17780)                                                                                                                                                              load
I (179) esp_image: segment 2: paddr=0003ef78 vaddr=40080000 size=010a0h (  4256)                                                                                                                                                              load
I (181) esp_image: segment 3: paddr=00040020 vaddr=400d0020 size=a754ch (685388)                                                                                                                                                              map
I (433) esp_image: segment 4: paddr=000e7574 vaddr=400810a0 size=173f8h ( 95224)                                                                                                                                                              load
I (485) boot: Loaded app from partition at offset 0x10000
I (485) boot: Disabling RNG early entropy source...
I (497) cpu_start: Multicore app
I (497) cpu_start: Pro cpu up.
I (497) cpu_start: Starting app cpu, entry point is 0x40081220
I (0) cpu_start: App cpu up.
I (517) cpu_start: Pro cpu start user code
I (517) cpu_start: cpu freq: 160000000 Hz
I (517) cpu_start: Application information:
I (522) cpu_start: Project name:     a2dp_source
I (527) cpu_start: App version:      v5.2-dev-823-g903af13e84-dirty
I (534) cpu_start: Compile time:     May 28 2023 18:38:15
I (540) cpu_start: ELF file SHA256:  16e39f079...
I (546) cpu_start: ESP-IDF:          v5.2-dev-823-g903af13e84-dirty
I (553) cpu_start: Min chip rev:     v0.0
I (557) cpu_start: Max chip rev:     v3.99
I (562) cpu_start: Chip rev:         v3.0
I (567) heap_init: Initializing. RAM available for dynamic allocation:
I (574) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (580) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (586) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (592) heap_init: At 3FFCBC30 len 000143D0 (80 KiB): DRAM
I (598) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (605) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (611) heap_init: At 40098498 len 00007B68 (30 KiB): IRAM
I (619) spi_flash: detected chip: gd
I (622) spi_flash: flash io: dio
W (626) spi_flash: Detected size(16384k) larger than the size in the binary imag                                                                                                                                                             e header(2048k). Using the size in the binary image header.
I (640) coexist: coex firmware version: ebddf30
I (645) app_start: Starting scheduler on CPU0
I (649) app_start: Starting scheduler on CPU1
I (649) main_task: Started on CPU0
I (659) main_task: Calling app_main()
I (679) BTDM_INIT: BT controller compile version [ad2b7cd]
set state id 2,state 0
set state id 0,state 0
set state id 6,state 127
set state id 262,state 127
set state id 518,state 127
set state id 774,state 127
set state id 1030,state 127
set state id 1286,state 127
set state id 1542,state 127
set state id 1798,state 127
set state id 2054,state 127
set state id 2310,state 127
set state id 5,state 0
set state id 8,state 0
I (709) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
set state id 0,state 0
set state id 0,state 0
set state id 5,state 0
W (1389) BT_BTC: btc_avrc_tg_set_rn_supported_evt failed: AVRC TG not yet initia                                                                                                                                                             lized

W (1399) BT_BTC: A2DP Enable with AVRC
I (1399) BT_AV: Starting device discovery...
I (1409) BT_AV: bt_app_av_sm_hdlr state: 1, event: 0x4
I (1409) BT_AV: event: 10
I (1419) BT_AV: event: 10
I (1419) BT_AV: event: 10
I (1419) main_task: Returned from app_main()
I (1429) BT_AV: Discovery started.
I (11399) BT_AV: bt_app_av_sm_hdlr state: 1, event: 0xff00
I (14229) BT_AV: Device discovery failed, continue to discover...
I (14239) BT_AV: Discovery started.
I (21399) BT_AV: bt_app_av_sm_hdlr state: 1, event: 0xff00
I (27039) BT_AV: Device discovery failed, continue to discover...
I (27049) BT_AV: Discovery started.
I (31399) BT_AV: bt_app_av_sm_hdlr state: 1, event: 0xff00
I (37389) BT_AV: Scanned device: f8:23:45:44:23:43
I (37389) BT_AV: --Class of Device: 0x340408
I (37389) BT_AV: --RSSI: -57
I (37399) BT_AV: Found a target device, address f8:23:45:44:23:43, name bt_Car
I (37399) BT_AV: Cancel device discovery ...
I (37409) BT_AV: Device discovery stopped.
I (37409) BT_AV: a2dp connecting to peer: bt_Car
W (37419) BT_APPL: reset flags
I (37429) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2
set state id 1,state 23
set state id 1,state 24
set state id 1,state 24
set state id 1,state 2
set state id 1,state 22
set state id 1,state 2
set state id 1,state 9
set state id 1,state 2
set state id 1,state 20
set state id 1,state 2
set state id 1,state 1
set state id 1,state 60
W (38459) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
set state id 1,state 14
I (38459) BT_AV: event: 16
set state id 1,state 1
set state id 1,state 8
set state id 1,state 1
set state id 1,state 21
set state id 1,state 1
set state id 1,state 24
set state id 1,state 1
set state id 1,state 24
set state id 1,state 1
set state id 1,state 1
set state id 1,state 36
set state id 1,state 61
set state id 1,state 63
set state id 1,state 15
set state id 1,state 16
set state id 1,state 64
set state id 1,state 65
set state id 1,state 99
set state id 1,state 68
set state id 1,state 70
set state id 1,state 69
set state id 1,state 71
I (38929) BT_AV: ESP_BT_GAP_CFM_REQ_EVT Please compare the numeric value: 765617
set state id 1,state 77
I (41399) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
set state id 1,state 76
set state id 1,state 39
set state id 1,state 35
set state id 1,state 40
set state id 1,state 1
set state id 1,state 93
set state id 1,state 1
set state id 1,state 41
set state id 1,state 42
set state id 1,state 44
I (43949) BT_AV: authentication success: bt_Car
I (43949) BT_AV: f8 23 45 44 23 43
set state id 1,state 1
E (44069) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
W (44239) BT_APPL: new conn_srvc id:18, app_id:0
W (44239) BT_APPL: bta_dm_pm_ssr conn_srvc id:18, app_id:0
W (44239) BT_APPL: bta_dm_pm_ssr:2, lat:1200
I (44249) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (44249) BT_AV: a2dp connected
set state id 1,state 0
W (51229) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (51229) BT_APPL: bta_dm_act no entry for connected service cbs
W (51239) BT_AVCT: ccb 0 not allocated
E (51239) BT_APPL: bta_av_rc_create found duplicated handle:0
I (51249) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x0
E (51249) BT_BTC: handle_rc_connect Connect failed with error code: 2
I (51249) BT_AV: a2dp disconnected
I (51399) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (51399) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (51399) BT_APPL: reset flags
I (51409) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2
set state id 1,state 23
set state id 1,state 24
set state id 1,state 24
set state id 1,state 2
set state id 1,state 22
set state id 1,state 2
set state id 1,state 9
set state id 1,state 2
set state id 1,state 20
set state id 1,state 2
set state id 1,state 1
set state id 1,state 60
W (52459) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
set state id 1,state 14
I (52469) BT_AV: event: 16
set state id 1,state 1
set state id 1,state 8
set state id 1,state 1
set state id 1,state 1
set state id 1,state 36
set state id 1,state 31
set state id 1,state 1
set state id 1,state 41
set state id 1,state 42
set state id 1,state 44
E (53249) BT_BTC: btc_initiate_av_open_tmr_hdlr No connected RC peers
I (61399) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (71399) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (81399) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (81399) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
set state id 1,state 25
set state id 1,state 27
set state id 1,state 0
W (82999) BT_L2CAP: L2CAP got sec_comp for unknown BD_ADDR

W (82999) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (82999) BT_APPL: bta_dm_act no entry for connected service cbs
W (83009) BT_BTC: BTA_AV_OPEN_EVT::FAILED status: 3

I (83019) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (91399) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (91399) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (91399) BT_APPL: reset flags
I (91409) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2
set state id 1,state 23
set state id 1,state 24
set state id 1,state 24
set state id 1,state 2
set state id 1,state 22
set state id 1,state 2
set state id 1,state 9
set state id 1,state 2
set state id 1,state 20
set state id 1,state 2
set state id 1,state 1
set state id 1,state 60
set state id 1,state 14
W (93749) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (93749) BT_AV: event: 16
set state id 1,state 1
set state id 1,state 8
set state id 1,state 1
set state id 1,state 1
set state id 1,state 36
set state id 1,state 31
set state id 1,state 1
set state id 1,state 41
set state id 1,state 42
set state id 1,state 44

shangke1112 commented 1 year ago

According to the last log ,there may be an issue with encryption ,but I am not sure.Please use this lib and try again. libbtdm3.tar.gz

espradio commented 1 year ago

Hi @shangke1112 Please find the log

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
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:7132
ho 0 tail 12 room 4
load:0x40078000,len:15672
ho 0 tail 12 room 4
load:0x40080400,len:4
load:0x40080404,len:3884
entry 0x40080650
I (33) boot: ESP-IDF v5.2-dev-917-g37d11ea04d-dirty 2nd stage bootloader
I (33) boot: compile time Jun  4 2023 23:05:49
I (35) boot: Multicore bootloader
I (39) boot: chip revision: v3.0
I (43) boot.esp32: SPI Speed      : 40MHz
I (48) boot.esp32: SPI Mode       : DIO
I (52) boot.esp32: SPI Flash Size : 2MB
I (57) boot: Enabling RNG early entropy source...
I (62) boot: Partition Table:
I (66) boot: ## Label            Usage          Type ST Offset   Length
I (73) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (81) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (88) boot:  2 factory          factory app      00 00 00010000 00100000
I (96) boot: End of partition table
I (100) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=2aa3ch (174652)                                                                                                                                                              map
I (171) esp_image: segment 1: paddr=0003aa64 vaddr=3ffbdb60 size=04574h ( 17780)                                                                                                                                                              load
I (179) esp_image: segment 2: paddr=0003efe0 vaddr=40080000 size=01038h (  4152)                                                                                                                                                              load
I (181) esp_image: segment 3: paddr=00040020 vaddr=400d0020 size=a7634h (685620)                                                                                                                                                              map
I (433) esp_image: segment 4: paddr=000e765c vaddr=40081038 size=17460h ( 95328)                                                                                                                                                              load
I (485) boot: Loaded app from partition at offset 0x10000
I (485) boot: Disabling RNG early entropy source...
I (497) cpu_start: Multicore app
I (497) cpu_start: Pro cpu up.
I (497) cpu_start: Starting app cpu, entry point is 0x40081220
I (0) cpu_start: App cpu up.
I (517) cpu_start: Pro cpu start user code
I (517) cpu_start: cpu freq: 160000000 Hz
I (517) cpu_start: Application information:
I (522) cpu_start: Project name:     a2dp_source
I (527) cpu_start: App version:      v5.2-dev-917-g37d11ea04d-dirty
I (534) cpu_start: Compile time:     Jun  4 2023 23:05:44
I (540) cpu_start: ELF file SHA256:  0b70bf53c...
I (546) cpu_start: ESP-IDF:          v5.2-dev-917-g37d11ea04d-dirty
I (553) cpu_start: Min chip rev:     v0.0
I (557) cpu_start: Max chip rev:     v3.99
I (562) cpu_start: Chip rev:         v3.0
I (567) heap_init: Initializing. RAM available for dynamic allocation:
I (574) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (580) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (586) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (592) heap_init: At 3FFCBC30 len 000143D0 (80 KiB): DRAM
I (599) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (605) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (611) heap_init: At 40098498 len 00007B68 (30 KiB): IRAM
I (619) spi_flash: detected chip: gd
I (622) spi_flash: flash io: dio
W (626) spi_flash: Detected size(16384k) larger than the size in the binary imag                                                                                                                                                             e header(2048k). Using the size in the binary image header.
I (640) coexist: coex firmware version: ebddf30
I (645) app_start: Starting scheduler on CPU0
I (649) app_start: Starting scheduler on CPU1
I (649) main_task: Started on CPU0
I (659) main_task: Calling app_main()
I (679) BTDM_INIT: BT controller compile version [4f4ce33]
set state id 2,state 0 A0: 0x8001ad29
set state id 0,state 0 A0: 0x8004ef19
set state id 6,state 127 A0: 0x800447a8
set state id 262,state 127 A0: 0x800447a8
set state id 518,state 127 A0: 0x800447a8
set state id 774,state 127 A0: 0x800447a8
set state id 1030,state 127 A0: 0x800447a8
set state id 1286,state 127 A0: 0x800447a8
set state id 1542,state 127 A0: 0x800447a8
set state id 1798,state 127 A0: 0x800447a8
set state id 2054,state 127 A0: 0x800447a8
set state id 2310,state 127 A0: 0x800447a8
set state id 5,state 0 A0: 0x8004ca80
set state id 8,state 0 A0: 0x8013bc7c
I (729) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
set state id 0,state 0 A0: 0x8004ef19
set state id 0,state 0 A0: 0x8004ef19
set state id 5,state 0 A0: 0x8004ca80
I (1419) BT_AV: Starting device discovery...
W (1419) BT_BTC: btc_avrc_tg_set_rn_supported_evt failed: AVRC TG not yet initia                                                                                                                                                             lized

W (1429) BT_BTC: A2DP Enable with AVRC
I (1439) BT_AV: bt_app_av_sm_hdlr state: 1, event: 0x4
I (1439) BT_AV: event: 10
I (1449) BT_AV: event: 10
I (1449) BT_AV: event: 10
I (1449) BT_AV: event: 10
I (1449) main_task: Returned from app_main()
I (1459) BT_AV: Discovery started.
I (11419) BT_AV: bt_app_av_sm_hdlr state: 1, event: 0xff00
I (14259) BT_AV: Device discovery failed, continue to discover...
I (14269) BT_AV: Discovery started.
I (21419) BT_AV: bt_app_av_sm_hdlr state: 1, event: 0xff00
I (27069) BT_AV: Device discovery failed, continue to discover...
I (27079) BT_AV: Discovery started.
I (31419) BT_AV: bt_app_av_sm_hdlr state: 1, event: 0xff00
I (33789) BT_AV: Scanned device: f8:23:45:44:23:43
I (33789) BT_AV: --Class of Device: 0x340408
I (33789) BT_AV: --RSSI: -48
I (33789) BT_AV: Found a target device, address f8:23:45:44:23:43, name bt_Car
I (33799) BT_AV: Cancel device discovery ...
I (33809) BT_AV: Device discovery stopped.
I (33809) BT_AV: a2dp connecting to peer: bt_Car
W (33809) BT_APPL: reset flags
I (33819) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2 A0: 0x8001cb90
set state id 1,state 23 A0: 0x800209e4
set state id 1,state 24 A0: 0x80020dd8
set state id 1,state 24 A0: 0x80020dd8
set state id 1,state 2 A0: 0x8013fcf9
set state id 1,state 22 A0: 0x80020a68
set state id 1,state 2 A0: 0x8002676d
set state id 1,state 9 A0: 0x80029362
set state id 1,state 2 A0: 0x80026c7e
set state id 1,state 20 A0: 0x80020a2e
set state id 1,state 2 A0: 0x8002f1b0
set state id 1,state 1 A0: 0x8001d4e9
set state id 1,state 60 A0: 0x800210fc
set state id 1,state 14 A0: 0x8001d1fd
W (35139) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (35149) BT_AV: event: 16
set state id 1,state 1 A0: 0x8001d0a9
set state id 1,state 8 A0: 0x800291f8
set state id 1,state 1 A0: 0x80025b4c
set state id 1,state 21 A0: 0x8001f024
set state id 1,state 1 A0: 0x8001f310
set state id 1,state 24 A0: 0x80140610
set state id 1,state 1 A0: 0x8013fcf9
set state id 1,state 24 A0: 0x80140610
set state id 1,state 1 A0: 0x8013fcf9
set state id 1,state 1 A0: 0x8001d0a9
set state id 1,state 36 A0: 0x8002101e
set state id 1,state 31 A0: 0x8002101e
set state id 1,state 61 A0: 0x80020eb8
set state id 1,state 63 A0: 0x8002d456
set state id 1,state 15 A0: 0x8002c780
set state id 1,state 16 A0: 0x8002f1b0
set state id 1,state 64 A0: 0x8002f1b0
set state id 1,state 65 A0: 0x80027240
set state id 1,state 99 A0: 0x80140970
set state id 1,state 68 A0: 0x8002890c
set state id 1,state 70 A0: 0x8002b2c1
set state id 1,state 69 A0: 0x8002f1b0
set state id 1,state 71 A0: 0x8002b135
I (35579) BT_AV: ESP_BT_GAP_CFM_REQ_EVT Please compare the numeric value: 306952
set state id 1,state 77 A0: 0x8001df5c
set state id 1,state 76 A0: 0x8002f1b0
set state id 1,state 39 A0: 0x8001dfbc
set state id 1,state 35 A0: 0x8002b988
set state id 1,state 40 A0: 0x8002c120
set state id 1,state 1 A0: 0x8013d962
set state id 1,state 93 A0: 0x80028594
set state id 1,state 1 A0: 0x80026518
set state id 1,state 41 A0: 0x80020290
I (38949) BT_AV: authentication success: bt_Car
I (38949) BT_AV: f8 23 45 44 23 43 
set state id 1,state 42 A0: 0x8001fe0c
set state id 1,state 44 A0: 0x8001fd98
set state id 1,state 1 A0: 0x8001d9a2
E (39059) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
W (39179) BT_APPL: new conn_srvc id:18, app_id:0
W (39189) BT_APPL: bta_dm_pm_ssr conn_srvc id:18, app_id:0
W (39189) BT_APPL: bta_dm_pm_ssr:2, lat:1200
I (39199) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (39199) BT_AV: a2dp connected
I (41419) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0xff00
I (41419) BT_AV: a2dp media ready checking ...
I (41419) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x3
I (41419) BT_AV: a2dp media ready, starting ...
W (41429) BT_APPL: new conn_srvc id:18, app_id:1
set state id 1,state 0 A0: 0x8002f471
W (45599) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
E (45609) BT_APPL: bta_dm_pm_sniff BTM_SetPowerMode() returns ERROR status=7
W (45609) BT_AVCT: ccb 0 not allocated
E (45609) BT_APPL: bta_av_rc_create found duplicated handle:0
I (45619) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x3
E (45619) BT_BTC: handle_rc_connect Connect failed with error code: 2
I (45619) BT_AV: a2dp media start failed.
I (45639) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x0
I (45639) BT_AV: a2dp disconnected
E (47619) BT_BTC: btc_initiate_av_open_tmr_hdlr No connected RC peers
I (51419) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (51419) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (51419) BT_APPL: reset flags
I (51429) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2 A0: 0x8001cb90
set state id 1,state 23 A0: 0x800209e4
set state id 1,state 24 A0: 0x80020dd8
set state id 1,state 24 A0: 0x80020dd8
set state id 1,state 2 A0: 0x8013fcf9
set state id 1,state 22 A0: 0x80020a68
set state id 1,state 2 A0: 0x8002676d
set state id 1,state 9 A0: 0x80029362
set state id 1,state 2 A0: 0x80026c7e
set state id 1,state 20 A0: 0x80020a2e
set state id 1,state 2 A0: 0x8002f1b0
set state id 1,state 1 A0: 0x8001d4e9
set state id 1,state 60 A0: 0x800210fc
set state id 1,state 14 A0: 0x8001d1fd
W (52779) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (52789) BT_AV: event: 16
set state id 1,state 1 A0: 0x8001d0a9
set state id 1,state 8 A0: 0x800291f8
set state id 1,state 1 A0: 0x80025b4c
set state id 1,state 1 A0: 0x8001d0a9
set state id 1,state 36 A0: 0x8002101e
set state id 1,state 31 A0: 0x8002101e
set state id 1,state 1 A0: 0x8001ce74
set state id 1,state 41 A0: 0x80020290
set state id 1,state 42 A0: 0x8001fe0c
set state id 1,state 44 A0: 0x8001fd98
I (61419) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (71419) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (81419) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (81419) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
detach pid 1,reason 34 A0: 0x8002aaf6
set state id 1,state 25 A0: 0x80020424
set state id 1,state 27 A0: 0x8001f8d0
set state id 1,state 0 A0: 0x8002f471
W (83179) BT_L2CAP: L2CAP got sec_comp for unknown BD_ADDR

W (83179) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (83179) BT_APPL: bta_dm_act no entry for connected service cbs
W (83189) BT_BTC: BTA_AV_OPEN_EVT::FAILED status: 3

I (83189) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (91419) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (91419) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (91419) BT_APPL: reset flags
I (91429) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2 A0: 0x8001cb90
set state id 1,state 23 A0: 0x800209e4
set state id 1,state 24 A0: 0x80020dd8
set state id 1,state 24 A0: 0x80020dd8
set state id 1,state 2 A0: 0x8013fcf9
set state id 1,state 22 A0: 0x80020a68
set state id 1,state 2 A0: 0x8002676d
set state id 1,state 9 A0: 0x80029362
set state id 1,state 2 A0: 0x80026c7e
set state id 1,state 20 A0: 0x80020a2e
set state id 1,state 2 A0: 0x8002f1b0
set state id 1,state 1 A0: 0x8001d4e9
set state id 1,state 60 A0: 0x800210fc
W (91769) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (91779) BT_AV: event: 16
set state id 1,state 14 A0: 0x8001d1fd
set state id 1,state 1 A0: 0x8001d0a9
set state id 1,state 8 A0: 0x800291f8
set state id 1,state 1 A0: 0x80025b4c
set state id 1,state 1 A0: 0x8001d0a9
set state id 1,state 36 A0: 0x8002101e
set state id 1,state 31 A0: 0x8002101e
set state id 1,state 1 A0: 0x8001ce74
set state id 1,state 41 A0: 0x80020290
set state id 1,state 42 A0: 0x8001fe0c
set state id 1,state 44 A0: 0x8001fd98
I (101419) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (111419) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (121419) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (121419) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
detach pid 1,reason 34 A0: 0x8002aaf6
set state id 1,state 25 A0: 0x80020424
set state id 1,state 27 A0: 0x8001f8d0
set state id 1,state 0 A0: 0x8002f471
W (122149) BT_L2CAP: L2CAP got sec_comp for unknown BD_ADDR

W (122149) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (122149) BT_APPL: bta_dm_act no entry for connected service cbs
W (122159) BT_BTC: BTA_AV_OPEN_EVT::FAILED status: 3

I (122159) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (131419) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (131419) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (131419) BT_APPL: reset flags
I (131429) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2 A0: 0x8001cb90
set state id 1,state 23 A0: 0x800209e4
set state id 1,state 24 A0: 0x80020dd8
set state id 1,state 24 A0: 0x80020dd8
set state id 1,state 2 A0: 0x8013fcf9
set state id 1,state 22 A0: 0x80020a68
set state id 1,state 2 A0: 0x8002676d
set state id 1,state 9 A0: 0x80029362
set state id 1,state 2 A0: 0x80026c7e
set state id 1,state 20 A0: 0x80020a2e
set state id 1,state 57 A0: 0x8001f120
set state id 1,state 58 A0: 0x80140c35
set state id 1,state 20 A0: 0x8001dd3e
set state id 1,state 2 A0: 0x8002f1b0
set state id 1,state 1 A0: 0x8001d4e9
set state id 1,state 60 A0: 0x800210fc
set state id 1,state 14 A0: 0x8001d1fd
W (132689) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
W (132689) BT_HCI: hcif link supset state id 1,state 1 A0: 0x8001d0a9
set state id 1,state 1 A0: 0x8001d0a9
v_to changed: hdl 0x80, supv_to 32000
I (132709) BT_AV: event: 16
W (132789) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
set state id 1,state 36 A0: 0x8002101e
set state id 1,state 31 A0: 0x8002101e
set state id 1,state 1 A0: 0x8001ce74
set state id 1,state 41 A0: 0x80020290
set state id 1,state 45 A0: 0x8002f1b0
set state id 1,state 48 A0: 0x8013e710
set state id 1,state 1 A0: 0x8001d9a2
E (133439) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
W (133699) BT_APPL: new conn_srvc id:18, app_id:0
W (133699) BT_APPL: bta_dm_pm_ssr conn_srvc id:18, app_id:0
W (133699) BT_APPL: bta_dm_pm_ssr:2, lat:1200
I (133719) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (133719) BT_AV: a2dp connected
set state id 1,state 0 A0: 0x8002f471
W (139839) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (139839) BT_APPL: bta_dm_act no entry for connected service cbs
W (139849) BT_AVCT: ccb 0 not allocated
E (139849) BT_APPL: bta_av_rc_create found duplicated handle:0
I (139859) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x0
E (139859) BT_BTC: handle_rc_connect Connect failed with error code: 2
I (139859) BT_AV: a2dp disconnected
I (141419) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (141419) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (141419) BT_APPL: reset flags
I (141429) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2 A0: 0x8001cb90
set state id 1,state 23 A0: 0x800209e4
set state id 1,state 24 A0: 0x80020dd8
set state id 1,state 24 A0: 0x80020dd8
set state id 1,state 2 A0: 0x8013fcf9
set state id 1,state 22 A0: 0x80020a68
set state id 1,state 2 A0: 0x8002676d
set state id 1,state 9 A0: 0x80029362
set state id 1,state 2 A0: 0x80026c7e
set state id 1,state 20 A0: 0x80020a2e
E (141859) BT_BTC: btc_initiate_av_open_tmr_hdlr No connected RC peers
set state id 1,state 2 A0: 0x8002f1b0
set state id 1,state 1 A0: 0x8001d4e9
set state id 1,state 60 A0: 0x800210fc
set state id 1,state 14 A0: 0x8001d1fd
W (141889) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (141899) BT_AV: event: 16
set state id 1,state 1 A0: 0x8001d0a9
set state id 1,state 8 A0: 0x800291f8
set state id 1,state 1 A0: 0x80025b4c
set state id 1,state 1 A0: 0x8001d0a9
set state id 1,state 36 A0: 0x8002101e
set state id 1,state 31 A0: 0x8002101e
set state id 1,state 1 A0: 0x8001ce74
set state id 1,state 41 A0: 0x80020290
set state id 1,state 42 A0: 0x8001fe0c
set state id 1,state 44 A0: 0x8001fd98
I (151419) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (161419) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (171419) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (171419) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
detach pid 1,reason 34 A0: 0x8002aaf6
set state id 1,state 25 A0: 0x80020424
set state id 1,state 27 A0: 0x8001f8d0
set state id 1,state 0 A0: 0x8002f471
W (172269) BT_L2CAP: L2CAP got sec_comp for unknown BD_ADDR

W (172269) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (172269) BT_APPL: bta_dm_act no entry for connected service cbs
W (172279) BT_BTC: BTA_AV_OPEN_EVT::FAILED status: 3

I (172279) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0

shangke1112 commented 1 year ago

According to this log ,our device send LMP_START_ENCRYPTION_REQ ,but the other device do not send LMP_ACCEPT or LMP_NOT_ACCEPT, so our devce timed out . This lib is used to confirm whether the other device supports encryption, please try again. libbtdm4.tar.gz

espradio commented 1 year ago

Hi

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
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:7132
ho 0 tail 12 room 4
load:0x40078000,len:15672
ho 0 tail 12 room 4
load:0x40080400,len:4
load:0x40080404,len:3884
entry 0x40080650
I (33) boot: ESP-IDF v5.2-dev-917-g37d11ea04d-dirty 2nd stage bootloader
I (33) boot: compile time Jun 12 2023 15:16:38
I (35) boot: Multicore bootloader
I (39) boot: chip revision: v3.0
I (43) boot.esp32: SPI Speed      : 40MHz
I (48) boot.esp32: SPI Mode       : DIO
I (52) boot.esp32: SPI Flash Size : 2MB
I (57) boot: Enabling RNG early entropy source...
I (62) boot: Partition Table:
I (66) boot: ## Label            Usage          Type ST Offset   Length
I (73) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (81) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (88) boot:  2 factory          factory app      00 00 00010000 00100000
I (96) boot: End of partition table
I (100) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=2aa6ch (174700)                                                                                                                                                              map
I (171) esp_image: segment 1: paddr=0003aa94 vaddr=3ffbdb60 size=04574h ( 17780)                                                                                                                                                              load
I (179) esp_image: segment 2: paddr=0003f010 vaddr=40080000 size=01008h (  4104)                                                                                                                                                              load
I (181) esp_image: segment 3: paddr=00040020 vaddr=400d0020 size=a7680h (685696)                                                                                                                                                              map
I (433) esp_image: segment 4: paddr=000e76a8 vaddr=40081008 size=17490h ( 95376)                                                                                                                                                              load
I (485) boot: Loaded app from partition at offset 0x10000
I (485) boot: Disabling RNG early entropy source...
I (497) cpu_start: Multicore app
I (497) cpu_start: Pro cpu up.
I (497) cpu_start: Starting app cpu, entry point is 0x40081220
I (0) cpu_start: App cpu up.
I (517) cpu_start: Pro cpu start user code
I (517) cpu_start: cpu freq: 160000000 Hz
I (517) cpu_start: Application information:
I (522) cpu_start: Project name:     a2dp_source
I (527) cpu_start: App version:      v5.2-dev-917-g37d11ea04d-dirty
I (534) cpu_start: Compile time:     Jun 12 2023 15:16:34
I (540) cpu_start: ELF file SHA256:  10d5a4caa...
I (546) cpu_start: ESP-IDF:          v5.2-dev-917-g37d11ea04d-dirty
I (553) cpu_start: Min chip rev:     v0.0
I (557) cpu_start: Max chip rev:     v3.99
I (562) cpu_start: Chip rev:         v3.0
I (567) heap_init: Initializing. RAM available for dynamic allocation:
I (574) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (580) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (586) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (593) heap_init: At 3FFCBC30 len 000143D0 (80 KiB): DRAM
I (599) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (605) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (612) heap_init: At 40098498 len 00007B68 (30 KiB): IRAM
I (619) spi_flash: detected chip: gd
I (622) spi_flash: flash io: dio
W (626) spi_flash: Detected size(16384k) larger than the size in the binary imag                                                                                                                                                             e header(2048k). Using the size in the binary image header.
I (640) coexist: coex firmware version: ebddf30
I (645) app_start: Starting scheduler on CPU0
I (649) app_start: Starting scheduler on CPU1
I (649) main_task: Started on CPU0
I (659) main_task: Calling app_main()
I (679) BTDM_INIT: BT controller compile version [5caffe9]
set state id 2,state 0 A0: 0x8001ad29
set state id 0,state 0 A0: 0x8004ef19
set state id 6,state 127 A0: 0x800447a8
set state id 262,state 127 A0: 0x800447a8
set state id 518,state 127 A0: 0x800447a8
set state id 774,state 127 A0: 0x800447a8
set state id 1030,state 127 A0: 0x800447a8
set state id 1286,state 127 A0: 0x800447a8
set state id 1542,state 127 A0: 0x800447a8
set state id 1798,state 127 A0: 0x800447a8
set state id 2054,state 127 A0: 0x800447a8
set state id 2310,state 127 A0: 0x800447a8
set state id 5,state 0 A0: 0x8004ca80
set state id 8,state 0 A0: 0x8013bc7c
I (729) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
set state id 0,state 0 A0: 0x8004ef19
set state id 0,state 0 A0: 0x8004ef19
set state id 5,state 0 A0: 0x8004ca80
W (1419) BT_BTC: btc_avrc_tg_set_rn_supported_evt failed: AVRC TG not yet initia                                                                                                                                                             lized

I (1419) main_task: Returned from app_main()
W (1419) BT_BTC: A2DP Enable with AVRC
I (1419) BT_AV: Starting device discovery...
I (1439) BT_AV: bt_app_av_sm_hdlr state: 1, event: 0x4
I (1439) BT_AV: event: 10
I (1439) BT_AV: event: 10
I (1449) BT_AV: event: 10
I (1449) BT_AV: Discovery started.
I (11429) BT_AV: bt_app_av_sm_hdlr state: 1, event: 0xff00
I (13699) BT_AV: Scanned device: 60:ab:67:1f:d6:2a
I (13699) BT_AV: --Class of Device: 0x5a020c
I (13699) BT_AV: --RSSI: -93
set state id 1,state 2 A0: 0x8001cc26
slmp0 78
set state id 1,state 23 A0: 0x800209e4
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xff
page 1,feats 0x0f
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xff
page 2,feats 0x00
set state id 1,state 2 A0: 0x8013ffad
slmp0 2
set state id 1,state 21 A0: 0x8001f024
detach pid 1,reason 19 A0: 0x8001f310
slmp0 14
set state id 1,state 25 A0: 0x80020424
set state id 1,state 26 A0: 0x80140d99
set state id 1,state 27 A0: 0x8001f8d0
set state id 1,state 0 A0: 0x8002f471
I (15199) BT_AV: Scanned device: 60:ab:67:1f:d6:2a
I (15199) BT_AV: Device discovery failed, continue to discover...
I (15209) BT_AV: Discovery started.
I (20259) BT_AV: Scanned device: 60:ab:67:1f:d6:2a
I (20259) BT_AV: --Class of Device: 0x5a020c
I (20259) BT_AV: --RSSI: -99
I (21429) BT_AV: bt_app_av_sm_hdlr state: 1, event: 0xff00
I (21829) BT_AV: Scanned device: f8:23:45:44:23:43
I (21829) BT_AV: --Class of Device: 0x340408
I (21829) BT_AV: --RSSI: -43
I (21829) BT_AV: Found a target device, address f8:23:45:44:23:43, name bt_Car
I (21839) BT_AV: Cancel device discovery ...
I (21849) BT_AV: Device discovery stopped.
I (21849) BT_AV: a2dp connecting to peer: bt_Car
W (21849) BT_APPL: reset flags
I (21859) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2 A0: 0x8001cb90
slmp0 78
set state id 1,state 23 A0: 0x800209e4
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 1,feats 0x07
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 2,feats 0x25
set state id 1,state 2 A0: 0x8013ffad
slmp0 74
set state id 1,state 22 A0: 0x80020a68
set state id 1,state 2 A0: 0x8002676d
slmp0 94
set state id 1,state 9 A0: 0x80029362
set state id 1,state 2 A0: 0x80026c7e
slmp0 102
set state id 1,state 20 A0: 0x80020a2e
set state id 1,state 2 A0: 0x8002f1b0
slmp0 254
slmp0 98
set state id 1,state 1 A0: 0x8001d4e9
slmp0 90
slmp0 70
slmp0 254
set state id 1,state 60 A0: 0x800210fc
slmp0 97
slmp0 92
set state id 1,state 14 A0: 0x8001d1fd
slmp0 110
W (22359) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
set state id 1,state 1 A0: 0x8001d0a9
slmp0 10
set state id 1,state 8 A0: 0x800291f8
set state id 1,state 1 A0: 0x80025b4c
slmp0 2
set state id 1,state 21 A0: 0x8001f024
I (22369) BT_AV: event: 16
set state id 1,state 1 A0: 0x8001f310
slmp0 254
set state id 1,state 24 A0: 0x80140774
slmp0 77
page 0,feats 0xbf
page 1,feats 0x07
set state id 1,state 1 A0: 0x8013ffad
slmp0 254
set state id 1,state 24 A0: 0x80140774
page 0,feats 0xbf
page 2,feats 0x25
set state id 1,state 1 A0: 0x8013ffad
set state id 1,state 1 A0: 0x8001d0a9
slmp0 5
slmp0 81
slmp0 120
slmp0 255
slmp0 255
set state id 1,state 36 A0: 0x8001f669
slmp0 9
set state id 1,state 1 A0: 0x8002d645
set state id 1,state 36 A0: 0x8002101e
set state id 1,state 61 A0: 0x80020eb8
slmp0 254
set state id 1,state 63 A0: 0x8002d456
slmp0 122
set state id 1,state 15 A0: 0x8002c780
slmp0 124
set state id 1,state 16 A0: 0x8002f1b0
slmp0 124
slmp0 124
set state id 1,state 64 A0: 0x8002f1b0
slmp0 6
set state id 1,state 65 A0: 0x80027240
slmp0 6
slmp0 6
slmp0 6
set state id 1,state 99 A0: 0x80140ad4
set state id 1,state 68 A0: 0x8002890c
slmp0 128
set state id 1,state 70 A0: 0x8002b2c1
set state id 1,state 69 A0: 0x8002f1b0
slmp0 6
set state id 1,state 71 A0: 0x8002b135
I (22769) BT_AV: ESP_BT_GAP_CFM_REQ_EVT Please compare the numeric value: 338367
slmp0 130
set state id 1,state 77 A0: 0x8001df5c
set state id 1,state 1 A0: 0x8013d98a
slmp0 254
W (25889) BT_BTM: btm_sec_clr_temp_auth_service() - no dev CB

detach pid 1,reason 19 A0: 0x800296b0
slmp0 14
set state id 1,state 25 A0: 0x80020424
set state id 1,state 26 A0: 0x80140d99
W (25899) BT_HCI: hci cmd send: disconnect: hdl 0x80, rsn:0x13
W (25909) BT_APPL: bta_dm_act no entry for connected service cbs
E (25919) BT_BTC:  btc_dm_auth_cmpl_evt() Authentication fail reason 5
E (25919) BT_AV: authentication failed, status: 9
W (25929) BT_BTC: BTA_AV_OPEN_EVT::FAILED status: 3

I (25929) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 27 A0: 0x8001f8d0
set state id 1,state 0 A0: 0x8002f471
E (25959) BT_BTM: Device not found

W (25959) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x16
E (25969) BT_APPL: bta_gattc_mark_bg_conn unable to find the bg connection mask for: f8:23:45:44:23:43
I (31429) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (31429) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (31429) BT_APPL: reset flags
I (31439) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2 A0: 0x8001cb90
slmp0 78
set state id 1,state 23 A0: 0x800209e4
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 1,feats 0x07
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 2,feats 0x25
set state id 1,state 2 A0: 0x8013ffad
slmp0 74
set state id 1,state 22 A0: 0x80020a68
set state id 1,state 2 A0: 0x8002676d
slmp0 94
set state id 1,state 9 A0: 0x80029362
set state id 1,state 2 A0: 0x80026c7e
slmp0 102
set state id 1,state 20 A0: 0x80020a2e
set state id 1,state 2 A0: 0x8002f1b0
slmp0 254
slmp0 98
set state id 1,state 1 A0: 0x8001d4e9
slmp0 90
slmp0 70
slmp0 254
set state id 1,state 60 A0: 0x800210fc
slmp0 97
slmp0 92
set state id 1,state 14 A0: 0x8001d1fd
slmp0 110
W (32549) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
set state id 1,state 1 A0: 0x8001d0a9
slmp0 10
set state id 1,state 8 A0: 0x800291f8
I (32559) BTset state id 1,state 1 A0: 0x80025b4c
slmp0 2
set state id 1,state 21 A0: 0x8001f024
_AV: event: 16et state id 1,state 1 A0: 0x8001f310
slmp0 254
set state id 1,state 24 A0: 0x80140774
[0m
slmp0 77
page 0,feats 0xbf
page 1,feats 0x07
set state id 1,state 1 A0: 0x8013ffad
slmp0 254
set state id 1,state 24 A0: 0x80140774
page 0,feats 0xbf
page 2,feats 0x25
set state id 1,state 1 A0: 0x8013ffad
set state id 1,state 1 A0: 0x8001d0a9
slmp0 120
slmp0 81
slmp0 255
slmp0 255
set state id 1,state 36 A0: 0x8002101e
set state id 1,state 61 A0: 0x80020eb8
slmp0 254
set state id 1,state 63 A0: 0x8002d456
slmp0 122
set state id 1,state 15 A0: 0x8002c780
slmp0 124
set state id 1,state 16 A0: 0x8002f1b0
slmp0 124
slmp0 124
set state id 1,state 64 A0: 0x8002f1b0
slmp0 6
set state id 1,state 65 A0: 0x80027240
slmp0 6
slmp0 6
slmp0 6
set state id 1,state 99 A0: 0x80140ad4
set state id 1,state 68 A0: 0x8002890c
slmp0 128
set state id 1,state 70 A0: 0x8002b2c1
set state id 1,state 69 A0: 0x8002f1b0
slmp0 6
set state id 1,state 71 A0: 0x8002b135
I (33009) BT_AV: ESP_BT_GAP_CFM_REQ_EVT Please compare the numeric value: 570533
slmp0 130
set state id 1,state 77 A0: 0x8001df5c
set state id 1,state 76 A0: 0x8002f1b0
slmp0 6
slmp0 22
set state id 1,state 39 A0: 0x8001dfbc
set state id 1,state 35 A0: 0x8002b988
slmp0 24
set state id 1,state 40 A0: 0x8002c120
set state id 1,state 1 A0: 0x8013d98a
slmp0 30
set state id 1,state 41 A0: 0x80020290
slmp0 32
set state id 1,state 42 A0: 0x8001fe0c
slmp0 34
set state id 1,state 44 A0: 0x8001fd98
I (35199) BT_AV: authentication success: bt_Car
I (35199) BT_AV: f8 23 45 44 23 43
set state id 1,state 1 A0: 0x8001d9a2
slmp0 5
slmp0 7
E (35299) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
W (35409) BT_APPL: new conn_srvc id:18, app_id:0
W (35409) BT_APPL: bta_dm_pm_ssr conn_srvc id:18, app_id:0
W (35409) BT_APPL: bta_dm_pm_ssr:2, lat:1200
I (35419) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (35419) BT_AV: a2dp connected
I (41429) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0xff00
I (41429) BT_AV: a2dp media ready checking ...
I (41429) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x3
I (41429) BT_AV: a2dp media ready, starting ...
W (41439) BT_APPL: new conn_srvc id:18, app_id:1
set state id 1,state 0 A0: 0x8002f471
W (42349) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
E (42349) BT_APPL: bta_dm_pm_sniff BTM_SetPowerMode() returns ERROR status=7
W (42349) BT_AVCT: ccb 0 not allocated
E (42349) BT_APPL: bta_av_rc_create found duplicated handle:0
I (42359) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x3
E (42359) BT_BTC: handle_rc_connect Connect failed with error code: 2
I (42369) BT_AV: a2dp media start failed.
I (42379) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x0
I (42379) BT_AV: a2dp disconnected
E (44359) BT_BTC: btc_initiate_av_open_tmr_hdlr No connected RC peers
I (51429) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (51429) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (51429) BT_APPL: reset flags
I (51439) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2 A0: 0x8001cb90
slmp0 78
set state id 1,state 23 A0: 0x800209e4
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 1,feats 0x07
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 2,feats 0x25
set state id 1,state 2 A0: 0x8013ffad
slmp0 74
set state id 1,state 22 A0: 0x80020a68
set state id 1,state 2 A0: 0x8002676d
slmp0 94
set state id 1,state 9 A0: 0x80029362
set state id 1,state 2 A0: 0x80026c7e
slmp0 102
set state id 1,state 20 A0: 0x80020a2e
set state id 1,state 2 A0: 0x8002f1b0
slmp0 254
slmp0 98
set state id 1,state 1 A0: 0x8001d4e9
slmp0 90
slmp0 70
slmp0 254
set state id 1,state 60 A0: 0x800210fc
slmp0 97
slmp0 92
set state id 1,state 14 A0: 0x8001d1fd
slmp0 110
W (51929) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (51939) BT_AV: event: 16
set state id 1,state 1 A0: 0x8001d0a9
slmp0 10
set state id 1,state 8 A0: 0x800291f8
slmp0 77
set state id 1,state 1 A0: 0x80025b4c
set state id 1,state 1 A0: 0x8001d0a9
slmp0 5
slmp0 81
slmp0 120
slmp0 255
slmp0 255
set state id 1,state 36 A0: 0x8002101e
slmp0 22
set state id 1,state 31 A0: 0x8002101e
set state id 1,state 1 A0: 0x8001ce74
slmp0 30
set state id 1,state 41 A0: 0x80020290
slmp0 32
set state id 1,state 42 A0: 0x8001fe0c
slmp0 34
set state id 1,state 44 A0: 0x8001fd98
set state id 1,state 1 A0: 0x8001d9a2
W (52209) BT_APPL: bta_dm_act no entry for connected service cbs
W (52209) BT_BTC: BTA_AV_OPEN_EVT::FAILED status: 3

I (52209) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
detach pid 1,reason 19 A0: 0x800296b0
slmp0 14
set state id 1,state 25 A0: 0x80020424
W (56209) BT_HCI: hci cmd send: disconnect: hdl 0x80, rsn:0x13
set state id 1,state 26 A0: 0x80140d99
set state id 1,state 27 A0: 0x8001f8d0
set state id 1,state 0 A0: 0x8002f471
W (56279) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x16
I (61429) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (61429) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (61429) BT_APPL: reset flags
I (61439) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2 A0: 0x8001cb90
slmp0 78
set state id 1,state 23 A0: 0x800209e4
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 1,feats 0x07
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 2,feats 0x25
set state id 1,state 2 A0: 0x8013ffad
slmp0 74
set state id 1,state 22 A0: 0x80020a68
set state id 1,state 2 A0: 0x8002676d
slmp0 94
set state id 1,state 9 A0: 0x80029362
set state id 1,state 2 A0: 0x80026c7e
slmp0 102
set state id 1,state 20 A0: 0x80020a2e
set state id 1,state 2 A0: 0x8002f1b0
slmp0 254
slmp0 98
set state id 1,state 1 A0: 0x8001d4e9
slmp0 90
slmp0 70
slmp0 254
set state id 1,state 60 A0: 0x800210fc
slmp0 97
slmp0 110
slmp0 92
set state id 1,state 14 A0: 0x8001d1fd
W (62259) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (62259) BT_AV: event: 16
set state id 1,state 1 A0: 0x8001d0a9
slmp0 10
set state id 1,state 8 A0: 0x800291f8
slmp0 77
set state id 1,state 1 A0: 0x80025b4c
set state id 1,state 1 A0: 0x8001d0a9
slmp0 81
slmp0 120
slmp0 255
slmp0 255
set state id 1,state 36 A0: 0x8002101e
slmp0 22
set state id 1,state 31 A0: 0x8002101e
set state id 1,state 1 A0: 0x8001ce74
slmp0 30
set state id 1,state 41 A0: 0x80020290
slmp0 32
set state id 1,state 42 A0: 0x8001fe0c
slmp0 34
set state id 1,state 44 A0: 0x8001fd98
set state id 1,state 1 A0: 0x8001d9a2
E (62579) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
slmp0 7
W (62699) BT_APPL: new conn_srvc id:18, app_id:0
W (62699) BT_APPL: bta_dm_pm_ssr conn_srvc id:18, app_id:0
W (62699) BT_APPL: bta_dm_pm_ssr:2, lat:1200
I (62699) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (62709) BT_AV: a2dp connected
set state id 1,state 0 A0: 0x8002f471
W (68729) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
W (68729) BT_APPL: bta_dm_act no entry for connected service cbs
W (68729) BT_AVCT: ccb 0 not allocated
E (68739) BT_APPL: bta_av_rc_create found duplicated handle:0
I (68739) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x0
E (68749) BT_BTC: handle_rc_connect Connect failed with error code: 2
I (68749) BT_AV: a2dp disconnected
E (70749) BT_BTC: btc_initiate_av_open_tmr_hdlr No connected RC peers
I (71429) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (71429) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (71429) BT_APPL: reset flags
I (71439) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2 A0: 0x8001cb90
slmp0 78
set state id 1,state 23 A0: 0x800209e4
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 1,feats 0x07
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 2,feats 0x25
set state id 1,state 2 A0: 0x8013ffad
slmp0 74
set state id 1,state 22 A0: 0x80020a68
set state id 1,state 2 A0: 0x8002676d
slmp0 94
set state id 1,state 9 A0: 0x80029362
set state id 1,state 2 A0: 0x80026c7e
slmp0 102
set state id 1,state 20 A0: 0x80020a2e
set state id 1,state 2 A0: 0x8002f1b0
slmp0 254
slmp0 98
set state id 1,state 1 A0: 0x8001d4e9
slmp0 90
slmp0 70
slmp0 254
set state id 1,state 60 A0: 0x800210fc
slmp0 97
slmp0 110
W (72649) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (72649) BT_AV: event: 16
slmp0 92
set state id 1,state 14 A0: 0x8001d1fd
slmp0 77
set state id 1,state 1 A0: 0x8001d0a9
slmp0 10
set state id 1,state 8 A0: 0x800291f8
slmp0 5
set state id 1,state 1 A0: 0x80025b4c
set state id 1,state 1 A0: 0x8001d0a9
slmp0 120
slmp0 81
slmp0 255
slmp0 255
set state id 1,state 36 A0: 0x8002101e
slmp0 22
set state id 1,state 31 A0: 0x8002101e
set state id 1,state 1 A0: 0x8001ce74
slmp0 30
set state id 1,state 41 A0: 0x80020290
slmp0 32
set state id 1,state 42 A0: 0x8001fe0c
slmp0 34
set state id 1,state 44 A0: 0x8001fd98
set state id 1,state 1 A0: 0x8001d9a2
W (72979) BT_APPL: bta_dm_act no entry for connected service cbs
W (72979) BT_BTC: BTA_AV_OPEN_EVT::FAILED status: 3

I (72979) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
detach pid 1,reason 19 A0: 0x800296b0
slmp0 14
set state id 1,state 25 A0: 0x80020424
W (76979) BT_HCI: hci cmd send: disconnect: hdl 0x80, rsn:0x13
set state id 1,state 26 A0: 0x80140d99
set state id 1,state 27 A0: 0x8001f8d0
set state id 1,state 0 A0: 0x8002f471
W (77049) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x16
I (81429) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (81429) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (81429) BT_APPL: reset flags
I (81439) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2 A0: 0x8001cb90
slmp0 78
set state id 1,state 23 A0: 0x800209e4
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 1,feats 0x07
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 2,feats 0x25
set state id 1,state 2 A0: 0x8013ffad
slmp0 74
set state id 1,state 22 A0: 0x80020a68
set state id 1,state 2 A0: 0x8002676d
slmp0 94
set state id 1,state 9 A0: 0x80029362
set state id 1,state 2 A0: 0x80026c7e
slmp0 102
set state id 1,state 20 A0: 0x80020a2e
set state id 1,state 2 A0: 0x8002f1b0
slmp0 254
slmp0 98
set state id 1,state 1 A0: 0x8001d4e9
slmp0 90
slmp0 70
slmp0 254
set state id 1,state 60 A0: 0x800210fc
slmp0 97
slmp0 92
set state id 1,state 14 A0: 0x8001d1fd
slmp0 110
W (81629) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
set state id 1,state 1 A0: 0x8001d0a9
slmp0 10
set state id 1,state 8 A0: 0x800291f8
I (81649) BT_AV: event: 16
set state id 1,state 1 A0: 0x80025b4c
set state id 1,state 1 A0: 0x8001d0a9
slmp0 77
slmp0 120
slmp0 81
slmp0 255
slmp0 255
set state id 1,state 36 A0: 0x8002101e
slmp0 22
set state id 1,state 31 A0: 0x8002101e
set state id 1,state 1 A0: 0x8001ce74
slmp0 30
set state id 1,state 41 A0: 0x80020290
slmp0 32
set state id 1,state 42 A0: 0x8001fe0c
slmp0 34
set state id 1,state 44 A0: 0x8001fd98
set state id 1,state 1 A0: 0x8001d9a2
E (81989) BT_APPL: bta_av_rc_create ACP handle exist for shdl:0
slmp0 7
W (82099) BT_APPL: new conn_srvc id:18, app_id:0
W (82099) BT_APPL: bta_dm_pm_ssr conn_srvc id:18, app_id:0
W (82099) BT_APPL: bta_dm_pm_ssr:2, lat:1200
I (82099) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
I (82109) BT_AV: a2dp connected
slmp0 46
set state id 1,state 50 A0: 0x8001facc
W (89299) BT_HCI: hci cmd send: sniff: hdl 0x80, intv(400 800)
I (91429) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0xff00
I (91429) BT_AV: a2dp media ready checking ...
I (91429) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x3
I (91429) BT_AV: a2dp media ready, starting ...
W (91439) BT_APPL: new conn_srvc id:18, app_id:1
I (101429) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0xff00
I (106449) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x3
I (106449) BT_AV: a2dp media start failed.
I (111429) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0xff00
I (111429) BT_AV: a2dp media ready checking ...
I (111429) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x3
I (111429) BT_AV: a2dp media ready, starting ...
set state id 1,state 0 A0: 0x8002f471
W (112309) BT_SDP: SDP - Rcvd L2CAP disc cfm, unknown CID: 0x44

W (112319) BT_HCI: hcif disc complete: hdl 0x80, rsn 0x8
E (112319) BT_APPL: bta_dm_pm_sniff BTM_SetPowerMode() returns ERROR status=7
W (112329) BT_AVCT: ccb 0 not allocated
E (112329) BT_APPL: bta_av_rc_create found duplicated handle:0
I (112339) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x3
I (112339) BT_AV: a2dp media start failed.
I (112349) BT_AV: bt_app_av_sm_hdlr state: 5, event: 0x0
I (112349) BT_AV: a2dp disconnected
I (121429) BT_AV: bt_app_av_sm_hdlr state: 3, event: 0xff00
I (121429) BT_AV: a2dp connecting to peer: f8:23:45:44:23:43
W (121429) BT_APPL: reset flags
I (121439) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0x0
set state id 1,state 2 A0: 0x8001cb90
slmp0 78
set state id 1,state 23 A0: 0x800209e4
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 1,feats 0x07
slmp0 254
set state id 1,state 24 A0: 0x80020dd8
page 0,feats 0xbf
page 2,feats 0x25
set state id 1,state 2 A0: 0x8013ffad
slmp0 74
set state id 1,state 22 A0: 0x80020a68
set state id 1,state 2 A0: 0x8002676d
slmp0 94
set state id 1,state 9 A0: 0x80029362
set state id 1,state 2 A0: 0x80026c7e
slmp0 102
set state id 1,state 20 A0: 0x80020a2e
set state id 1,state 2 A0: 0x8002f1b0
slmp0 254
slmp0 98
set state id 1,state 1 A0: 0x8001d4e9
slmp0 90
slmp0 70
slmp0 254
set state id 1,state 60 A0: 0x800210fc
slmp0 97
slmp0 92
set state id 1,state 14 A0: 0x8001d1fd
slmp0 110
W (122679) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
set state id 1,state 1 A0: 0x8001d0a9
slmp0 10
set state id 1,state 8 A0: 0x800291f8
I (122689) BT_AV: event: 16
set state id 1,state 1 A0: 0x80025b4c
set state id 1,state 1 A0: 0x8001d0a9
slmp0 77
slmp0 5
slmp0 81
slmp0 120
slmp0 255
slmp0 255
set state id 1,state 36 A0: 0x8002101e
slmp0 22
set state id 1,state 31 A0: 0x8002101e
set state id 1,state 1 A0: 0x8001ce74
slmp0 30
set state id 1,state 41 A0: 0x80020290
slmp0 32
set state id 1,state 42 A0: 0x8001fe0c
slmp0 34
set state id 1,state 44 A0: 0x8001fd98
I (131429) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00
I (141429) BT_AV: bt_app_av_sm_hdlr state: 4, event: 0xff00

shangke1112 commented 1 year ago

this log: detach pid 1,reason 19 A0: 0x8001f310 . Reason 19 means the remote device send a disconnect to our device ,the previous log has a value of 34. It seems that these two test result are different. May I ask if there is any issues with other devices ?

espradio commented 1 year ago

Issue observed only with a specific device. But if we use it with Android Phone that device works properly.

espradio commented 1 year ago

Any other logs will help?

shangke1112 commented 1 year ago

What I mean is there any issues using the "BT_Car" wiht other devices ? The simplest solution to this problem is to caption packets to analysis, do you have a device for captuing packets? It is difficult to determine the behavior of the other device through our decice's log.

espradio commented 1 year ago

What I mean is there any issues using the "BT_Car" wiht other devices ? No. do you have a device for captuing packets? Unfortunately I dont have

shangke1112 commented 1 year ago

Modify the macro "SC_MODE_INCLUDED" to "TRUE" in the file bt_target.h , this will change the encryption mode .

define SC_MODE_INCLUDED TRUE

Also ,please try a few more times and send the log to me.

espressif / esp-idf

Not able to stay in ad2p connected (IDFGH-10137) #11408

Answers checklist.

General issue report

define SC_MODE_INCLUDED TRUE