BT_BTC: btc_dm_auth_cmpl_evt() Authentication fail reason 5

boernsen
Posts: 9
Joined: Tue Jul 19, 2022 7:43 pm

BT_BTC: btc_dm_auth_cmpl_evt() Authentication fail reason 5

Postby boernsen » Wed Oct 12, 2022 7:12 pm

Hi everyone,

I am trying to get my ESP32 pair with a Bluetooth Classic 2.0 trackpad (generally recognized as Bluetooth mouse on Windows/Linux) using the official esp_hid_host example.

So, I:
  • followed Get started guide
  • built and flashed the example
  • opened a monitor
  • put my trackpad into pairing mode
  • reset the ESP32
It finds the trackpad, but ends with the following error:

Code: Select all

E (6510) BT_HIDH: OPEN ERROR: ERR
E (6510) ESP_HIDH_DEMO:  OPEN failed!
W (6660) BT_HCI: hcif disc complete: hdl 0x81, rsn 0x5
E (6670) BT_BTC:  btc_dm_auth_cmpl_evt() Authentication fail reason 5
I don't know how to proceed or debug. What can I do?

This is the full monitor output:

Code: Select all

user@user-kubuntu:~/eclipse-workspace/esp_hid_host_v442$ idf.py -p /dev/ttyUSB0 monitor
Executing action: monitor
Running idf_monitor in directory /home/user/eclipse-workspace/esp_hid_host_v442
Executing "/home/user/.espressif/python_env/idf4.4_py3.8_env/bin/python /home/user/esp-idf/v4.4.2/esp-idf/tools/idf_monitor.py -p /dev/ttyUSB0 -b 115200 --toolchain-prefix xtensa-esp32-elf- --target esp32 --revision 0 /home/user/eclipse-workspace/esp_hid_host_v442/build/esp_hid_host.elf -m '/home/user/.espressif/python_env/idf4.4_py3.8_env/bin/python' '/home/user/esp-idf/v4.4.2/esp-idf/tools/idf.py' '-p' '/dev/ttyUSB0'"...
--- idf_monitor on /dev/ttyUSB0 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
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:6660
load:0x40078000,len:14848
ho 0 tail 12 room 4
load:0x40080400,len:3792
0x40080400: _init at ??:?

entry 0x40080694
I (29) boot: ESP-IDF v4.4.2 2nd stage bootloader
I (29) boot: compile time 20:46:26
I (29) boot: chip revision: 3
I (32) boot_comm: chip revision: 3, min. bootloader chip revision: 0
I (39) boot.esp32: SPI Speed      : 40MHz
I (44) boot.esp32: SPI Mode       : DIO
I (48) boot.esp32: SPI Flash Size : 2MB
I (53) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (69) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (76) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (84) boot:  2 factory          factory app      00 00 00010000 00100000
I (91) boot: End of partition table
I (96) boot_comm: chip revision: 3, min. application chip revision: 0
I (103) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=180c0h ( 98496) map
I (147) esp_image: segment 1: paddr=000280e8 vaddr=3ffbdb60 size=04628h ( 17960) load
I (154) esp_image: segment 2: paddr=0002c718 vaddr=40080000 size=03900h ( 14592) load
I (160) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=67a1ch (424476) map
I (315) esp_image: segment 4: paddr=00097a44 vaddr=40083900 size=1367ch ( 79484) load
I (348) esp_image: segment 5: paddr=000ab0c8 vaddr=50000000 size=00010h (    16) load
I (359) boot: Loaded app from partition at offset 0x10000
I (359) boot: Disabling RNG early entropy source...
I (371) cpu_start: Pro cpu up.
I (371) cpu_start: Starting app cpu, entry point is 0x400811a8
0x400811a8: call_start_cpu1 at /home/user/esp-idf/v4.4.2/esp-idf/components/esp_system/port/cpu_start.c:160

I (0) cpu_start: App cpu up.
I (387) cpu_start: Pro cpu start user code
I (387) cpu_start: cpu freq: 160000000
I (388) cpu_start: Application information:
I (392) cpu_start: Project name:     esp_hid_host
I (397) cpu_start: App version:      f55d8fd
I (402) cpu_start: Compile time:     Oct 12 2022 20:46:19
I (408) cpu_start: ELF file SHA256:  627e3c7aa9802bfa...
I (414) cpu_start: ESP-IDF:          v4.4.2
I (420) heap_init: Initializing. RAM available for dynamic allocation:
I (427) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (433) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (439) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (445) heap_init: At 3FFC6350 len 00019CB0 (103 KiB): DRAM
I (451) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (457) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (464) heap_init: At 40096F7C len 00009084 (36 KiB): IRAM
I (471) spi_flash: detected chip: generic
I (475) spi_flash: flash io: dio
W (479) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.                                                                          
I (493) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (540) ESP_HIDH_DEMO: setting hid gap, mode:2
I (540) BTDM_INIT: BT controller compile version [bf9c077]
I (540) system_api: Base MAC address is not set
I (540) system_api: read default base MAC address from EFUSE
I (550) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1230) ESP_HIDH_DEMO: EVENT: 5
I (1230) ESP_HIDH_DEMO: SCAN...
I (5090) ESP_HIDH_DEMO: SCAN: 0 results
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:6660
load:0x40078000,len:14848
ho 0 tail 12 room 4
load:0x40080400,len:3792
0x40080400: _init at ??:?

entry 0x40080694
I (29) boot: ESP-IDF v4.4.2 2nd stage bootloader
I (29) boot: compile time 20:46:26
I (29) boot: chip revision: 3
I (32) boot_comm: chip revision: 3, min. bootloader chip revision: 0
I (39) boot.esp32: SPI Speed      : 40MHz
I (44) boot.esp32: SPI Mode       : DIO
I (48) boot.esp32: SPI Flash Size : 2MB
I (53) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (69) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (76) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (84) boot:  2 factory          factory app      00 00 00010000 00100000
I (91) boot: End of partition table
I (96) boot_comm: chip revision: 3, min. application chip revision: 0
I (103) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=180c0h ( 98496) map
I (147) esp_image: segment 1: paddr=000280e8 vaddr=3ffbdb60 size=04628h ( 17960) load
I (154) esp_image: segment 2: paddr=0002c718 vaddr=40080000 size=03900h ( 14592) load
I (160) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=67a1ch (424476) map
I (315) esp_image: segment 4: paddr=00097a44 vaddr=40083900 size=1367ch ( 79484) load
I (348) esp_image: segment 5: paddr=000ab0c8 vaddr=50000000 size=00010h (    16) load
I (359) boot: Loaded app from partition at offset 0x10000
I (359) boot: Disabling RNG early entropy source...
I (371) cpu_start: Pro cpu up.
I (371) cpu_start: Starting app cpu, entry point is 0x400811a8
0x400811a8: call_start_cpu1 at /home/user/esp-idf/v4.4.2/esp-idf/components/esp_system/port/cpu_start.c:160

I (0) cpu_start: App cpu up.
I (387) cpu_start: Pro cpu start user code
I (387) cpu_start: cpu freq: 160000000
I (388) cpu_start: Application information:
I (392) cpu_start: Project name:     esp_hid_host
I (397) cpu_start: App version:      f55d8fd
I (402) cpu_start: Compile time:     Oct 12 2022 20:46:19
I (408) cpu_start: ELF file SHA256:  627e3c7aa9802bfa...
I (414) cpu_start: ESP-IDF:          v4.4.2
I (420) heap_init: Initializing. RAM available for dynamic allocation:
I (427) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (433) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (439) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (445) heap_init: At 3FFC6350 len 00019CB0 (103 KiB): DRAM
I (451) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (457) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (464) heap_init: At 40096F7C len 00009084 (36 KiB): IRAM
I (471) spi_flash: detected chip: generic
I (475) spi_flash: flash io: dio
W (479) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (493) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (540) ESP_HIDH_DEMO: setting hid gap, mode:2
I (540) BTDM_INIT: BT controller compile version [bf9c077]
I (540) system_api: Base MAC address is not set
I (540) system_api: read default base MAC address from EFUSE
I (550) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1220) ESP_HIDH_DEMO: EVENT: 5
I (1220) ESP_HIDH_DEMO: SCAN...
BT : xx:xx:xx:xx:xx:01, COD: major: AV, minor: 15, service: 0x040, RSSI: -81
BT : xx:xx:xx:xx:xx:02, COD: major: AV, minor: 15, service: 0x040, RSSI: -89, NAME: [TV] Samsung 5 Series (49)
BT : xx:xx:xx:xx:xx:03, COD: major: PERIPHERAL, minor: 37, service: 0x001, RSSI: -51
BT : xx:xx:xx:xx:xx:01, COD: major: AV, minor: 15, service: 0x040, RSSI: -84
BT : xx:xx:xx:xx:xx:01, COD: major: AV, minor: 15, service: 0x040, RSSI: -81
BT : xx:xx:xx:xx:xx:03, COD: major: PERIPHERAL, minor: 37, service: 0x001, RSSI: -50
BT : xx:xx:xx:xx:xx:04, COD: major: AV, minor: 15, service: 0x040, RSSI: -89, NAME: [TV] Samsung 5 Series (49)
BT : xx:xx:xx:xx:xx:01, COD: major: AV, minor: 15, service: 0x040, RSSI: -86
BT : xx:xx:xx:xx:xx:01, COD: major: AV, minor: 15, service: 0x040, RSSI: -82, NAME: [TV] Samsung 7 Series (43)
BT : xx:xx:xx:xx:xx:01, COD: major: AV, minor: 15, service: 0x040, RSSI: -77, NAME: [TV] Samsung 7 Series (43)
BT : xx:xx:xx:xx:xx:01, COD: major: AV, minor: 15, service: 0x040, RSSI: -75, NAME: [TV] Samsung 7 Series (43)
BT : xx:xx:xx:xx:xx:01, COD: major: AV, minor: 15, service: 0x040, RSSI: -80, NAME: [TV] Samsung 7 Series (43)
BT : xx:xx:xx:xx:xx:01, COD: major: AV, minor: 15, service: 0x040, RSSI: -79
BT : xx:xx:xx:xx:xx:01, COD: major: AV, minor: 15, service: 0x040, RSSI: -81
BT : xx:xx:xx:xx:xx:03, BDNAME: Trackpad
I (5480) ESP_HIDH_DEMO: SCAN: 1 results
  BT : xx:xx:xx:xx:xx:03, RSSI: -50, USAGE: GENERIC, COD: PERIPHERAL[MOUSE+TABLET] srv 0x001, UUID16: 0x0000, NAME: Trackpad
W (5920) BT_HCI: hcif conn complete: hdl 0x81, st 0x0
W (6060) BT_SDP: process_service_attr_rsp

W (6360) BT_SDP: process_service_attr_rsp

E (6510) BT_HIDH: OPEN ERROR: ERR
E (6510) ESP_HIDH_DEMO:  OPEN failed!
W (6660) BT_HCI: hcif disc complete: hdl 0x81, rsn 0x5
E (6670) BT_BTC:  btc_dm_auth_cmpl_evt() Authentication fail reason 5
Other things I have tried:
  • using the master branch of esp-idf --> the same result
  • with v4.4.2 in menuconfig: set Component config --> Bluetooth --> Bluedroid options --> Secure Simple Pairing to DISABLED --> results in a build error (/home/user/eclipse-workspace/esp_hid_host_v442/build/../main/esp_hid_gap.c:426: undefined reference to `esp_bt_gap_set_security_param')
  • older versions such as v4.3.1 or v4.2.4 (with their included example code of esp_hid_host) result in build errors even in default config (../main/esp_hid_host_main.c:131:54: error: 'esp_hidh_gattc_event_handler' undeclared (first use in this function); did you mean 'esp_hidh_event_data_t'?)
Any ideas?

boernsen
Posts: 9
Joined: Tue Jul 19, 2022 7:43 pm

Re: BT_BTC: btc_dm_auth_cmpl_evt() Authentication fail reason 5

Postby boernsen » Fri Oct 14, 2022 2:20 pm

Any idea?

Could it be related to the pairing PIN? The trackpad normally requires to enter a PIN when pairing it. In my attempt I didn't come over any request to enter a PIN.

Who is online

Users browsing this forum: Bing [Bot] and 112 guests